Skip to contentSkip to conversation

Delay in responding caused by netfilter ?

DISCUSSION Jörg Harmuth 5 participants 9 messages Apr 29, 2005 – May 5, 2005

lore
Share & tools
lore

Jörg Harmuth

author
#0 lore raw

Hi all,

Situation:

2 independant servers, one running RH7.2, the other SuSE8.1, with the same symptoms. There is a delay between the TCP/IP habdshake and the server greeting of 26 seconds (SuSE) or 32 seconds respectively (RH). Indeed everything is working, but there is this delay. Some tcpdump:

tcpdump -n -i bond1 'tcp[1] == 110 or tcp[3] == 110'
tcpdump: listening on bond1

13:25:24.835287 10.10.10.100.60719 > 81.169.151.156.110: S \
3714172130:3714172130(0) win 5840 <mss 1460,sackOK,timestamp \
335589204 0,nop,wscale 0> (DF) [tos 0x10]

13:25:24.879667 81.169.151.156.110 > 10.10.10.100.60719: S \
2643711030:2643711030(0) ack 3714172131 win 5792 <mss \
1460,sackOK,timestamp 17886154 335589204,nop,wscale 0> (DF)

13:25:24.879702 10.10.10.100.60719 > 81.169.151.156.110: . ack 1 win \
    5840 <nop,nop,timestamp 335589209 17886154> (DF) [tos 0x10]

13:25:50.964202 81.169.151.156.110 > 10.10.10.100.60719: P 1:35(34) \
ack 1 win 5792 <nop,nop,timestamp 17888762 335589209> (DF)

13:25:50.964224 10.10.10.100.60719 > 81.169.151.156.110: . ack 35 \
win 5840 <nop,nop,timestamp 335591818 17888762> (DF) [tos 0x10]

...

This seems to concern only services that are started by inetd, so I thought inetd would cause this delay. But when I empty the chains (only having a default policy of ACCEPT, nothing more) this delay vanishes and everything is working as expected.

Complete ruleset:

*filter
:INPUT DROP [343:76556]
:FORWARD DROP [0:0]
:OUTPUT DROP [1648:107018]
-A INPUT -i lo -j ACCEPT
-A INPUT -p tcp -m state --state RELATED,ESTABLISHED -j ACCEPT -A INPUT -p tcp -m tcp --dport 22222 -m state --state NEW \
--tcp-flags SYN,RST,ACK SYN -j ACCEPT
-A INPUT -p tcp -m tcp --dport 443 -m state --state NEW \
--tcp-flags SYN,RST,ACK SYN -j ACCEPT
-A INPUT -p tcp -m tcp --dport 25 -m state --state NEW \
--tcp-flags SYN,RST,ACK SYN -j ACCEPT
-A INPUT -p tcp -m tcp --dport 110 -m state --state NEW \
--tcp-flags SYN,RST,ACK SYN -j ACCEPT
-A INPUT -p tcp -m tcp --dport 80 -m state --state NEW \
--tcp-flags SYN,RST,ACK SYN -j ACCEPT
-A INPUT -p tcp -m tcp --dport 22 -m state --state NEW \
--tcp-flags SYN,RST,ACK SYN -j ACCEPT
-A INPUT -p tcp -m tcp --dport 21 -m state --state NEW \
--tcp-flags SYN,RST,ACK SYN -j ACCEPT
-A INPUT -p tcp -m tcp --dport 990 -m state --state NEW \
--tcp-flags SYN,RST,ACK SYN -j ACCEPT
-A INPUT -p tcp -m tcp --dport 21000:21199 -m state \
--state NEW --tcp-flags SYN,RST,ACK SYN -j ACCEPT
-A INPUT -p udp -m udp --dport 53 -j ACCEPT
-A INPUT -p udp -m udp --dport 123 -j ACCEPT
-A INPUT -p udp -m udp --sport 53 -j ACCEPT
-A OUTPUT -o lo -j ACCEPT
-A OUTPUT -p tcp -m state --state RELATED,ESTABLISHED -j ACCEPT -A OUTPUT -p udp -m udp --sport 123 -j ACCEPT
-A OUTPUT -p udp -m udp --sport 53 -j ACCEPT
-A OUTPUT -p udp -m udp --dport 53 -j ACCEPT
COMMIT

Nothing complicated in my eyes. I have absolutely no idea how this tiny ruleset can cause such delays or - at least - is involved in this.

Any ideas are highly welcome.

Thanks and have a nice time,

Joerg

#1 lore raw
Quoted 11 lines · Jörg Harmuth

Hi all,

Situation:

2 independant servers, one running RH7.2, the other SuSE8.1, with the same symptoms. There is a delay between the TCP/IP habdshake and the server greeting of 26 seconds (SuSE) or 32 seconds respectively (RH). Indeed everything is working, but there is this delay. Some tcpdump:

tcpdump -n -i bond1 'tcp[1] == 110 or tcp[3] == 110'
tcpdump: listening on bond1

This gets us the connection you are looking at, but drops anything else. So
-- we can't see things that MIGHT be going wrong.

Quoted 9 lines

13:25:24.835287 10.10.10.100.60719 > 81.169.151.156.110: S \
3714172130:3714172130(0) win 5840 <mss 1460,sackOK,timestamp \
335589204 0,nop,wscale 0> (DF) [tos 0x10]

13:25:24.879667 81.169.151.156.110 > 10.10.10.100.60719: S \
2643711030:2643711030(0) ack 3714172131 win 5792 <mss \
1460,sackOK,timestamp 17886154 335589204,nop,wscale 0> (DF)

Quoted 9 lines
13:25:24.879702 10.10.10.100.60719 > 81.169.151.156.110: . ack 1 win \
    5840 <nop,nop,timestamp 335589209 17886154> (DF) [tos 0x10]

13:25:50.964202 81.169.151.156.110 > 10.10.10.100.60719: P 1:35(34) \
ack 1 win 5792 <nop,nop,timestamp 17888762 335589209> (DF)

13:25:50.964224 10.10.10.100.60719 > 81.169.151.156.110: . ack 35 \
win 5840 <nop,nop,timestamp 335591818 17888762> (DF) [tos 0x10]

I'm wondering if that pop3 server is trying to do an identd check on the connection that is getting *b0rked* with the firewall up. Try that dump again and loosen the filter a tad.

Quoted 6 lines

...

This seems to concern only services that are started by inetd, so I thought inetd would cause this delay. But when I empty the chains (only having a default policy of ACCEPT, nothing more) this delay vanishes and everything is working as expected.

That might be part of the problem, but thing of what inetd/xinetd might be
doing to authenticate the connection before they start the server.

Quoted 47 lines

Complete ruleset:

*filter

:INPUT DROP [343:76556]
:FORWARD DROP [0:0]
:OUTPUT DROP [1648:107018]

(quoted diff) +0 -19
-A INPUT -i lo -j ACCEPT
-A INPUT -p tcp -m state --state RELATED,ESTABLISHED -j ACCEPT
-A INPUT -p tcp -m tcp --dport 22222 -m state --state NEW \
   --tcp-flags SYN,RST,ACK SYN -j ACCEPT
-A INPUT -p tcp -m tcp --dport 443 -m state --state NEW \
   --tcp-flags SYN,RST,ACK SYN -j ACCEPT
-A INPUT -p tcp -m tcp --dport 25 -m state --state NEW \
   --tcp-flags SYN,RST,ACK SYN -j ACCEPT
-A INPUT -p tcp -m tcp --dport 110 -m state --state NEW \
   --tcp-flags SYN,RST,ACK SYN -j ACCEPT
-A INPUT -p tcp -m tcp --dport 80 -m state --state NEW \
   --tcp-flags SYN,RST,ACK SYN -j ACCEPT
-A INPUT -p tcp -m tcp --dport 22 -m state --state NEW \
   --tcp-flags SYN,RST,ACK SYN -j ACCEPT
-A INPUT -p tcp -m tcp --dport 21 -m state --state NEW \
   --tcp-flags SYN,RST,ACK SYN -j ACCEPT
-A INPUT -p tcp -m tcp --dport 990 -m state --state NEW \
   --tcp-flags SYN,RST,ACK SYN  -j ACCEPT
-A INPUT -p tcp -m tcp --dport 21000:21199 -m state \
   --state NEW --tcp-flags SYN,RST,ACK SYN -j ACCEPT
-A INPUT -p udp -m udp --dport 53 -j ACCEPT
-A INPUT -p udp -m udp --dport 123 -j ACCEPT
-A INPUT -p udp -m udp --sport 53 -j ACCEPT
-A OUTPUT -o lo -j ACCEPT
-A OUTPUT -p tcp -m state --state RELATED,ESTABLISHED -j ACCEPT
-A OUTPUT -p udp -m udp --sport 123 -j ACCEPT
-A OUTPUT -p udp -m udp --sport 53 -j ACCEPT
-A OUTPUT -p udp -m udp --dport 53 -j ACCEPT

COMMIT

Nothing complicated in my eyes. I have absolutely no idea how this tiny ruleset can cause such delays or - at least - is involved in this.

Any ideas are highly welcome.

Thanks and have a nice time,

Joerg

#2 lore raw
Quoted 3 lines · Alistair Tonner

I'm wondering if that pop3 server is trying to do an identd check on the connection that is getting *b0rked* with the firewall up. Try that dump again and loosen the filter a tad.

i'd second that notion. setup the OUTPUT chain to allow everything and see if that fixes it. if it does--figure out what traffic you need to be allowing out to prevent the delay.

-j

--
"Peter: We love the Bible in this house.
Francis: Really. What's your favorite book of the Bible?
Peter: Uhhhhh... the book where Jesus swallows the puzzle piece and the man in the yellow hat has to take him to the hospital."
--Family Guy

#3 lore raw
Quoted 3 lines

i'd second that notion. setup the OUTPUT chain to allow everything and see if that fixes it. if it does--figure out what traffic you need to be allowing out to prevent the delay.

Rather than allowing ident would it be possible to do a REJECT (via iptables -t filter -A OUTPUT -j REJECT) (I'm not sure if this can be a policy or not) that way the ident will fail immediately verses timing out? That is if you don't want the ident to happen. Seeing as how a LOT of servers don't even support ident any more this might just as well be an option.

Grant. . . .

#4 lore raw
Quoted 1 line

Rather than allowing ident would it be possible to do a REJECT (via iptables -t filter -A OUTPUT -j REJECT) (I'm not sure if this can be a policy or not) that way the ident will fail immediately verses timing out? That is if you don't want the ident to happen. Seeing as how a LOT of servers don't even support ident any more this might just as well be an option.

I have written some rules and posted them to the mail list (see https://lists.netfilter.org/pipermail/netfilter/2005-May/060150.html) on how to REJECT Ident (Auth) queries only for systems that you have recently sent SMTP traffic to. It would be fairly easy to extend it to work for Pop3 as well. Take a look if you are interested.

Grant. . . .

author
#5 lore raw

Re: Delay in responding caused by netfilter ? [Completely Solved]

In reply to Taylor, Grant

Hi all,

Quoted 8 lines · Grant

Rather than allowing ident would it be possible to do a REJECT (via iptables -t filter -A OUTPUT -j REJECT) (I'm not sure if this can be a policy or not) that way the ident will fail immediately verses timing out? That is if you don't want the ident to happen. Seeing as how a LOT of servers don't even support ident any more this might just as well be an option.

Which is what I did on one server (SuSE) and it solved the problem there.

The other server was different in that the problem occured not always, only about 80% of all connections were affected and only POP3. The real solution can be found here:

http://www.washington.edu/imap/IMAP-FAQs/index.html issue 7.24

Quick summary. Mostly the cause is either reverse DNS request timing out or ident requests also timing out. The latter happens on systems running xinetd. In e.g /etc/xinetd.d/ipop3 are lines like

log_on_success += USERID

These lines cause inetd to start an ident request. Delete all of these and similar lines in each file they occur, restart xinetd and the prolem is gone. No need to write rules :)

Thanks to all providing ideas and pointing me to ident.

Have a nice time,

Joerg

#6 lore raw

Re: Delay in responding caused by netfilter ? [Completely Solved]

Quoted 1 line

Which is what I did on one server (SuSE) and it solved the problem there.

*nod*

Quoted 5 lines

The other server was different in that the problem occured not always, only about 80% of all connections were affected and only POP3. The real solution can be found here:

http://www.washington.edu/imap/IMAP-FAQs/index.html issue 7.24

This article is written from the System Administrator's point of view, i.e. from the server end of the connection where as what I did was written from the end users point of view from the client end of the connection. The solution that this article talks about is how to configure the server to not even query for Ident (Auth) information. What I did was configure my firewall to do an automatic REJECT of any Ident (Auth) queries that come in to my firewall from an SMTP server that I have just recently spoken to. It is entirely possible that I could set up an SMTP server on my home server (that I would send all my outbound mail at the house through) that would connect to the ultimate MX for each peice of mail that I send out. The ultimate that I would talk to could be configured to send Ident (Auth) queries or it could just as easily be configured not to. This is the situation that I h ave no control over the server (ultimate MX) that would be sending the Ident (Auth) queri
es and this is the situation that I was addressing. Personally IMHO these are two distinct problems that are EXTREMELY closely related to each other both having to do with Ident (Auth) and SMTP (or POP3 in your case) for the same connection, but on the opposite end of said connection.

Quoted 1 line

Thanks to all providing ideas and pointing me to ident.

No problem and you are welcome. :)

Grant. . . .

#7 lore raw

Re: Delay in responding caused by netfilter ? [Completely Solved]

In reply to Jörg Harmuth
Quoted 22 lines · Jörg Harmuth

Hi all,

Quoted 6 lines · Grant

Rather than allowing ident would it be possible to do a REJECT (via iptables -t filter -A OUTPUT -j REJECT) (I'm not sure if this can be a policy or not) that way the ident will fail immediately verses timing out? That is if you don't want the ident to happen. Seeing as how a LOT of servers don't even support ident any more this might just as well be an option.

Which is what I did on one server (SuSE) and it solved the problem there.

The other server was different in that the problem occured not always, only about 80% of all connections were affected and only POP3. The real solution can be found here:

http://www.washington.edu/imap/IMAP-FAQs/index.html issue 7.24

Quick summary. Mostly the cause is either reverse DNS request timing out or ident requests also timing out. The latter happens on systems running xinetd. In e.g /etc/xinetd.d/ipop3 are lines like

Quoted 5 lines

log_on_success += USERID

These lines cause inetd to start an ident request. Delete all of these and similar lines in each file they occur, restart xinetd and the prolem is gone. No need to write rules :)

Indeed would be the issue -- I'll not gloat -- but it comes from experience
at work with a mail server that was doing the same thing .. 'twas an identd lookup that was waiting to time out when done through the firewall, but responding normally any other time. That happened to be a Cisco pix, but the cause and the symptom are the same. Also why I didn't suggest the solution, just the cause.

Alistair Tonner

Quoted 2 lines

Thanks to all providing ideas and pointing me to ident.

Welcome, 'swat we all hereabouts for.

Quoted 4 lines

Have a nice time,

Joerg

#8 lore raw
In reply to Alistair Tonner

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

sendmail likes to do an ident check and will slow if port 113 is not allowed to talk, popd might as Allister hints do the same, add rules to allow ident to pass and see if things run swifter.

Thanks,

Ron DuFresne

Quoted 86 lines · Alistair Tonner
Quoted 11 lines · Jörg Harmuth

Hi all,

Situation:

2 independant servers, one running RH7.2, the other SuSE8.1, with the same symptoms. There is a delay between the TCP/IP habdshake and the server greeting of 26 seconds (SuSE) or 32 seconds respectively (RH). Indeed everything is working, but there is this delay. Some tcpdump:

tcpdump -n -i bond1 'tcp[1] == 110 or tcp[3] == 110'
tcpdump: listening on bond1

This gets us the connection you are looking at, but drops anything else. So
-- we can't see things that MIGHT be going wrong.

Quoted 9 lines

13:25:24.835287 10.10.10.100.60719 > 81.169.151.156.110: S \
3714172130:3714172130(0) win 5840 <mss 1460,sackOK,timestamp \
335589204 0,nop,wscale 0> (DF) [tos 0x10]

13:25:24.879667 81.169.151.156.110 > 10.10.10.100.60719: S \
2643711030:2643711030(0) ack 3714172131 win 5792 <mss \
1460,sackOK,timestamp 17886154 335589204,nop,wscale 0> (DF)

Quoted 9 lines
13:25:24.879702 10.10.10.100.60719 > 81.169.151.156.110: . ack 1 win \
    5840 <nop,nop,timestamp 335589209 17886154> (DF) [tos 0x10]

13:25:50.964202 81.169.151.156.110 > 10.10.10.100.60719: P 1:35(34) \
ack 1 win 5792 <nop,nop,timestamp 17888762 335589209> (DF)

13:25:50.964224 10.10.10.100.60719 > 81.169.151.156.110: . ack 35 \
win 5840 <nop,nop,timestamp 335591818 17888762> (DF) [tos 0x10]

I'm wondering if that pop3 server is trying to do an identd check on the connection that is getting *b0rked* with the firewall up. Try that dump again and loosen the filter a tad.

Quoted 6 lines

...

This seems to concern only services that are started by inetd, so I thought inetd would cause this delay. But when I empty the chains (only having a default policy of ACCEPT, nothing more) this delay vanishes and everything is working as expected.

That might be part of the problem, but thing of what inetd/xinetd might be
doing to authenticate the connection before they start the server.

Quoted 39 lines

Complete ruleset:

*filter

:INPUT DROP [343:76556]
:FORWARD DROP [0:0]
:OUTPUT DROP [1648:107018]

(quoted diff) +0 -19
-A INPUT -i lo -j ACCEPT
-A INPUT -p tcp -m state --state RELATED,ESTABLISHED -j ACCEPT
-A INPUT -p tcp -m tcp --dport 22222 -m state --state NEW \
   --tcp-flags SYN,RST,ACK SYN -j ACCEPT
-A INPUT -p tcp -m tcp --dport 443 -m state --state NEW \
   --tcp-flags SYN,RST,ACK SYN -j ACCEPT
-A INPUT -p tcp -m tcp --dport 25 -m state --state NEW \
   --tcp-flags SYN,RST,ACK SYN -j ACCEPT
-A INPUT -p tcp -m tcp --dport 110 -m state --state NEW \
   --tcp-flags SYN,RST,ACK SYN -j ACCEPT
-A INPUT -p tcp -m tcp --dport 80 -m state --state NEW \
   --tcp-flags SYN,RST,ACK SYN -j ACCEPT
-A INPUT -p tcp -m tcp --dport 22 -m state --state NEW \
   --tcp-flags SYN,RST,ACK SYN -j ACCEPT
-A INPUT -p tcp -m tcp --dport 21 -m state --state NEW \
   --tcp-flags SYN,RST,ACK SYN -j ACCEPT
-A INPUT -p tcp -m tcp --dport 990 -m state --state NEW \
   --tcp-flags SYN,RST,ACK SYN  -j ACCEPT
-A INPUT -p tcp -m tcp --dport 21000:21199 -m state \
   --state NEW --tcp-flags SYN,RST,ACK SYN -j ACCEPT
-A INPUT -p udp -m udp --dport 53 -j ACCEPT
-A INPUT -p udp -m udp --dport 123 -j ACCEPT
-A INPUT -p udp -m udp --sport 53 -j ACCEPT
-A OUTPUT -o lo -j ACCEPT
-A OUTPUT -p tcp -m state --state RELATED,ESTABLISHED -j ACCEPT
-A OUTPUT -p udp -m udp --sport 123 -j ACCEPT
-A OUTPUT -p udp -m udp --sport 53 -j ACCEPT
-A OUTPUT -p udp -m udp --dport 53 -j ACCEPT

COMMIT

Quoted 10 lines
Quoted 8 lines

Nothing complicated in my eyes. I have absolutely no idea how this tiny ruleset can cause such delays or - at least - is involved in this.

Any ideas are highly welcome.

Thanks and have a nice time,

Joerg

- -- ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
admin & senior security consultant: sysinfo.com
http://sysinfo.com
Key fingerprint = 9401 4B13 B918 164C 647A E838 B2DF AFCC 94B0 6629

...We waste time looking for the perfect lover
instead of creating the perfect love.

-Tom Robbins <Still Life With Woodpecker>
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.2.4 (GNU/Linux)

iD8DBQFCcnLbst+vzJSwZikRAiuwAKCdITbONycqJqFhl0uyzkCmyA5ozQCg00Ao ZHlhWDO0ZJiGcUg3zOIbVeY=
=Tjkr
-----END PGP SIGNATURE-----