[Postfixbuch-users] welcher timeout parameter für eingehende Mails

Andreas Winkelmann ml at awinkelmann.de
Di Jan 23 23:31:14 CET 2007


On Tuesday 23 January 2007 18:51, Uwe Driessen wrote:

> Mal einen anderen Server von dem ich annehme das er richtig konfiguriert
> ist aber dennoch immer ein connection lost kommt.
> Ich habe allerdings immer nur die ersten 160 byte mitgelockt
>

> 14:04:15.070954 IP (tos 0x0, ttl  56, id 12818, offset 0, flags [DF],
> proto: TCP (6), length: 60) plasma.35792 > fblan.smtp: S, cksum 0x7340
> (correct), 3359409039:3359409039(0) win 5840 <mss 1460,sackOK,timestamp
> 2309665181 0,nop,wscale 2>
>         0x0000:  4500 003c 3212 4000 3806 65b3 d5cb ee0a  E..<2. at .8.e.....
>         0x0010:  c19e 2582 8bd0 0019 c83c 838f 0000 0000  ..%......<......
>         0x0020:  a002 16d0 7340 0000 0204 05b4 0402 080a  ....s at ..........
>         0x0030:  89aa b19d 0000 0000 0103 0302            ............

> 14:04:15.071219 IP (tos 0x0, ttl  64, id 0, offset 0, flags [DF], proto:
> TCP (6), length: 60) fblan.smtp > plasma.35792: S, cksum 0x913b (correct),
> 2222965403:2222965403(0) ack 3359409040 win 5736 <mss 1446,sackOK,timestamp
> 71014161 2309665181,nop,wscale 4>
>         0x0000:  4500 003c 0000 4000 4006 8fc5 c19e 2582  E..<.. at .@.....%.
>         0x0010:  d5cb ee0a 0019 8bd0 847f c29b c83c 8390  .............<..
>         0x0020:  a012 1668 913b 0000 0204 05a6 0402 080a  ...h.;..........
>         0x0030:  043b 9711 89aa b19d 0103 0304            .;..........

> 14:04:15.100917 IP (tos 0x0, ttl  56, id 12819, offset 0, flags [DF],
> proto: TCP (6), length: 52) plasma.35792 > fblan.smtp: ., cksum 0xd084
> (correct), ack 1 win 1460 <nop,nop,timestamp 2309665219 71014161>
>         0x0000:  4500 0034 3213 4000 3806 65ba d5cb ee0a  E..42. at .8.e.....
>         0x0010:  c19e 2582 8bd0 0019 c83c 8390 847f c29c  ..%......<......
>         0x0020:  8010 05b4 d084 0000 0101 080a 89aa b1c3  ................
>         0x0030:  043b 9711                                .;..

Ok Client verbindet sich zu Dir. Normaler Verbindungsaufbau.

> 14:04:40.245548 IP (tos 0x0, ttl  64, id 21892, offset 0, flags [DF],
> proto: TCP (6), length: 71) fblan.smtp > plasma.35792: P, cksum 0xf34e
> (correct), 1:    20(19) ack 1 win 359 <nop,nop,timestamp 71020454
> 2309665219> 0x0000:  4500 0047 5584 4000 4006 3a36 c19e 2582 
> E..GU. at .@.:6..%. 0x0010:  d5cb ee0a 0019 8bd0 847f c29c c83c 8390 
> .............<.. 0x0020:  8018 0167 f34e 0000 0101 080a 043b afa6 
> ...g.N.......;.. 0x0030:  89aa b1c3 3232 3020 6d61 696c 2e66 626c 
> ....220.mail.fbl 0x0040:  616e 2e64 650d 0a                        an.de..

Dein Banner geht zum Client

> 14:04:40.272618 IP (tos 0x0, ttl  56, id 12820, offset 0, flags [DF],
> proto: TCP (6), length: 52) plasma.35792 > fblan.smtp: ., cksum 0x5580
> (correct), ack   20 win 1460 <nop,nop,timestamp 2309690399 71020454>
>         0x0000:  4500 0034 3214 4000 3806 65b9 d5cb ee0a  E..42. at .8.e.....
>         0x0010:  c19e 2582 8bd0 0019 c83c 8390 847f c2af  ..%......<......
>         0x0020:  8010 05b4 5580 0000 0101 080a 89ab 141f  ....U...........
>         0x0030:  043b afa6                                .;..

Wird vom Client bestätigt.

> 14:04:40.272875 IP (tos 0x0, ttl  56, id 12821, offset 0, flags [DF],
> proto: TCP (6), length: 77) plasma.35792 > fblan.smtp: P, cksum 0x1c38
> (correct), 1:    26(25) ack 20 win 1460 <nop,nop,timestamp 2309690399
> 71020454> 0x0000:  4500 004d 3215 4000 3806 659f d5cb ee0a 
> E..M2. at .8.e..... 0x0010:  c19e 2582 8bd0 0019 c83c 8390 847f c2af 
> ..%......<...... 0x0020:  8018 05b4 1c38 0000 0101 080a 89ab 141f 
> .....8.......... 0x0030:  043b afa6 4548 4c4f 2070 6c61 736d 612e 
> .;..EHLO.plasma. 0x0040:  6a70 6265 726c 696e 2e64 650d 0a        
> jpberlin.de.. 

Der Client schickt ein EHLO...

> 14:04:40.273047 IP (tos 0x0, ttl  64, id 21893, offset 0, 
> flags [DF], proto: TCP (6), length: 52) fblan.smtp > plasma.35792: ., cksum
> 0x59ad (correct), ack   26 win 359 <nop,nop,timestamp 71020461 2309690399>
>         0x0000:  4500 0034 5585 4000 4006 3a48 c19e 2582  E..4U. at .@.:H..%.
>         0x0010:  d5cb ee0a 0019 8bd0 847f c2af c83c 83a9  .............<..
>         0x0020:  8010 0167 59ad 0000 0101 080a 043b afad  ...gY........;..
>         0x0030:  89ab 141f                                ....

Wird von Dir bestätigt.

> 14:04:40.273455 IP (tos 0x0, ttl  64, id 21894, offset 0, flags [DF],
> proto: TCP (6), length: 248) fblan.smtp > plasma.35792: P 20:216(196) ack
> 26 win 359    <nop,nop,timestamp 71020461 2309690399>
>         0x0000:  4500 00f8 5586 4000 4006 3983 c19e 2582  E...U. at .@.9...%.
>         0x0010:  d5cb ee0a 0019 8bd0 847f c2af c83c 83a9  .............<..
>         0x0020:  8018 0167 5c9e 0000 0101 080a 043b afad  ...g\........;..
>         0x0030:  89ab 141f 3235 302d 6d61 696c 2e66 626c  ....250-mail.fbl
>         0x0040:  616e 2e64 650d 0a32 3530 2d50 4950 454c  an.de..250-PIPEL
>         0x0050:  494e 494e 470d 0a32 3530 2d53 495a 4520  INING..250-SIZE.
>         0x0060:  3330 3030 3030 3030 0d0a 3235 302d 4554  30000000..250-ET
>         0x0070:  524e 0d0a 3235 302d 4155 5448 204c 4f47  RN..250-AUTH.LOG
>         0x0080:  494e 2050 4c41 494e 2044 4947 4553 542d  IN.PLAIN.DIGEST-
>         0x0090:  4d44 3520 4352 414d 2d4d 4435 0d0a 3235  MD5.CRAM-MD5..25
>         0x00a0:  302d 4155 5448 3d4c 4f47 494e 2050 4c41  0-AUTH=LOGIN.PLA
>         0x00b0:  494e 2044 4947 4553 542d                 IN.DIGEST-

Du schickst dem Client die Featureliste (inkl. PIPELINING)

> 14:04:40.302566 IP (tos 0x0, ttl  56, id 12822, offset 0, flags [DF],
> proto: TCP (6), length: 141) plasma.35792 > fblan.smtp: P, cksum 0x87d3
> (correct), 26:  115(89) ack 216 win 1728 <nop,nop,timestamp 2309690427
> 71020461> 0x0000:  4500 008d 3216 4000 3806 655e d5cb ee0a 
> E...2. at .8.e^.... 0x0010:  c19e 2582 8bd0 0019 c83c 83a9 847f c373 
> ..%......<.....s 0x0020:  8018 06c0 87d3 0000 0101 080a 89ab 143b 
> ...............; 0x0030:  043b afad 4d41 494c 2046 524f 4d3a 3c70 
> .;..MAIL.FROM:<p 0x0040:  2e68 6569 6e6c 6569 6e40 6865 696e 6c65 
> .heinlein at heinle 0x0050:  696e 2d73 7570 706f 7274 2e64 653e 2053 
> in-support.de>.S 0x0060:  495a 453d 3338 3034 0d0a 5243 5054 2054 
> IZE=3804..RCPT.T 0x0070:  4f3a 3c64 7269 6573 7365 6e40 6662 6c61 
> O:<driessen at fbla 0x0080:  6e2e 6465 3e0d 0a44 4154 410d 0a        
> n.de>..DATA.. 

Der Client bestätigt das Paket und schickt sofort in einem Rutsch MAIL FROM, 
RCPT TO, DATA. Normales Pipelining halt.

> 14:04:40.344079 IP (tos 0x0, ttl  64, id 21895, offset 0, 
> flags [DF], proto: TCP (6), length: 52) fblan.smtp > plasma.35792: ., cksum
> 0x5862 (correct), ack   115 win 359 <nop,nop,timestamp 71020479 2309690427>
>         0x0000:  4500 0034 5587 4000 4006 3a46 c19e 2582  E..4U. at .@.:F..%.
>         0x0010:  d5cb ee0a 0019 8bd0 847f c373 c83c 8402  ...........s.<..
>         0x0020:  8010 0167 5862 0000 0101 080a 043b afbf  ...gXb.......;..
>         0x0030:  89ab 143b                                ...;

Das wird von Dir bestätigt.

> 14:05:10.303879 IP (tos 0x0, ttl  56, id 12823, offset 0, flags [DF],
> proto: TCP (6), length: 52) plasma.35792 > fblan.smtp: F, cksum 0xddd1
> (correct), 115:  115(0) ack 216 win 1728 <nop,nop,timestamp 2309720433
> 71020479> 0x0000:  4500 0034 3217 4000 3806 65b6 d5cb ee0a 
> E..42. at .8.e..... 0x0010:  c19e 2582 8bd0 0019 c83c 8402 847f c373 
> ..%......<.....s 0x0020:  8011 06c0 ddd1 0000 0101 080a 89ab 8971 
> ...............q 0x0030:  043b afbf                                .;..

Und hier wird es wohl interessant. 30 Sekunden passiert nix und der Client 
fängt an die Verbindung abzubauen. Kann man ihm wohl auch nicht unbedingt 
übelnehmen.

> 14:05:10.344176 IP (tos 0x0, ttl  64, id 21896, offset 0, flags [DF],
> proto: TCP (6), length: 52) fblan.smtp > plasma.35792: ., cksum 0xc5de
> (correct), ack   116 win 359 <nop,nop,timestamp 71027979 2309720433>
>         0x0000:  4500 0034 5588 4000 4006 3a45 c19e 2582  E..4U. at .@.:E..%.
>         0x0010:  d5cb ee0a 0019 8bd0 847f c373 c83c 8403  ...........s.<..
>         0x0020:  8010 0167 c5de 0000 0101 080a 043b cd0b  ...g.........;..
>         0x0030:  89ab 8971                                ...q

Der Verbindungsabbau wird bestätigt. Ich bin mir jetzt nicht sicher in wie 
weit das Postfix mitbekommt. Denke mal das macht der Kernel selber. Da 
Postfix ja später noch Daten schickt. siehe unten.

> 14:05:45.632613 IP (tos 0x0, ttl  64, id 21897, offset 0, flags [DF],
> proto: TCP (6), length: 80) fblan.smtp > plasma.35792: P, cksum 0xf9b5
> (correct), 216:  244(28) ack 116 win 359 <nop,nop,timestamp 71036801
> 2309720433> 0x0000:  4500 0050 5589 4000 4006 3a28 c19e 2582 
> E..PU. at .@.:(..%. 0x0010:  d5cb ee0a 0019 8bd0 847f c373 c83c 8403 
> ...........s.<.. 0x0020:  8018 0167 f9b5 0000 0101 080a 043b ef81 
> ...g.........;.. 0x0030:  89ab 8971 3235 3020 322e 312e 3020 4f6b 
> ...q250.2.1.0.Ok 0x0040:  0d0a 3235 3020 322e 312e 3520 4f6b 0d0a 
> ..250.2.1.5.Ok.. 

Jetzt schickt Postfix die Antwort auf MAIL FROM, RCPT TO....

> 14:05:45.636000 IP (tos 0x0, ttl  64, id 21898, offset 0, 
> flags [DF], proto: TCP (6), length: 89) fblan.smtp > plasma.35792: FP,
> cksum 0x7241 (correct), 244: 281(37) ack 116 win 359 <nop,nop,timestamp
> 71036801 2309720433> 0x0000:  4500 0059 558a 4000 4006 3a1e c19e 2582 
> E..YU. at .@.:...%. 0x0010:  d5cb ee0a 0019 8bd0 847f c38f c83c 8403 
> .............<.. 0x0020:  8019 0167 7241 0000 0101 080a 043b ef81 
> ...grA.......;.. 0x0030:  89ab 8971 3335 3420 456e 6420 6461 7461 
> ...q354.End.data 0x0040:  2077 6974 6820 3c43 523e 3c4c 463e 2e3c 
> .with.<CR><LF>.< 0x0050:  4352 3e3c 4c46 3e0d 0a                  
> CR><LF>.. 

Und die Antwort auf DATA. Also ist Postfix jetzt bereit Daten vom Client zu 
bekommen. Dies sind nun 65 Sekunden seit der Client MAIL FROM, RCPT TO und 
DATA geschickt hat. Ein wenig happig vielleicht.

> 14:05:45.668438 IP (tos 0x0, ttl  56, id 0, offset 0, flags [DF], 
> proto: TCP (6), length: 40) plasma.35792 > fblan.smtp: R, cksum 0x2cc0
> (correct), 3359409155:3359409155(0) win 0
>         0x0000:  4500 0028 0000 4000 3806 97d9 d5cb ee0a  E..(.. at .8.......
>         0x0010:  c19e 2582 8bd0 0019 c83c 8403 0000 0000  ..%......<......
>         0x0020:  5004 0000 2cc0 0000 0000 0000 0000       P...,.........
> 14:05:45.673380 IP (tos 0x0, ttl  56, id 0, offset 0, flags [DF], proto:
> TCP (6), length: 40) plasma.35792 > fblan.smtp: R, cksum 0x2cc0 (correct),
> 3359409155:3359409155(0) win 0
>         0x0000:  4500 0028 0000 4000 3806 97d9 d5cb ee0a  E..(.. at .8.......
>         0x0010:  c19e 2582 8bd0 0019 c83c 8403 0000 0000  ..%......<......
>         0x0020:  5004 0000 2cc0 0000 0000 0000 0000       P...,.........

Der Client versucht noch die Verbindung zurückzusetzen. Ist eh vorbei.

Hmm, entweder ist Dein System so ausgelastet, dass Postfix das Paket erst sehr 
spät vom Kernel bekommt oder Du solltest Deine smtpd_*_restrictions 
überdenken. Evtl. ein oder zwei DNS-Timeouts rbl oder sowas. Oder ein lahmer 
Policy-Service. Du könntest mal im smtpd das Verbose Logging einschalten und 
die Uhrzeiten kontrollieren. Was da >60 Sekunden braucht.

-- 
	Andreas



Mehr Informationen über die Mailingliste Postfixbuch-users