Postfix stellt Mails an einen bestimmten Benutzer nicht zu
Sylvia Gelman
sgelman at rmr.tu-darmstadt.de
Mi Mai 8 14:04:48 CEST 2019
Hallo Kai,
ohne debug Modus erkennt man nicht viel, dies ist das komplette Log beim
Senden einer Nachricht die dann in der Queue dauerhaft bleibt:
May 8 13:44:12 server postfix/smtpd[28381]: connect from
client.rt.e-technik.domain.de[IP]
May 8 13:44:12 server postfix/smtpd[28381]: Anonymous TLS connection
established from client.rt.e-technik.domain.de[IP]: TLSv1.2 with cipher
ECDHE-RSA-AES128
-GCM-SHA256 (128/128 bits)
May 8 13:44:12 server postfix/smtpd[28381]: 931E4240DF1:
client=client.rt.e-technik.domain.de[IP]
May 8 13:44:12 server postfix/cleanup[28385]: 931E4240DF1:
message-id=<4401d636-0ef2-5e43-cccf-b3dbf4ca3078 at domain.de>
May 8 13:44:12 server postfix/qmgr[28369]: 1AD5F240CBB: skipped, still
being delivered
May 8 13:44:12 server postfix/qmgr[28369]: 931E4240DF1:
from=<sgelman at domain.de>, size=989, nrcpt=1 (queue active)
May 8 13:44:12 server postfix/qmgr[28369]: AFECC240FAC: skipped, still
being delivered
May 8 13:44:12 server postfix/qmgr[28369]: 8D67B24092E: skipped, still
being delivered
May 8 13:44:12 server postfix/qmgr[28369]: 9B5BE2412F2: skipped, still
being delivered
May 8 13:44:12 server postfix/qmgr[28369]: E57042401C0: skipped, still
being delivered
May 8 13:44:12 server postfix/qmgr[28369]: 6591B240C30: skipped, still
being delivered
May 8 13:44:12 server postfix/qmgr[28369]: 4B1C92401BE: skipped, still
being delivered
May 8 13:44:12 server postfix/qmgr[28369]: 887BE2414AF: skipped, still
being delivered
May 8 13:44:12 server postfix/qmgr[28369]: 1017B24014C: skipped, still
being delivered
May 8 13:44:12 server postfix/qmgr[28369]: 56DBF240F35: skipped, still
being delivered
May 8 13:44:12 server postfix/qmgr[28369]: B9725240D4F: skipped, still
being delivered
May 8 13:44:12 server postfix/qmgr[28369]: 78BE1240A20: skipped, still
being delivered
May 8 13:44:12 server postfix/qmgr[28369]: C133624159E: skipped, still
being delivered
May 8 13:44:12 server postfix/smtpd[28381]: disconnect from
client.rt.e-technik.domain.de[IP]
Wie gesagt, im Debug Modus sieht man als letzte Zeile dies:
May 8 11:13:03 server postfix/local[25188]: set_eugid: euid 3147 egid 2002
dann steigt er aus, es kommt einfach garnichts mehr.
Bei einer normalen Mail die zugestellt wird, geht es ab hier
folgendermaßen weiter:
May 8 11:14:29 server postfix/local[25197]: set_eugid: euid 3005 egid 2017
May 8 11:14:29 server postfix/local[25197]: set_eugid: euid 110 egid 116
May 8 11:14:29 server postfix/local[25197]: deliver_dotforward: path
/home/atest/.forward expand_status 0 look_status -1
May 8 11:14:29 server postfix/local[25197]: deliver_mailbox[3]: local
atest recip atest at server.rt.e-technik.domain.de exten deliver
atest at server.rt.e-technik.domain.de exp_from
May 8 11:14:29 server postfix/local[25197]: been_here: mailbox atest: 0
May 8 11:14:29 server postfix/local[25197]: connect to subsystem
private/cyrus
May 8 11:14:29 server postfix/local[25197]: private/cyrus socket: wanted
attribute: status
May 8 11:14:29 server postfix/local[25197]: input attribute name: status
May 8 11:14:29 server postfix/local[25197]: input attribute value: 0
May 8 11:14:29 server postfix/local[25197]: private/cyrus socket: wanted
attribute: (list terminator)
May 8 11:14:29 server postfix/local[25197]: input attribute name: (end)
May 8 11:14:29 server postfix/local[25197]: send attr flags = 3
May 8 11:14:29 server postfix/local[25197]: send attr queue_name = active
May 8 11:14:29 server postfix/local[25197]: send attr queue_id = A682F240BE8
May 8 11:14:29 server postfix/local[25197]: send attr offset = 796
May 8 11:14:29 server postfix/local[25197]: send attr size = 991
May 8 11:14:29 server postfix/local[25197]: send attr nexthop =
server.rt.e-technik.domain.de
May 8 11:14:29 server postfix/local[25197]: send attr encoding = 8bit
May 8 11:14:29 server postfix/local[25197]: send attr sender =
sgelman at domain.de
May 8 11:14:29 server postfix/local[25197]: send attr envelope_id =
May 8 11:14:29 server postfix/local[25197]: send attr ret_flags = 0
May 8 11:14:29 server postfix/local[25197]: send attr time = [data 88 bytes]
May 8 11:14:29 server postfix/local[25197]: send attr log_client_name =
client.rt.e-technik.domain.de
May 8 11:14:29 server postfix/local[25197]: send attr log_client_address
= IP
May 8 11:14:29 server postfix/local[25197]: send attr log_client_port =
59252
May 8 11:14:29 server postfix/local[25197]: send attr log_protocol_name
= ESMTP
May 8 11:14:29 server postfix/local[25197]: send attr log_helo_name = [IP]
May 8 11:14:29 server postfix/local[25197]: send attr sasl_method =
May 8 11:14:29 server postfix/local[25197]: send attr sasl_username =
May 8 11:14:29 server postfix/local[25197]: send attr sasl_sender =
May 8 11:14:29 server postfix/local[25197]: send attr log_ident =
A682F240BE8
May 8 11:14:29 server postfix/local[25197]: send attr rewrite_context =
remote
May 8 11:14:29 server postfix/local[25197]: send attr recipient_count = 1
May 8 11:14:29 server postfix/local[25197]: send attr original_recipient
= atest at domain.de
May 8 11:14:29 server postfix/local[25197]: send attr recipient =
atest at server.rt.e-technik.domain.de
May 8 11:14:29 server postfix/local[25197]: send attr offset =
18446744073709551615
May 8 11:14:29 server postfix/local[25197]: send attr dsn_orig_rcpt =
rfc822;atest at domain.de
May 8 11:14:29 server postfix/local[25197]: send attr notify_flags = 0
May 8 11:14:29 server cyrus/master[25200]: about to exec
/usr/lib/cyrus/bin/lmtpd
May 8 11:14:29 server cyrus/lmtpunix[25200]: executed
May 8 11:14:29 server cyrus/lmtpunix[25200]: accepted connection
May 8 11:14:29 server cyrus/lmtpunix[25200]: lmtp connection preauth'd
as postman
May 8 11:14:29 server cyrus/lmtpunix[25200]: Delivered:
<f1f1c902-f952-dcc1-e911-541009709f76 at domain.de> to mailbox: user.atest
May 8 11:14:29 server cyrus/lmtpunix[25200]: USAGE atest user: 0.004000
sys: 0.000000
May 8 11:14:29 server postfix/pipe[25198]: A682F240BE8:
to=<atest at server.rt.e-technik.domain.de>, orig_to=<atest at domain.de>,
relay=cyrus, delay=0.28, delays=0.04/0.15/0/0.09, dsn=2.0.0, status=sent
(delivered via cyrus service)
May 8 11:14:29 server postfix/local[25197]: private/cyrus socket: wanted
attribute: status
May 8 11:14:29 server postfix/local[25197]: input attribute name: status
May 8 11:14:29 server postfix/local[25197]: input attribute value: (end)
May 8 11:14:29 server postfix/local[25197]: private/cyrus socket: wanted
attribute: diag_type
May 8 11:14:29 server postfix/local[25197]: input attribute name: diag_type
May 8 11:14:29 server postfix/local[25197]: input attribute value: (end)
May 8 11:14:29 server postfix/local[25197]: private/cyrus socket: wanted
attribute: diag_text
May 8 11:14:29 server postfix/local[25197]: input attribute name: diag_text
May 8 11:14:29 server postfix/local[25197]: input attribute value: (end)
May 8 11:14:29 server postfix/local[25197]: private/cyrus socket: wanted
attribute: mta_type
May 8 11:14:29 server postfix/local[25197]: input attribute name: mta_type
May 8 11:14:29 server postfix/local[25197]: input attribute value: (end)
May 8 11:14:29 server postfix/local[25197]: private/cyrus socket: wanted
attribute: mta_mname
May 8 11:14:29 server postfix/local[25197]: input attribute name: mta_mname
May 8 11:14:29 server postfix/local[25197]: input attribute value: (end)
May 8 11:14:29 server postfix/local[25197]: private/cyrus socket: wanted
attribute: action
May 8 11:14:29 server postfix/local[25197]: input attribute name: action
May 8 11:14:29 server postfix/local[25197]: input attribute value: (end)
May 8 11:14:29 server postfix/local[25197]: private/cyrus socket: wanted
attribute: reason
May 8 11:14:29 server postfix/local[25197]: input attribute name: reason
May 8 11:14:29 server postfix/local[25197]: input attribute value: (end)
May 8 11:14:29 server postfix/local[25197]: private/cyrus socket: wanted
attribute: status
May 8 11:14:29 server postfix/local[25197]: input attribute name: status
May 8 11:14:29 server postfix/local[25197]: input attribute value: 0
May 8 11:14:29 server postfix/local[25197]: private/cyrus socket: wanted
attribute: (list terminator)
May 8 11:14:29 server postfix/local[25197]: input attribute name: (end)
May 8 11:14:29 server postfix/local[25197]: deliver_request_final: send:
"" 0
May 8 11:14:29 server postfix/local[25197]: send attr status =
May 8 11:14:29 server postfix/local[25197]: send attr diag_type =
May 8 11:14:29 server postfix/local[25197]: send attr diag_text =
May 8 11:14:29 server postfix/local[25197]: send attr mta_type =
May 8 11:14:29 server postfix/local[25197]: send attr mta_mname =
May 8 11:14:29 server postfix/local[25197]: send attr action =
May 8 11:14:29 server postfix/local[25197]: send attr reason =
May 8 11:14:29 server postfix/local[25197]: send attr status = 0
May 8 11:14:29 server postfix/local[25197]: master_notify: status 1
May 8 11:14:29 server postfix/qmgr[25181]: A682F240BE8: removed
May 8 11:14:29 server postfix/local[25197]: connection closed
May 8 11:14:29 server postfix/local[25197]: watchdog_stop: 0x55ce67b12120
May 8 11:14:29 server postfix/local[25197]: watchdog_start: 0x55ce67b12120
Am 08.05.19 um 12:15 schrieb Kai Fürstenberg:
> Hi Sylvia,
>
> zunächst habe ich mich einmal geirrt: Postfix loggt kein "queued as", er
> gibt dieses aber an den einliefernden Server zurück, der es seinerseits
> loggt oder loggen kann.
>
>
> Bitte kein verbose und kein rumgeschnippsel mehr.
> Ich hätte gerne mal ein komplettes Log in ganz normaler Form.
>
> Nimm also bitte mal alle -vv raus aus der master.cf, postfix reload,
> postfix flush und poste den kompletten Logausschnmitt am besten so wie
> es ist, ohne Auslassungen oder Ergänzungen.
>
> Bzw. liefere mal eine neue Mail an den Empfänger ein und poste den
> kompletten Logausschnmitt am besten so wie es ist, ohne Auslassungen
> oder Ergänzungen.
>
>>> mich irritiert, dass es keine Logeinträge gibt. Mich irritiert auch,
>>> dass unter mailq keine Angaben zur Verzögerung eingetragen sind.
>>> Normalerweise steht da, warum es länger dauert oder ob die Mail of HOLD
>>> steht.
>> ja das irritiert mich ja auch, es müsste schon längst der Sender
>> informiert worden sein, dass die Mail nicht zugestellt werden konnte.
>>> Evtl. vorher den
>>> Loglevel von Cyrus höhersetzen.
>> Wo setze ich den Loglevel von Cyrus höher? Finde dazu nichts.
> Der Loglevel von Cyrus wird über syslogd gesteuert. In der Cyrus-Zeile
> musst du debug gesondert setzen.
>
> Wie gesagt, ist ewig her, dass ich den benutzt habe...
>
--
Sylvia Gelman
IT Organisation
Technische Universität Darmstadt
Institut für Automatisierungstechnik und Mechatronik - IAT
Fachgebiet Regelungsmethoden und Robotik (RMR)
Landgraf-Georg-Str. 4
Gebäude S3|10 Raum 409
D-64283 Darmstadt
Tel.: +49 6151 / 16-25055
Email: sgelman at rmr.tu-darmstadt.de
Mehr Informationen über die Mailingliste postfix-users