[Postfixbuch-users] Timeouts beim senden
Jan Theofel
theofel at etes.de
Mi Aug 6 10:26:04 CEST 2003
Hallo zusammen,
ich habe mit folgender Konstellation ein Problem: Auf einem Linux-Server mit
permanenter Anbindung an das Internet läuft Postfix, dahinter befindet sich
ein HPUX mit sendmail.
Dieses sendmail fabriziert nun bei einigen E-Mails Timeouts. Dabei scheint es
sich eher um größere E-Mails zu handeln, aber nicht ausschliesslich.
In meiner postfix-Log sieht das so aus:
ug 6 09:26:31 gateway postfix/smtpd[4062]: connect from unix1.absender.de[194.175.86.2]
Aug 6 09:26:31 gateway postfix/smtpd[4062]: 136A0AB5A: client=unix1.absender.de[194.175.86.2]
Aug 6 09:34:43 gateway postfix/smtpd[4062]: timeout after DATA from unix1.absender.de[194.175.86.2]
Scheint erst mal ein sendmail-Problem zu sein. Dort sieht das so aus:
Aug 5 14:29:41 unix1 sendmail[13261]: h75CTRL6013261: from=<userxy at absender.com>, size=517889, class=0, nrcpts=1, msgid=<000001c35b4d$ecb59b40$78
56afc2 at PC20>, proto=ESMTP, daemon=MTA, relay=pc20.absender.de [194.175.86.120]
Aug 5 14:36:09 unix1 sendmail[13325]: h75CTRL6013261: to=<info at irgendwo.de>, delay=00:06:40, xdelay=00:06:27, mailer=relay, pri=120598, rela
y=gateway.absender.de. [194.175.86.60], dsn=4.0.0, stat=I/O error
Aug 5 15:07:40 unix1 sendmail[20607]: h75CTRL6013261: SYSERR(root): timeout writing message to gateway.absender.de.: Connection timed out with gateway.centa-
star.de.
Aug 5 15:07:40 unix1 sendmail[20607]: h75CTRL6013261: to=<info at irgendwo.de>, delay=00:38:11, xdelay=00:15:00, mailer=relay, pri=210598, rela
y=gateway.absender.de. [194.175.86.60], dsn=4.0.0, stat=Deferred
Nun hab ich mir gedacht, was soll, sollen die eben direkt den Linux-Postfix
als SMTP Server eintragen und direkt verschicken. Nur da scheint es auch
immer wieder dieses Problem zu geben. Ich fürchte daher, dass das Problem
bei Postfix zu suchen ist.
Bei der Suche im Netz habe ich jedoch auch gefunden, dass die sendmail-
Meldung "dsn=4.0.0, stat=I/O error" auf ein DNS Problem hinweist. Nur
nicht auf welches.
Daher habe ich mal ein ausführliches Protokoll beim postfix aktiviert
(Level 9) und den unten angefügten Log bekommen. Ich hoffe ich habe
ihn angemessen gekürzt.
Was kann ich tun um das Problem weiter einzugrenzen?
Danke + Gruß,
Jan
Aug 6 10:01:13 gateway postfix/smtpd[4736]: connect from unix1.absender.de[194.175.86.2]
Aug 6 10:01:13 gateway postfix/smtpd[4736]: > unix1.absender.de[194.175.86.2]: 220 gateway.absender.com ESMTP Postfix
Aug 6 10:01:13 gateway postfix/smtpd[4736]: watchdog_pat: 0x808a318
Aug 6 10:01:13 gateway postfix/smtpd[4736]: vstream_fflush_some: fd 10 flush 41
Aug 6 10:01:13 gateway postfix/smtpd[4736]: vstream_buf_get_ready: fd 10 got 26
Aug 6 10:01:13 gateway postfix/smtpd[4736]: < unix1.absender.de[194.175.86.2]: EHLO unix1.absender.de
Aug 6 10:01:13 gateway postfix/smtpd[4736]: > unix1.absender.de[194.175.86.2]: 250-gateway.absender.com
Aug 6 10:01:13 gateway postfix/smtpd[4736]: > unix1.absender.de[194.175.86.2]: 250-PIPELINING
Aug 6 10:01:13 gateway postfix/smtpd[4736]: > unix1.absender.de[194.175.86.2]: 250-SIZE 102400000
Aug 6 10:01:13 gateway postfix/smtpd[4736]: > unix1.absender.de[194.175.86.2]: 250-VRFY
Aug 6 10:01:13 gateway postfix/smtpd[4736]: > unix1.absender.de[194.175.86.2]: 250-ETRN
Aug 6 10:01:13 gateway postfix/smtpd[4736]: match_hostname: unix1.absender.de ~? 194.175.86.0/24
Aug 6 10:01:13 gateway postfix/smtpd[4736]: match_hostaddr: 194.175.86.2 ~? 194.175.86.0/24
Aug 6 10:01:13 gateway postfix/smtpd[4736]: > unix1.absender.de[194.175.86.2]: 250-XVERP
Aug 6 10:01:13 gateway postfix/smtpd[4736]: > unix1.absender.de[194.175.86.2]: 250 8BITMIME
Aug 6 10:01:13 gateway postfix/smtpd[4736]: watchdog_pat: 0x808a318
Aug 6 10:01:13 gateway postfix/smtpd[4736]: vstream_fflush_some: fd 10 flush 108
Aug 6 10:01:13 gateway postfix/smtpd[4736]: vstream_buf_get_ready: fd 10 got 59
Aug 6 10:01:13 gateway postfix/smtpd[4736]: < unix1.absender.de[194.175.86.2]: MAIL From:<matthias_schaffert at centa-star.com> SIZE=518225
Aug 6 10:01:13 gateway postfix/smtpd[4736]: extract_addr: input: <matthias_schaffert at centa-star.com>
Aug 6 10:01:13 gateway postfix/smtpd[4736]: extract_addr: result: matthias_schaffert at centa-star.com
Aug 6 10:01:13 gateway postfix/smtpd[4736]: fsspace: .: block size 4096, blocks free 9403861
Aug 6 10:01:13 gateway postfix/smtpd[4736]: smtpd_check_size: blocks 4096 avail 9403861 min_free 0 size 518225
Aug 6 10:01:13 gateway postfix/smtpd[4736]: connect to subsystem public/cleanup
Aug 6 10:01:13 gateway postfix/smtpd[4736]: public/cleanup socket: wanted attribute: queue_id
Aug 6 10:01:13 gateway postfix/smtpd[4736]: vstream_buf_get_ready: fd 13 got 20
Aug 6 10:01:13 gateway postfix/smtpd[4736]: input attribute name: queue_id
Aug 6 10:01:13 gateway postfix/smtpd[4736]: input attribute value: 91118950E
Aug 6 10:01:13 gateway postfix/smtpd[4736]: public/cleanup socket: wanted attribute: (list terminator)
Aug 6 10:01:13 gateway postfix/smtpd[4736]: input attribute name: (end)
Aug 6 10:01:13 gateway postfix/smtpd[4736]: send attr flags = 2
Aug 6 10:01:13 gateway postfix/smtpd[4736]: 91118950E: client=unix1.absender.de[194.175.86.2]
Aug 6 10:01:13 gateway postfix/smtpd[4736]: rec_put: type T len 10 data 1060156873
Aug 6 10:01:13 gateway postfix/smtpd[4736]: rec_put: type S len 33 data matthias_s
Aug 6 10:01:13 gateway postfix/smtpd[4736]: rec_put: type A len 31 data client_nam
Aug 6 10:01:13 gateway postfix/smtpd[4736]: rec_put: type A len 27 data client_add
Aug 6 10:01:13 gateway postfix/smtpd[4736]: rec_put: type A len 48 data message_or
Aug 6 10:01:13 gateway postfix/smtpd[4736]: rec_put: type A len 29 data helo_name=
Aug 6 10:01:13 gateway postfix/smtpd[4736]: rec_put: type A len 19 data protocol_n
Aug 6 10:01:13 gateway postfix/smtpd[4736]: > unix1.absender.de[194.175.86.2]: 250 Ok
Aug 6 10:01:13 gateway postfix/smtpd[4736]: watchdog_pat: 0x808a318
Aug 6 10:01:13 gateway postfix/smtpd[4736]: vstream_fflush_some: fd 10 flush 8
Aug 6 10:01:13 gateway postfix/smtpd[4736]: vstream_buf_get_ready: fd 10 got 48
Aug 6 10:01:13 gateway postfix/smtpd[4736]: < unix1.absender.de[194.175.86.2]: RCPT To:<name at empfaenger.de>
Aug 6 10:01:13 gateway postfix/smtpd[4736]: extract_addr: input: <name at empfaenger.de>
Aug 6 10:01:13 gateway postfix/smtpd[4736]: extract_addr: result: name at empfaenger.de
Aug 6 10:01:13 gateway postfix/smtpd[4736]: generic_checks: START
Aug 6 10:01:13 gateway postfix/smtpd[4736]: generic_checks: name=permit_mynetworks
Aug 6 10:01:13 gateway postfix/smtpd[4736]: permit_mynetworks: unix1.absender.de 194.175.86.2
Aug 6 10:01:13 gateway postfix/smtpd[4736]: match_hostname: unix1.absender.de ~? 194.175.86.0/24
Aug 6 10:01:13 gateway postfix/smtpd[4736]: match_hostaddr: 194.175.86.2 ~? 194.175.86.0/24
Aug 6 10:01:13 gateway postfix/smtpd[4736]: generic_checks: name=permit_mynetworks status=1
Aug 6 10:01:13 gateway postfix/smtpd[4736]: smtpd_check_rcptmap: name at empfaenger.de
Aug 6 10:01:13 gateway postfix/smtpd[4736]: event_request_timer: reset 0x805c770 0x808f920 100
Aug 6 10:01:13 gateway postfix/smtpd[4736]: send attr request = rewrite
Aug 6 10:01:13 gateway postfix/smtpd[4736]: send attr rule = canonicalize
Aug 6 10:01:13 gateway postfix/smtpd[4736]: send attr address = name at empfaenger.de
Aug 6 10:01:13 gateway postfix/smtpd[4736]: vstream_fflush_some: fd 14 flush 74
Aug 6 10:01:13 gateway postfix/smtpd[4736]: private/rewrite socket: wanted attribute: address
Aug 6 10:01:13 gateway postfix/smtpd[4736]: vstream_buf_get_ready: fd 14 got 40
Aug 6 10:01:13 gateway postfix/smtpd[4736]: input attribute name: address
Aug 6 10:01:13 gateway postfix/smtpd[4736]: input attribute value: name at empfaenger.de
Aug 6 10:01:13 gateway postfix/smtpd[4736]: private/rewrite socket: wanted attribute: (list terminator)
Aug 6 10:01:13 gateway postfix/smtpd[4736]: input attribute name: (end)
Aug 6 10:01:13 gateway postfix/smtpd[4736]: rewrite_clnt: canonicalize: name at empfaenger.de -> name at empfaenger.de
Aug 6 10:01:13 gateway postfix/smtpd[4736]: event_request_timer: reset 0x805c770 0x808f920 100
Aug 6 10:01:13 gateway postfix/smtpd[4736]: send attr request = resolve
Aug 6 10:01:13 gateway postfix/smtpd[4736]: send attr address = name at empfaenger.de
Aug 6 10:01:13 gateway postfix/smtpd[4736]: vstream_fflush_some: fd 14 flush 56
Aug 6 10:01:13 gateway postfix/smtpd[4736]: private/rewrite socket: wanted attribute: transport
Aug 6 10:01:13 gateway postfix/smtpd[4736]: vstream_buf_get_ready: fd 14 got 93
Aug 6 10:01:13 gateway postfix/smtpd[4736]: input attribute name: transport
Aug 6 10:01:13 gateway postfix/smtpd[4736]: input attribute value: smtp
Aug 6 10:01:13 gateway postfix/smtpd[4736]: private/rewrite socket: wanted attribute: nexthop
Aug 6 10:01:13 gateway postfix/smtpd[4736]: input attribute name: nexthop
Aug 6 10:01:13 gateway postfix/smtpd[4736]: input attribute value: empfaenger.de
Aug 6 10:01:13 gateway postfix/smtpd[4736]: private/rewrite socket: wanted attribute: recipient
Aug 6 10:01:13 gateway postfix/smtpd[4736]: input attribute name: recipient
Aug 6 10:01:13 gateway postfix/smtpd[4736]: input attribute value: name at empfaenger.de
Aug 6 10:01:13 gateway postfix/smtpd[4736]: private/rewrite socket: wanted attribute: flags
Aug 6 10:01:13 gateway postfix/smtpd[4736]: input attribute name: flags
Aug 6 10:01:13 gateway postfix/smtpd[4736]: input attribute value: 4096
Aug 6 10:01:13 gateway postfix/smtpd[4736]: private/rewrite socket: wanted attribute: (list terminator)
Aug 6 10:01:13 gateway postfix/smtpd[4736]: input attribute name: (end)
Aug 6 10:01:13 gateway postfix/smtpd[4736]: resolve_clnt_query: `name at empfaenger.de' -> t=`smtp' h=`empfaenger.de' r=`name at empfaenger.de'
Aug 6 10:01:13 gateway postfix/smtpd[4736]: ctable_locate: install entry key name at empfaenger.de
Aug 6 10:01:13 gateway postfix/smtpd[4736]: maps_find: name at empfaenger.de: not found
Aug 6 10:01:13 gateway postfix/smtpd[4736]: match_string: empfaenger.de ~? gateway.absender.com
Aug 6 10:01:13 gateway postfix/smtpd[4736]: match_list_match: empfaenger.de: no match
Aug 6 10:01:13 gateway postfix/smtpd[4736]: maps_find: @empfaenger.de: not found
Aug 6 10:01:13 gateway postfix/smtpd[4736]: mail_addr_find: name at empfaenger.de -> (not found)
Aug 6 10:01:13 gateway postfix/smtpd[4736]: maps_find: name at empfaenger.de: not found
Aug 6 10:01:13 gateway postfix/smtpd[4736]: match_string: empfaenger.de ~? gateway.absender.com
Aug 6 10:01:13 gateway postfix/smtpd[4736]: match_list_match: empfaenger.de: no match
Aug 6 10:01:13 gateway postfix/smtpd[4736]: maps_find: @empfaenger.de: not found
Aug 6 10:01:13 gateway postfix/smtpd[4736]: mail_addr_find: name at empfaenger.de -> (not found)
Aug 6 10:01:13 gateway postfix/smtpd[4736]: maps_find: name at empfaenger.de: not found
Aug 6 10:01:13 gateway postfix/smtpd[4736]: match_string: empfaenger.de ~? gateway.absender.com
Aug 6 10:01:13 gateway postfix/smtpd[4736]: match_list_match: empfaenger.de: no match
Aug 6 10:01:13 gateway postfix/smtpd[4736]: maps_find: @empfaenger.de: not found
Aug 6 10:01:13 gateway postfix/smtpd[4736]: mail_addr_find: name at empfaenger.de -> (not found)
Aug 6 10:01:13 gateway postfix/smtpd[4736]: rec_put: type R len 30 data a.dennenmo
Aug 6 10:01:13 gateway postfix/smtpd[4736]: > unix1.absender.de[194.175.86.2]: 250 Ok
Aug 6 10:01:13 gateway postfix/smtpd[4736]: watchdog_pat: 0x808a318
Aug 6 10:01:13 gateway postfix/smtpd[4736]: < unix1.absender.de[194.175.86.2]: DATA
Aug 6 10:01:13 gateway postfix/smtpd[4736]: rec_put: type M len 0 data
Aug 6 10:01:13 gateway postfix/smtpd[4736]: rec_put: type N len 71 data Received:
Aug 6 10:01:13 gateway postfix/smtpd[4736]: rec_put: type N len 59 data ?by gatewa
Aug 6 10:01:13 gateway postfix/smtpd[4736]: rec_put: type N len 77 data ?for <a.de
Aug 6 10:01:13 gateway postfix/smtpd[4736]: > unix1.absender.de[194.175.86.2]: 354 End data with <CR><LF>.<CR><LF>
Aug 6 10:01:13 gateway postfix/smtpd[4736]: vstream_fflush_some: fd 13 flush 467
Aug 6 10:01:13 gateway postfix/smtpd[4736]: vstream_fflush_some: fd 10 flush 45
Aug 6 10:01:13 gateway postfix/smtpd[4736]: vstream_buf_get_ready: fd 10 got 1460
Aug 6 10:01:13 gateway postfix/smtpd[4736]: rec_put: type N len 57 data Received:
Aug 6 10:01:13 gateway postfix/smtpd[4736]: rec_put: type N len 68 data ?by unix1.
Aug 6 10:01:13 gateway postfix/smtpd[4736]: rec_put: type N len 78 data ?for <a.de
Aug 6 10:01:13 gateway postfix/smtpd[4736]: rec_put: type N len 44 data Reply-To:
[...]
Aug 6 10:01:14 gateway postfix/smtpd[4736]: rec_put: type N len 62 data 279.279 ln
Aug 6 10:01:14 gateway postfix/smtpd[4736]: rec_put: type N len 67 data cv=0D177.4
Aug 6 10:01:14 gateway postfix/smtpd[4736]: rec_put: type N len 72 data 273.069 ln
Aug 6 10:01:14 gateway postfix/smtpd[4736]: rec_put: type N len 64 data ln=0D177.0
Aug 6 10:01:14 gateway postfix/smtpd[4736]: rec_put: type N len 74 data ln=0D175.3
Aug 6 10:01:14 gateway postfix/smtpd[4736]: rec_put: type N len 70 data 278.496 17
Aug 6 10:01:14 gateway postfix/smtpd[4736]: rec_put: type N len 73 data 279.9 174.
Aug 6 10:01:14 gateway postfix/smtpd[4736]: rec_put: type N len 69 data 279.324 17
Aug 6 10:01:14 gateway postfix/smtpd[4736]: rec_put: type N len 74 data 275.994 cv
Aug 6 10:01:14 gateway postfix/smtpd[4736]: rec_put: type N len 74 data 275.49 cv=
Aug 6 10:06:14 gateway postfix/smtpd[4736]: > unix1.absender.de[194.175.86.2]: 421 Error: timeout exceeded
Aug 6 10:06:15 gateway postfix/smtpd[4736]: vstream_fflush_some: fd 10 flush 29
Aug 6 10:06:15 gateway postfix/smtpd[4736]: timeout after DATA from unix1.absender.de[194.175.86.2]
Aug 6 10:06:15 gateway postfix/smtpd[4736]: vstream_fflush_some: fd 10 flush 0
Aug 6 10:06:15 gateway postfix/smtpd[4736]: vstream_fflush_some: fd 13 flush 3891
Aug 6 10:06:15 gateway postfix/smtpd[4736]: disconnect from unix1.absender.de[194.175.86.2]
--
Jan Theofel Fon: +49 (7 11) 48 90 83 - 0
ETES - EDV-Systemhaus GbR Fax: +49 (7 11) 48 90 83 - 50
Libanonstrasse 58 A * D-70184 Stuttgart Web: http://www.etes.de
______________________________________
Inflex - eMail Scanning and Protection
Queries to: postmaster at etes.de
Mehr Informationen über die Mailingliste Postfixbuch-users