[Dovecot] %{session} does not work with deliver_log_format
Hi,
# 2.1.10: /etc/dovecot/dovecot.conf # OS: Linux 2.6.32-45-server x86_64 Ubuntu 10.04.4 LTS deliver_log_format = mailbox: deliver: session=<%{session}> msgid=%m from=%f: %$
produces log messages always containing "session=
Feb 24 09:22:09 10.129.3.233 dovecot: lmtp(3484, user@example.org): mbnWK6/NKVGcDQAAiWCYmA: sieve: mailbox: deliver: session=
http://wiki2.dovecot.org/Variables leads me to the assumption that %{session} works "everywhere" and for deliver_log_format too.
Is deliver_log_format variable expansion handled differently from login_log_format_elements and mail_log_prefix?
Regards Daniel
On 25.2.2013, at 0.53, Daniel Parthey daniel.parthey@informatik.tu-chemnitz.de wrote:
# 2.1.10: /etc/dovecot/dovecot.conf # OS: Linux 2.6.32-45-server x86_64 Ubuntu 10.04.4 LTS deliver_log_format = mailbox: deliver: session=<%{session}> msgid=%m from=%f: %$
produces log messages always containing "session=
", like this one: Feb 24 09:22:09 10.129.3.233 dovecot: lmtp(3484, user@example.org): mbnWK6/NKVGcDQAAiWCYmA: sieve: mailbox: deliver: session=
msgid=20130224082208.8A807C0CF@mx01.example.org from=postmaster@example.org: stored mail into mailbox 'INBOX/postmaster' http://wiki2.dovecot.org/Variables leads me to the assumption that %{session} works "everywhere" and for deliver_log_format too.
Added "(almost)" :)
Is deliver_log_format variable expansion handled differently from login_log_format_elements and mail_log_prefix?
Very differently. Hmm.
The idea behind imap/pop3 session IDs is to track the session through proxies, authentication, etc.
LMTP has a completely different session ID currently, which gets reset for each mail delivery and is written to the Received: header that it writes. It doesn't traverse through proxies, because each delivery gets a different ID anyway.
So .. Why is it that you want this? For matching a log line with a Received: header? I guess that could be done, but the name should probably be different from %{session} so it won't get mixed up with what IMAP/POP3 uses it for.
Timo Sirainen wrote:
On 25.2.2013, at 0.53, Daniel Parthey daniel.parthey@informatik.tu-chemnitz.de wrote:
# 2.1.10: /etc/dovecot/dovecot.conf # OS: Linux 2.6.32-45-server x86_64 Ubuntu 10.04.4 LTS deliver_log_format = mailbox: deliver: session=<%{session}> msgid=%m from=%f: %$
produces log messages always containing "session=
", like this one: Feb 24 09:22:09 10.129.3.233 dovecot: lmtp(3484, user@example.org): mbnWK6/NKVGcDQAAiWCYmA: sieve: mailbox: deliver: session=
msgid=20130224082208.8A807C0CF@mx01.example.org from=postmaster@example.org: stored mail into mailbox 'INBOX/postmaster' http://wiki2.dovecot.org/Variables leads me to the assumption that %{session} works "everywhere" and for deliver_log_format too.
Added "(almost)" :)
Is deliver_log_format variable expansion handled differently from login_log_format_elements and mail_log_prefix?
Very differently. Hmm.
The idea behind imap/pop3 session IDs is to track the session through proxies, authentication, etc.
LMTP has a completely different session ID currently, which gets reset for each mail delivery and is written to the Received: header that it writes. It doesn't traverse through proxies, because each delivery gets a different ID anyway.
So .. Why is it that you want this? For matching a log line with a Received: header? I guess that could be done, but the name should probably be different from %{session} so it won't get mixed up with what IMAP/POP3 uses it for.
I simply run an LMTP director/proxy to prevent NFS locking issues and in error cases I want to investigate where the mail has gone (through the director lmtp to the mailbox lmtp). I thought this is what "session IDs" were intended for.
Obviously, the generated ID is a different one for director and mailbox, looking at the Received: lines of a single message:
Received: from mail01.example.org ([10.129.3.193]) by mail01.example.org (Dovecot) with LMTP id vdSeD+CrK1HXZQAAiWCYmA ; Mon, 25 Feb 2013 19:25:02 +0100 Received: from mx01.example.org ([127.0.0.1]) by mail01.example.org (Dovecot) with LMTP id fu7aIn6sK1EMaQAAiWCYmA ; Mon, 25 Feb 2013 19:25:02 +0100
What would you suggest how to track an LMTP delivery through a director proxy? Should one use the MessageID to correlate the lmtp log entries in dovecot-director.log and dovecot.log?
Regards Daniel
On 25.2.2013, at 23.34, Daniel Parthey daniel.parthey@informatik.tu-chemnitz.de wrote:
LMTP has a completely different session ID currently, which gets reset for each mail delivery and is written to the Received: header that it writes. It doesn't traverse through proxies, because each delivery gets a different ID anyway.
So .. Why is it that you want this? For matching a log line with a Received: header? I guess that could be done, but the name should probably be different from %{session} so it won't get mixed up with what IMAP/POP3 uses it for.
I simply run an LMTP director/proxy to prevent NFS locking issues and in error cases I want to investigate where the mail has gone (through the director lmtp to the mailbox lmtp). I thought this is what "session IDs" were intended for.
The SMTP server should log the delivery ID that the backend generates, and you should be able to grep for it, right?
Obviously, the generated ID is a different one for director and mailbox, looking at the Received: lines of a single message:
Received: from mail01.example.org ([10.129.3.193]) by mail01.example.org (Dovecot) with LMTP id vdSeD+CrK1HXZQAAiWCYmA ; Mon, 25 Feb 2013 19:25:02 +0100 Received: from mx01.example.org ([127.0.0.1]) by mail01.example.org (Dovecot) with LMTP id fu7aIn6sK1EMaQAAiWCYmA ; Mon, 25 Feb 2013 19:25:02 +0100
What would you suggest how to track an LMTP delivery through a director proxy? Should one use the MessageID to correlate the lmtp log entries in dovecot-director.log and dovecot.log?
I was first thinking about having LMTP proxy log the delivery ID, until I noticed that LMTP proxy doesn't log anything about delivered mails currently. I'm not really sure if that would be of any actual help?..
Timo Sirainen wrote:
On 25.2.2013, at 23.34, Daniel Parthey daniel.parthey@informatik.tu-chemnitz.de wrote:
LMTP has a completely different session ID currently, which gets reset for each mail delivery and is written to the Received: header that it writes. It doesn't traverse through proxies, because each delivery gets a different ID anyway.
So .. Why is it that you want this? For matching a log line with a Received: header? I guess that could be done, but the name should probably be different from %{session} so it won't get mixed up with what IMAP/POP3 uses it for.
I simply run an LMTP director/proxy to prevent NFS locking issues and in error cases I want to investigate where the mail has gone (through the director lmtp to the mailbox lmtp). I thought this is what "session IDs" were intended for.
The SMTP server should log the delivery ID that the backend generates, and you should be able to grep for it, right?
Ah ok, that's totally fine. I didn't expect the ID to be the "backend" IP :)
Obviously, the generated ID is a different one for director and mailbox, looking at the Received: lines of a single message:
Received: from mail01.example.org ([10.129.3.193]) by mail01.example.org (Dovecot) with LMTP id vdSeD+CrK1HXZQAAiWCYmA ; Mon, 25 Feb 2013 19:25:02 +0100 Received: from mx01.example.org ([127.0.0.1]) by mail01.example.org (Dovecot) with LMTP id fu7aIn6sK1EMaQAAiWCYmA ; Mon, 25 Feb 2013 19:25:02 +0100
What would you suggest how to track an LMTP delivery through a director proxy? Should one use the MessageID to correlate the lmtp log entries in dovecot-director.log and dovecot.log?
I was first thinking about having LMTP proxy log the delivery ID, until I noticed that LMTP proxy doesn't log anything about delivered mails currently. I'm not really sure if that would be of any actual help?
Currently our lmtp proxy logs the following:
dovecot: lmtp(3538): Debug: none: root=, index=, control=, inbox=, alt= dovecot: lmtp(3538): Connect from 127.0.0.1 dovecot: lmtp(3538): Debug: auth input: user=user@example.org proxy proxy_timeout=120 port=19024 host=10.129.3.193 proxy_refresh=86400 dovecot: lmtp(3538): Disconnect from 127.0.0.1: Client quit (in reset)
In combination with syslog timestamp, this is enough information to track the user/backend assignment in the director, also shown by doveadm director status user@example.org.
Regards Daniel
participants (2)
-
Daniel Parthey
-
Timo Sirainen