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=<[email protected]>
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=<[email protected]>, 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 [email protected] exten deliver
[email protected] 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 =
[email protected]
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
= [email protected]
May 8 11:14:29 server postfix/local[25197]: send attr recipient =
[email protected]
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;[email protected]
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:
<[email protected]> 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=<[email protected]>, orig_to=<[email protected]>,
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: [email protected]
