Re: Postfix stellt Mails an einen bestimmten Benutzer nicht zu
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@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@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@server.rt.e-technik.domain.de exten deliver atest@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@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@domain.de
May 8 11:14:29 server postfix/local[25197]: send attr recipient = atest@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@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@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@server.rt.e-technik.domain.de, orig_to=atest@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...
Hallo Sylvia,
ich habe folgende Fragen/Bitten (in der Hoffnung, diese Infos im Thread nicht überlsen zu haben):
(1) Schicke mal bitte noch Deine master.conf
(2) Nur zur Sicherheit gefragt: Du schreibst eingangs, dass das Problem bei _einem_ neu angelegten User auftritt. Im weiteren Verlauf erwähnst Du dann aber das hier:
Im cyradm, ist die Mailbox mit 'listmailbox' gelistet?
ja beide Accounts. Ich habe ja nochmal alles neu gemacht, mit den üblichen Mitarbeiterrechten:
-----^^^^^
Handelt es sich demnach also eigentlich um _zwei_ Accounts? Das würde sich ja auch mit dieser Auflistung decken:
user/michavogt (\HasChildren)
[...]
user/mvogt (\HasChildren)
[...]
Oder war das nur zum Testen ("nochmal alles neu gemacht"), damit Du einen weiteren neuen User zur Verfügung hast?
(3)
Die Rechte unter /var/spool/cyrus/mail/m/user stimmen bei den Accounts auch.
Ich glaube Dir das zwar ;-), aber schicke bitte trotzdem mal das Listing dieser drei Verzeichnisse, damit man die Owner/Permissions sehen kann:
a) /var/spool/cyrus/mail/a/user/atest b) /var/spool/cyrus/mail/m/user/michavogt c) /var/spool/cyrus/mail/m/user/mvogt
(4) Welchen Output erhälst Du jeweils, wenn Du diese Abfragen durchführst:
a) postmap -q atest@server.rt.e-technik.domain.de ldap:/etc/postfix/ldap-aliases.cf b) postmap -q michavogt@server.rt.e-technik.domain.de ldap:/etc/postfix/ldap-aliases.cf c) postmap -q mvogt@server.rt.e-technik.domain.de ldap:/etc/postfix/ldap-aliases.cf
In diesem Zusammenhang: Es dürfte mit Deinem konkreten Problem nix zu tun haben, aber ändere in Deiner main.cf diese Zeile:
virtual_alias_maps = ldap:/etc/postfix/ldap-aliases.cf
mal besser folgendermaßen:
virtual_alias_maps = proxy:ldap:/etc/postfix/ldap-aliases.cf
(5) Auch wenn es lt. Deiner Info nicht genutzt wird - zeige mal bitte die Owner/Permissions und Inhalte von:
a) /home/atest/ b) /home/michavogt/ c) /home/mvogt/
Was Deine Frage zum Cyrus-Debug betrifft: Ich habe hier u. a. noch ein älteres Debian-System, da steht in der /etc/imapd.conf das hier drin (falls Du das ganze Cyrus-Zeugs genauer untersuchen willst):
## ## DEBUGGING ## # Debugging hook. See /usr/share/doc/cyrus-common-2.2/README.Debian.debug # Keep the hook disabled when it is not in use # # gdb Back-traces #debug_command: /usr/bin/gdb -batch -cd=/tmp -x /usr/lib/cyrus/get-backtrace.gdb /usr/lib/cyrus/bin/%s %d
/tmp/gdb-backtrace.cyrus.%1$s.%2$d <&- 2>&1 &
# # system-call traces #debug_command: /usr/bin/strace -tt -o /tmp/strace.cyrus.%s.%d -p %2$d <&- 2>&1 & # # library traces #debug_command: /usr/bin/ltrace -tt -n 2 -o /tmp/ltrace.cyrus.%s.%d -p %2$d <&- 2>&1 &
Viele Grüße Markus
participants (2)
-
Markus Winkler -
Sylvia Gelman