Extended logging / moved mails jumping back
Hi!
About 4-6 MUA Thunderbird 60.6.1 are going to connect with dovecot 2.2.13/IMAP (debian 8) and are using the same user/password. This setup works for years flawless (updated clients and serversoftware).
Since a few weeks there is one major trouble:
I one of the client moves a mail from the inbox to a another IMAP-Folder, most of the moved mail are moved for the moment. But an unstable period later, the mails are moved back to the inbox. In rarely cases, the moved mail is copied (one in the inbox, one in the destinationfolder).
Now I have to check, if this a Thunderbird-Issue or is this a dovecot-issue. For that reason, I will activate the extended logging of dovecot.
### ###
dovecot -n
2.2.13: /etc/dovecot/dovecot.conf
OS: Linux 3.16.0-6-amd64 x86_64 Debian 8.11
auth_mechanisms = plain login debug_log_path = /var/log/mail.dovecot-debug disable_plaintext_auth = no info_log_path = /var/log/mail.dovecot-info listen = *,[::] log_path = /var/log/mail.dovecot-error log_timestamp = "%Y-%m-%d %H:%M:%S " mail_debug = yes mail_max_userip_connections = 100 mail_privileged_group = vmail passdb { args = /etc/dovecot/dovecot-sql.conf driver = sql } plugin { mail_log_events = delete undelete expunge copy mailbox_delete mailbox_rename mail_log_fields = uid box msgid size quota = dict:user::file:/var/vmail/%d/%n/.quotausage sieve = /var/vmail/%d/%n/.sieve sieve_max_redirects = 25 } protocols = imap pop3 service auth { unix_listener /var/spool/postfix/private/auth { group = postfix mode = 0660 user = postfix } unix_listener auth-userdb { group = vmail mode = 0600 user = vmail } user = root } service imap-login { client_limit = 1000 process_limit = 512 } service lmtp { unix_listener /var/spool/postfix/private/dovecot-lmtp { group = postfix mode = 0600 user = postfix } } ssl_cert = </etc/postfix/smtpd.cert ssl_key = </etc/postfix/smtpd.key ssl_protocols = !SSLv3 userdb { driver = prefetch } userdb { args = /etc/dovecot/dovecot-sql.conf driver = sql } protocol imap { mail_plugins = quota imap_quota } protocol pop3 { mail_plugins = quota pop3_uidl_format = %08Xu%08Xv } protocol lda { mail_plugins = sieve quota postmaster_address = postmaster@monarch.products4more.at } protocol lmtp { mail_plugins = quota sieve postmaster_address = postmaster@monarch.products4more.at }
### ### ### ### ### ###
It works: dovecot logs to three differnt logfiles /var/log/mail.dovecot-* It doesnt work:
plugin { mail_log_events = delete undelete expunge copy mailbox_delete mailbox_rename mail_log_fields = uid box msgid size }
I cant see such events in the logfiles. Which switch is to turn on to log all events? Or do anyone know the reason for the annoying "copy/move-the-mail-back"-issue?
Thank you in advance for all inputs.
regards, martin
Hi!
Now I have to check, if this a Thunderbird-Issue or is this a dovecot-issue. For that reason, I will activate the extended logging of dovecot. <snip/> I cant see such events in the logfiles. Which switch is to turn on to log all events? Or do anyone know the reason for the annoying "copy/move-the-mail-back"-issue?
Thank you in advance for all inputs.
regards, martin
You are missing
mail_plugins = $mail_plugins notify mail_log
Thank you - it didnt work for me (yet). But I think there is another problem which I have to solve first. I recognised that the maildelivery stops after turning on the logging to the three files.
The incomming mails are held in the mailq, in syslog appears
relay=dovecot, delay=0.13, delays=0.07/0/0/0.06, dsn=4.3.0, status=deferred (temporary failure. Command output: Can't open log file /var/log/mail.dovecot-error: Permission denied )
In /var/log/mail.dovecot-error are lines like 2019-04-14 10:16:18 auth: Warning: auth client 0 disconnected with 1 pending requests: Connection reset by peer
Here the output of ls -la /var/log/mail.dovecot-error -rw-r--r-- 1 root root 21259 Apr 14 11:24 /var/log/mail.dovecot-error
If I turn the extended logging off, all works fine.
postqueue -f releases all held mails to their boxes.
Any hints for me?
Thank you!
martin
On Sun, Apr 14, 2019 at 12:04:36PM +0200, Martin Müller via dovecot wrote:
relay=dovecot, delay=0.13, delays=0.07/0/0/0.06, dsn=4.3.0, status=deferred (temporary failure. Command output: Can't open log file /var/log/mail.dovecot-error: Permission denied ) [...] Here the output of ls -la /var/log/mail.dovecot-error -rw-r--r-- 1 root root 21259 Apr 14 11:24 /var/log/mail.dovecot-error [...] Any hints for me?
Well, fix the permission errors? Give write access to the docecot user (or whatever you use) for the log file.
Also take care if you use the systemd service, there may be other restrictions in place (ProtectSystem etc)
did some improvements on the server.
from
dovecot -n
2.2.13: /etc/dovecot/dovecot.conf
OS: Linux 3.16.0-6-amd64 x86_64 Debian 8.11
to
2.2.27 (c0f36b0): /etc/dovecot/dovecot.conf
Pigeonhole version 0.4.16 (fed8554)
OS: Linux 4.9.0-8-amd64 x86_64 Debian 9.8
dovecot is working for days without issues, logging is running to one file /var/log/mail.dovecot
In the logfile appears 2019-04-19 18:53:54 imap-login: Info: Login: user=<office@ourdomain.at>, method=PLAIN, rip=80.75.xx.35, lip=136.xxx.9.172, mpid=28364, TLS, session=<vDTC9uSG2opQS/Yj>
All 4 different MUAs Thunderbird are logged in the same way. They are behind a router, so they having the same remote IP. So I cant differentiate, which MUA causes which event.
Is there a way, to identify which client raise a special event?
Am So., 14. Apr. 2019 um 12:38 Uhr schrieb Reto Brunner via dovecot < dovecot@dovecot.org>:
On Sun, Apr 14, 2019 at 12:04:36PM +0200, Martin Müller via dovecot wrote:
relay=dovecot, delay=0.13, delays=0.07/0/0/0.06, dsn=4.3.0, status=deferred (temporary failure. Command output: Can't open log file /var/log/mail.dovecot-error: Permission denied ) [...] Here the output of ls -la /var/log/mail.dovecot-error -rw-r--r-- 1 root root 21259 Apr 14 11:24 /var/log/mail.dovecot-error [...] Any hints for me?
Well, fix the permission errors? Give write access to the docecot user (or whatever you use) for the log file.
Also take care if you use the systemd service, there may be other restrictions in place (ProtectSystem etc)
-- Martin
On 19 Apr 2019, at 20.04, Martin Müller via dovecot <dovecot@dovecot.org> wrote:
2019-04-19 18:53:54 imap-login: Info: Login: user=<office@ourdomain.at <mailto:office@ourdomain.at>>, method=PLAIN, rip=80.75.xx.35, lip=136.xxx.9.172, mpid=28364, TLS, session=<vDTC9uSG2opQS/Yj>
All 4 different MUAs Thunderbird are logged in the same way. They are behind a router, so they having the same remote IP. So I cant differentiate, which MUA causes which event.
Is there a way, to identify which client raise a special event?
I think Thunderbird does send IMAP ID information so you can try adding "imap_id_log = *" to your config to get the info logged.
Maybe it has some information to identify the different clients.
Sami
participants (4)
-
Aki Tuomi
-
Martin Müller
-
Reto Brunner
-
Sami Ketola