Postfix - timed out while sending message body

uhe · April 4, 2009, 8:44am

Hallo ,

ich nutzer den “Univention Corporate Server 2.1-0-0 (mountain beech)”. Ich hole die Mail über fetchmaíl von t-com
ab und versende über “relayhost = smtp.webpage.t-com.de”. Das Upload ohne Anlage funktioniert ohne Probleme. Schicke ich Mail mit Anlagen tritt folgender Fehler auf:

(conversation with smtp.webpage.t-com.de[80.152.31.131] timed out while sending message body)

postconf -n zeigt:

alias_database = hash:/etc/aliases
alias_maps = hash:/etc/aliases
append_dot_mydomain = no
broken_sasl_auth_clients = yes
canonical_maps = hash:/etc/postfix/canonical
command_directory = /usr/sbin
config_directory = /etc/postfix
content_filter = smtp-amavis:[127.0.0.1]:10024
daemon_directory = /usr/lib/postfix
local_recipient_maps = $virtual_maps
masquerade_domains = $mydomain
masquerade_exceptions = root
message_size_limit = 10240000
mydestination = $myhostname.$mydomain, localhost.$mydomain, kluge-bauplanung.de kluge-bauplanung.local, localhost, $transport_maps
mydomain = kluge-bauplanung.local
myhostname = frodo.kluge-bauplanung.local
mynetworks = 127.0.0.0/8, 192.168.0.0/24
myorigin = /etc/mailname
relay_domains = $mydestination
relayhost = smtp.webpage.t-com.de
relocated_maps = hash:/etc/postfix/relocated
smtp_helo_name = kluge-bauplanung.de
smtp_sasl_auth_enable = yes
smtp_sasl_password_maps = hash:/etc/postfix/smtp_auth
smtp_sasl_security_options = noanonymous
smtpd_recipient_restrictions = permit_mynetworks,permit_sasl_authenticated, reject_unauth_destination, reject_unlisted_recipient, check_policy_service unix:private/kolabpolicy
smtpd_sasl_auth_enable = yes
smtpd_sasl_local_domain =
smtpd_sasl_security_options = noanonymous
smtpd_sender_restrictions = permit_mynetworks, check_policy_service unix:private/kolabpolicy
smtpd_starttls_timeout = 300s
smtpd_timeout = 300s
smtpd_tls_auth_only = yes
smtpd_tls_cert_file = /etc/univention/ssl/frodo.kluge-bauplanung.local/cert.pem
smtpd_tls_key_file = /etc/univention/ssl/frodo.kluge-bauplanung.local/private.key
smtpd_tls_received_header = no
smtpd_tls_session_cache_timeout = 3600s
smtpd_use_tls = yes
tls_random_source = dev:/dev/urandom
transport_maps = hash:/etc/postfix/transport, ldap:ldaptransport

Danke für die Hilfe

-uhe

odabas · April 7, 2009, 9:58am

Hallo,

für die weitere Analyse dieses Problems wäre es hilfreich wenn Sie uns noch weitere Informationen zu kommen lassen können.
[ul]
[li]Gibt es diesbezüglich Meldungen bzw. Hinweise in den entsprechenden Log-Dateien
(/var/log/mail.err, ./mail.warn, …/mail.info)? Falls ja, könnten Sie den entsprechenden Abschnitt hier posten?

[/li]
[li]Wie groß sind die zu versendenden Mail-Anlagen?

[/li]
[li]Gibt es diesbezüglich evtl. Einschränkungen vom Relayhost?[/li][/ul]

Mit freundlichen Grüßen
Murat Odabas

uhe · April 7, 2009, 1:42pm

Hallo Herr Odabas,

in den Logs steht nur, dass die Nachricht gequeued wurde.

Vielleicht ist das insteressant:

root@frodo:/var/log# tail -f mail.warn
Apr 7 14:50:40 frodo fetchmail[10502]: Di 07 Apr 2009 14:50:40 CEST: schlafe 300 Sekunden langApr 7 14:50:50 frodo postfix/smtpd[16461]: connect from unknown[192.168.0.175]Apr 7 14:50:50 frodo cyrus/imaps[4213]: open: user wolle@kluge-bauplanung.local opened INBOX/Drafts
Apr 7 14:50:50 frodo postfix/smtpd[16461]: 4C5EE99161: client=unknown[192.168.0.175]Apr 7 14:50:50 frodo postfix/cleanup[16463]: 4C5EE99161: message-id=<751B418D-268D-40F5-A912-145BA58FC2C9@k
luge-bauplanung.de>
Apr 7 14:50:50 frodo postfix/qmgr[9694]: 4C5EE99161: from=wolfgang.staemmler@kluge-bauplanung.de, size=973873, nrcpt=1 (queue active)
Apr 7 14:50:50 frodo cyrus/imaps[4205]: append_fromstage: message 414 added to kluge-bauplanung.local!user.
wolle.Sent MessagesApr 7 14:50:50 frodo postfix/smtpd[16468]: connect from localhost[127.0.0.1]
Apr 7 14:50:50 frodo postfix/smtpd[16468]: DB74C99169: client=unknown[192.168.0.175]
Apr 7 14:50:50 frodo postfix/cleanup[16469]: DB74C99169: message-id=<751B418D-268D-40F5-A912-145BA58FC2C9@k
luge-bauplanung.de>Apr 7 14:50:51 frodo postfix/qmgr[9694]: DB74C99169: from=wolfgang.staemmler@kluge-bauplanung.de, size=97
4384, nrcpt=1 (queue active)
Apr 7 14:50:51 frodo postfix/smtpd[16468]: disconnect from localhost[127.0.0.1]
Apr 7 14:50:51 frodo amavis[3968]: (03968-09) Passed, wolfgang.staemmler@kluge-bauplanung.de -> <Uhe@gmh-
systems-ost.de>, quarantine SlzkZfeTAze8, Message-ID: <751B418D-268D-40F5-A912-145BA58FC2C9@kluge-bauplanung
.de>, Hits: -
Apr 7 14:50:51 frodo postfix/smtp[16465]: 4C5EE99161: to=Uhe@gmh-systems-ost.de, relay=127.0.0.1[127.0.0.1]:10024, delay=0.75, delays=0.17/0.04/0/0.55, dsn=2.6.0, status=sent (250 2.6.0 Ok, id=03968-09, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as DB74C99169)
Apr 7 14:50:51 frodo postfix/qmgr[9694]: 4C5EE99161: removed
Apr 7 14:50:51 frodo postfix/smtpd[16472]: connect from localhost[127.0.0.1]
Apr 7 14:50:51 frodo postfix/smtpd[16472]: 2178099161: client=localhost[127.0.0.1]Apr 7 14:50:51 frodo postfix/cleanup[16469]: 2178099161: message-id=<751B418D-268D-40F5-A912-145BA58FC2C9@k
luge-bauplanung.de>
Apr 7 14:50:51 frodo postfix/qmgr[9694]: DB74C99169: from=wolfgang.staemmler@kluge-bauplanung.de, size=97
4384, nrcpt=1 (queue active)
Apr 7 14:50:51 frodo postfix/smtpd[16468]: disconnect from localhost[127.0.0.1]
Apr 7 14:50:51 frodo amavis[3968]: (03968-09) Passed, wolfgang.staemmler@kluge-bauplanung.de -> <Uhe@gmh-
systems-ost.de>, quarantine SlzkZfeTAze8, Message-ID: <751B418D-268D-40F5-A912-145BA58FC2C9@kluge-bauplanung
.de>, Hits: -
Apr 7 14:50:51 frodo postfix/smtp[16465]: 4C5EE99161: to=Uhe@gmh-systems-ost.de, relay=127.0.0.1[127.0.0.1]:10024, delay=0.75, delays=0.17/0.04/0/0.55, dsn=2.6.0, status=sent (250 2.6.0 Ok, id=03968-09, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as DB74C99169)
Apr 7 14:50:51 frodo postfix/qmgr[9694]: 4C5EE99161: removed
Apr 7 14:50:51 frodo postfix/smtpd[16472]: connect from localhost[127.0.0.1]
Apr 7 14:50:51 frodo postfix/smtpd[16472]: 2178099161: client=localhost[127.0.0.1]Apr 7 14:50:51 frodo postfix/cleanup[16469]: 2178099161: message-id=<751B418D-268D-40F5-A912-145BA58FC2C9@k
luge-bauplanung.de>
Apr 7 14:50:51 frodo postfix/qmgr[9694]: 2178099161: from=wolfgang.staemmler@kluge-bauplanung.de, size=97
4574, nrcpt=1 (queue active)Apr 7 14:50:51 frodo postfix/smtpd[16472]: disconnect from localhost[127.0.0.1]
Apr 7 14:50:51 frodo postfix/pipe[16470]: DB74C99169: to=Uhe@gmh-systems-ost.de, relay=kolabfilter, delay
=0.45, delays=0.16/0.02/0/0.27, dsn=2.0.0, status=sent (delivered via kolabfilter service)
Apr 7 14:50:51 frodo postfix/qmgr[9694]: DB74C99169: removed
Apr 7 14:50:53 frodo cyrus/imaps[4213]: mailbox_expunge: removing mail kluge-bauplanung.local!user.wolle.Dr
afts:173Apr 7 14:50:53 frodo cyrus/imaps[4213]: Expunged 1 messages from kluge-bauplanung.local!user.wolle.Drafts
Apr 7 14:50:53 frodo cyrus/imaps[4213]: Deleted 1 messages from kluge-bauplanung.local!user.wolle.Drafts
Apr 7 14:51:07 frodo cyrus/imaps[4209]: open: user wolle@kluge-bauplanung.local opened INBOX/Apple Mail To
Do
Apr 7 14:51:07 frodo cyrus/imaps[4213]: open: user wolle@kluge-bauplanung.local opened INBOX/Sent Messages
Apr 7 14:51:08 frodo cyrus/imaps[4213]: open: user wolle@kluge-bauplanung.local opened INBOX/Sent Messages
Apr 7 14:51:50 frodo postfix/smtpd[16461]: disconnect from unknown[192.168.0.175]
Apr 7 14:52:57 frodo postfix/smtpd[16461]: connect from frodo.kluge-bauplanung.local[192.168.0.100]
Apr 7 14:52:57 frodo postfix/smtpd[16461]: disconnect from frodo.kluge-bauplanung.local[192.168.0.100]
Apr 7 14:54:59 frodo postfix/smtp[16473]: 2178099161: to=uhe@gmh-systems-ost.de, relay=smtp.webpage.t-com.de[80.152.31.131]:25, delay=249, delays=0.19/0.04/0.44/248, dsn=4.4.2, status=deferred (conversation with smtp.webpage.t-com.de[80.152.31.131] timed out while sending message body)
Apr 7 14:55:40 frodo fetchmail[10502]: erweckt um Di 07 Apr 2009 14:55:40 CEST
Apr 7 14:55:41 frodo fetchmail[10502]: Di 07 Apr 2009 14:55:41 CEST: schlafe 300 Sekunden lang

die Größe des Anhanges ist meiner Meinung nach bedeutungslos. Es muß nur eine
Anlage sein. Ich habe schon große Dateien (über 2MB) durchbekommen und bin bei
kleinen hängen geblieben.
Der Relayhost ist ja smtp.webpage.t-com.de und er funktioniert problemlos
bei der Nutzung als Einzelplatz (lokal ohne Kolab als Mailserver) mit Thunderbird
oder Apple Mail. Ich kenne keine Einschränkungen bezüglich des Relays.
Muss man vielleicht die SMTP Prozesse erhöhen?

Danke
Uwe Hentzschel

uhe · April 7, 2009, 1:44pm

Noch vergessen!

root@frodo:/var/log# mailq
-Queue ID- --Size-- ----Arrival Time---- -Sender/Recipient-------
2178099161 974574 Tue Apr 7 14:50:51 wolfgang.staemmler@kluge-bauplanung.de
(conversation with smtp.webpage.t-com.de[80.152.31.131] timed out while sending message body)
uhe@gmh-systems-ost.de

-uhe

odabas · April 9, 2009, 9:55am

Hallo,

Sie schrieben:

Dieses Verhalten könnte mit Ihrem Relayhost zusammenhängen. Vielleicht wäre es möglich das Sie einen anderen Relayhost verwenden, um diese Annahme zu prüfen?

Evtl. könnte in diesem Fall die Erhöhung der Postfix-Variable smtpd_timeout in der /etc/postfix/main.cf weiterhelfen, welche standardmäßig auf 300s eingestellt ist. Nach der Änderung müssten Sie die Postfix Konfigurationsdatei mit postfix reload neu einlesen.

Mit freundlichen Grüßen
Murat Odabas