dovecot - Apr 2018 - Saving Drafts with Roundcube marks old Mails in INBOX as unread.

Hello List,


I have a problem with the client Roundcube. Whenever I save a draft to the
Folder INBOX.Drafts a old mail in my INBOX will be marked as unread.

Here are the IMAP Logs from Roundcube and Dovecot debug logs. I have no idea why
it happens. The IMAP protocol looks normal to me but as you can see in the
second to last line in the Dovecot log Dovecot is changing the flag of an old
E-Mail in INBOX that has the same UID as the Mail that was just created in
INBOX.Drafts.


[03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] S: * OK [CAPABILITY
IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE XLIST +NAMESPACE
METADATA QUOTA AUTH=PLAIN AUTH=LOGIN] CENSORED - ready.
[03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] C: A0001 ID
("name" "Roundcube" "version" "1.1.3"
"php" "5.6.33" "os" "Linux"
"command"
"/?_task=mail&_unlock=loading1522741802861&_lang=de&_framed=1")
[03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] S: * ID ("name"
"Dovecot")
[03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] S: A0001 OK ID completed.
[03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] C: A0002 AUTHENTICATE
PLAIN ****** [37]
[03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] S: A0002 OK [CAPABILITY
IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE SORT SORT=DISPLAY
THREAD=REFERENCES THREAD=REFS THREAD=ORDEREDSUBJECT MULTIAPPEND URL-PARTIAL
CATENATE UNSELECT CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE
QRESYNC ESEARCH ESORT SEARCHRES WITHIN CONTEXT=SEARCH LIST-STATUS BINARY MOVE
XLIST +NAMESPACE METADATA QUOTA SPECIAL-USE QUOTA] Logged in
[03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] C: A0003 SETMETADATA NIL
(0 "CLIENT_IP" 1 "X.X.X.X")
[03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] S: A0003 BAD Error in IMAP
command SETMETADATA: METADATA disabled (0.000 + 0.000 secs).
[03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] C: A0004 LSUB ""
INBOX.Drafts
[03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] S: * LSUB (\Drafts)
"." INBOX.Drafts
[03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] S: A0004 OK Lsub completed
(0.000 + 0.000 secs).
[03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] C: A0005 LIST ""
INBOX.Drafts
[03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] S: * LIST (\HasNoChildren
\Drafts) "." INBOX.Drafts
[03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] S: A0005 OK List completed
(0.000 + 0.000 secs).
[03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] C: A0006 APPEND
INBOX.Drafts (\Seen) {75743+}
[03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] C: MIME-Version: 1.0^M
[03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] C:
[03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] S: A0006 OK [APPENDUID
1506921305 58] Append completed (0.001 + 0.042 secs).
[03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] C: A0007 SELECT INBOX
[03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] S: * FLAGS (\Answered
\Flagged \Deleted \Seen \Draft Junk $MDNSent)
[03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] S: * OK [PERMANENTFLAGS
(\Answered \Flagged \Deleted \Seen \Draft Junk $MDNSent \*)] Flags permitted.
[03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] S: * 682 EXISTS
[03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] S: * 0 RECENT
[03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] S: * OK [UNSEEN 48] First
unseen.
[03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] S: * OK [UIDVALIDITY
1506921304] UIDs valid
[03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] S: * OK [UIDNEXT 881]
Predicted next UID
[03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] S: A0007 OK [READ-WRITE]
Select completed (0.000 + 0.000 secs).
[03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] C: A0008 UID STORE 58
-FLAGS.SILENT (\Seen)
[03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] S: A0008 OK Store
completed (0.003 + 0.000 + 0.002 secs).
[03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] C: A0009 LOGOUT
[03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] S: * BYE Logging out
[03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] S: A0009 OK Logout
completed (0.000 + 0.000 secs).



Apr  3 09:50:03 HOST dovecot: imap-login: Login: user=<USER_1>,
method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=3272652, TLS,
session=<MDhE9OxoTKl/AAAB>
Apr  3 09:50:03 HOST dovecot: imap(USER_1): Debug: Loading modules from
directory: /usr/lib/dovecot/modules
Apr  3 09:50:03 HOST dovecot: imap(USER_1): Debug: Module loaded:
/usr/lib/dovecot/modules/lib10_quota_plugin.so
Apr  3 09:50:03 HOST dovecot: imap(USER_1): Debug: Module loaded:
/usr/lib/dovecot/modules/lib11_imap_quota_plugin.so
Apr  3 09:50:03 HOST dovecot: imap(USER_1): Debug: Module loaded:
/usr/lib/dovecot/modules/lib15_notify_plugin.so
Apr  3 09:50:03 HOST dovecot: imap(USER_1): Debug: Module loaded:
/usr/lib/dovecot/modules/lib20_mail_log_plugin.so
Apr  3 09:50:03 HOST dovecot: imap(USER_1): Debug: Module loaded:
/usr/lib/dovecot/modules/lib90_stats_plugin.so
Apr  3 09:50:03 HOST dovecot: imap(USER_1): Debug: Module loaded:
/usr/lib/dovecot/modules/lib95_imap_stats_plugin.so
Apr  3 09:50:03 HOST dovecot: imap(USER_1): Debug: Effective uid=5678, gid=345,
home=/var/www/usermail/USER_1
Apr  3 09:50:03 HOST dovecot: imap(USER_1): Debug: Quota root: name=USER_1(soft
quota) backend=fs argsApr  3 09:50:03 HOST dovecot: imap(USER_1): Debug: Quota
grace: root=USER_1(soft quota) bytes=0 (10%)
Apr  3 09:50:03 HOST dovecot: imap(USER_1): Debug: Namespace inbox:
type=private, prefix=INBOX., sep=., inbox=yes, hidden=no, list=yes,
subscriptions=yes
location=maildir:~/Maildir:CONTROL=/opt/dovecot/control/USER_1-control:INDEX=/opt/dovecot/index/USER_1
Apr  3 09:50:03 HOST dovecot: imap(USER_1): Debug: maildir++:
root=/var/www/usermail/USER_1/Maildir, index=/opt/dovecot/index/USER_1,
indexpvt=, control=/opt/dovecot/control/USER_1-control,
inbox=/var/www/usermail/USER_1/Maildir, altApr  3 09:50:03 HOST dovecot:
imap(USER_1): Debug: fs quota add mailbox dir = /var/www/usermail/USER_1/Maildir
Apr  3 09:50:03 HOST dovecot: imap(USER_1): Debug: fs quota block device =
/dev/sda2
Apr  3 09:50:03 HOST dovecot: imap(USER_1): Debug: fs quota mount point =
/storage
Apr  3 09:50:03 HOST dovecot: imap(USER_1): Debug: fs quota mount type = ext4
Apr  3 09:50:03 HOST dovecot: imap(USER_1): Debug: Namespace : type=private,
prefix=, sep=, inbox=no, hidden=yes, list=no, subscriptions=no
location=fail::LAYOUT=none
Apr  3 09:50:03 HOST dovecot: imap(USER_1): Debug: none: root=, index=,
indexpvt=, control=, inbox=, altApr  3 09:50:03 HOST dovecot: imap(USER_1):
Debug: Quota root USER_1(soft quota): Recalculated relative rules with
bytes=6291456000 count=0. Now grace=629145600
Apr  3 09:50:03 HOST dovecot: imap(USER_1): Debug: quota: quota_over_flag check:
STORAGE ret=1 value=2134020 limit=6144000
Apr  3 09:50:03 HOST dovecot: imap(USER_1): Debug: quota:
quota_over_flag=0((null)) vs currently overquota=0
Apr  3 09:50:03 HOST dovecot: imap(USER_1): save: box=INBOX.Drafts, uid=58,
msgid=<8a36c2d8f5ce6f094789b39352cb4172 at webmail-HOST.mailserver.tld>,
size=74708, subject=unread test, flags=(\Seen)
Apr  3 09:50:03 HOST dovecot: imap(USER_1): Debug: Mailbox INBOX: Opened mail
UID=58 because: header Message-ID (Mail has other cached fields,
reset_id=1506921306)
Apr  3 09:50:03 HOST dovecot: imap(USER_1): flag_change: box=INBOX, uid=58,
msgid=<CENSORED at CENSORED.TLD>, size=129564, subject=CENSORED SUBJECT,
flags=()
Apr  3 09:50:03 HOST dovecot: imap(USER_1): Logged out in=75975 out=1225


Information about dovecot:

dovecot --version
2.2.27 (c0f36b0)

dovecot -n
# 2.2.27 (c0f36b0): /etc/dovecot/dovecot.conf
# Pigeonhole version 0.4.16 (fed8554)
# OS: Linux 4.9.44-040944-generic x86_64 Debian 8.10
auth_mechanisms = plain login
default_client_limit = 32000
default_process_limit = 8000
disable_plaintext_auth = no
listen = *
login_greeting = CENSORED - ready.
mail_debug = yes
mail_location =
maildir:~/Maildir:CONTROL=/opt/dovecot/control/%n-control:INDEX=/opt/dovecot/index/%n
mail_plugins = " stats quota mail_log notify"
namespace inbox {
  inbox = yes
  location   mailbox Drafts {
    auto = subscribe
    special_use = \Drafts
  }
  mailbox Spam {
    auto = subscribe
    special_use = \Junk
  }
  mailbox Sent {
    auto = subscribe
    special_use = \Sent
  }
  mailbox "Sent Messages" {
    special_use = \Sent
  }
  mailbox Trash {
    auto = subscribe
    special_use = \Trash
  }
  prefix = INBOX.
  separator = .
}
passdb {
  args = dovecot-%s
  driver = pam
}
plugin {
  cgroup_debug = false
  cgroup_path = /sys/fs/cgroup
  mail_log_events = delete undelete expunge copy mailbox_delete mailbox_rename
flag_change append
  mail_log_fields = uid box msgid size subject flags
  quota = fs:%n(soft quota)
  sieve = ~/.dovecot.sieve
  sieve_dir = ~/sieve
  stats_command_min_time = 1 mins
  stats_domain_min_time = 12 hours
  stats_ip_min_time = 12 hours
  stats_memory_limit = 16 M
  stats_refresh = 30 secs
  stats_session_min_time = 15 mins
  stats_track_cmds = no
  stats_user_min_time = 24 hours
}
protocols = " imap pop3"
service auth {
  unix_listener /var/spool/postfix/private/auth {
    group = postfix
    mode = 0666
    user = postfix
  }
}
service imap-login {
  inet_listener imaps {
    ssl = yes
  }
}
service imap-postlogin {
  executable = script-login /etc/dovecot/post-login/expire.sh
}
service imap {
  executable = imap imap-postlogin
  process_limit = 4096
}
service pop3-login {
  inet_listener pop3 {
    port = 110
  }
  inet_listener pop3s {
    port = 995
    ssl = yes
  }
}
service pop3-postlogin {
  executable = script-login /etc/dovecot/post-login/expire.sh
}
service pop3 {
  executable = pop3 pop3-postlogin
}
service quota-status {
  executable = quota-status -p postfix
  unix_listener /var/spool/postfix/private/quota {
    group = postfix
    mode = 0660
    user = postfix
  }
}
service stats {
  fifo_listener stats-mail {
    mode = 0666
    user = dovecot
  }
}
ssl_ca = </etc/ssl.crt/ca-admin.crt
ssl_cert = </etc/ssl.crt/admin.crt
ssl_cipher_list =
ECDHE-RSA-AES256-GCM-SHA384:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-RSA-AES256-SHA384:ECDHE-ECDSA-AES256-SHA384:DHE-DSS-AES256-GCM-SHA384:DHE-RSA-AES256-GCM-SHA384:DHE-RSA-AES256-SHA256:DHE-DSS-AES256-SHA256:ECDHE-RSA-AES256-SHA:DHE-RSA-AES256-SHA:AES256-GCM-SHA384:AES256-SHA256:AES256-SHA
ssl_key =  # hidden, use -P to show it
ssl_prefer_server_ciphers = yes
ssl_protocols = !SSLv2 !SSLv3
userdb {
  driver = passwd
}
protocol imap {
  imap_capability = +XLIST +NAMESPACE METADATA QUOTA
  imap_idle_notify_interval = 1 mins
  mail_max_userip_connections = 500
  mail_plugins = " stats quota mail_log notify imap_quota imap_stats"
}
protocol pop3 {
  mail_max_userip_connections = 500
  mail_plugins = " stats quota mail_log notify"
  pop3_client_workarounds = outlook-no-nuls oe-ns-eoh
}

On 04.04.2018 09:59, sk at tyrion.de wrote:
> [03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] C: A0001 ID
("name" "Roundcube" "version" "1.1.3"
"php" "5.6.33" "os" "Linux"
"command"
"/?_task=mail&_unlock=loading1522741802861&_lang=de&_framed=1")
> [03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] S: * ID
("name" "Dovecot")
> [03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] S: A0001 OK ID
completed.
> [03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] C: A0002 AUTHENTICATE
PLAIN ****** [37]
> [03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] S: A0002 OK
[CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE SORT
SORT=DISPLAY THREAD=REFERENCES THREAD=REFS THREAD=ORDEREDSUBJECT MULTIAPPEND
URL-PARTIAL CATENATE UNSELECT CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED
I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT SEARCHRES WITHIN CONTEXT=SEARCH
LIST-STATUS BINARY MOVE XLIST +NAMESPACE METADATA QUOTA SPECIAL-USE QUOTA]
Logged in
> [03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] C: A0003 SETMETADATA
NIL (0 "CLIENT_IP" 1 "X.X.X.X")
I see you're using quite old Roundcube version with some plugins. I
propose to try with all plugins disabled and upgrade to something more
recent.

-- 
Aleksander 'A.L.E.C' Machniak
Kolab Groupware Developer         [http://kolab.org]
Roundcube Webmail Developer   [http://roundcube.net]
----------------------------------------------------
PGP: 19359DC1 # Blog: https://kolabian.wordpress.com

> On 4 Apr 2018, at 10.59, sk at tyrion.de wrote:
> 
> Hello List,
> 
> 
> I have a problem with the client Roundcube. Whenever I save a draft to the
Folder INBOX.Drafts a old mail in my INBOX will be marked as unread.
> 
> Here are the IMAP Logs from Roundcube and Dovecot debug logs. I have no
idea why it happens. The IMAP protocol looks normal to me but as you can see in
the second to last line in the Dovecot log Dovecot is changing the flag of an
old E-Mail in INBOX that has the same UID as the Mail that was just created in
INBOX.Drafts.
> 
> 
> [03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] S: A0006 OK
[APPENDUID 1506921305 58] Append completed (0.001 + 0.042 secs).
> [03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] C: A0007 SELECT INBOX
Here roundcube SELECTs INBOX again
> [03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] S: * FLAGS (\Answered
\Flagged \Deleted \Seen \Draft Junk $MDNSent)
> [03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] S: * OK
[PERMANENTFLAGS (\Answered \Flagged \Deleted \Seen \Draft Junk $MDNSent \*)]
Flags permitted.
> [03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] S: * 682 EXISTS
> [03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] S: * 0 RECENT
> [03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] S: * OK [UNSEEN 48]
First unseen.
> [03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] S: * OK [UIDVALIDITY
1506921304] UIDs valid
> [03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] S: * OK [UIDNEXT 881]
Predicted next UID
> [03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] S: A0007 OK
[READ-WRITE] Select completed (0.000 + 0.000 secs).
> [03-Apr-2018 09:50:03 +0200]: <6c472a00> [8095] C: A0008 UID STORE 58
-FLAGS.SILENT (\Seen)
And here roundcube removes \Seen flag from mail UID 58

so it's roundcube that removes the \Seen flag, effectively making the mail
unseen again. Seems like roundcube bug.

Sami