1 (edited by communque 2024-08-01 05:05:47)

Topic: dovecot log: imap: Error: DETAIL: Key (username, domain) already exis

==== REQUIRED BASIC INFO OF YOUR IREDMAIL SERVER ====
- iRedMail version:  iRedMail-1.7.0
- Deployed with downloadable installer
- Linux/BSD distribution name and version: Ubuntu 24.04 LTS
- Store mail accounts in which backend (LDAP/MySQL/PGSQL): PGSQL
- Web server (Apache or Nginx): Nginx
- Manage mail accounts with iRedAdmin-Pro? No
====

Seeing a repeating error in the dovecot log ( /var/log/dovecot/dovecot.log ):

[timestamp] mail dovecot: imap: Error: DETAIL:  Key (username, domain)=(myUser@myDomain, myDomain) already exists.

What would account for this?  How to trouble-shoot & resolve?

----

Spider Email Archiver: On-Premises, lightweight email archiving software developed by iRedMail team. Supports Amazon S3 compatible storage and custom branding.

2

Re: dovecot log: imap: Error: DETAIL: Key (username, domain) already exis

Seems caused by sql table "vmail.last_login".
Could you please turn on debug mode in Dovecot and try again? Show me full log under /var/log/dovecot/dovecot.log related to this error.

FYI https://docs.iredmail.org/debug.dovecot.html

3

Re: dovecot log: imap: Error: DETAIL: Key (username, domain) already exis

ZhangHuangbin wrote:

Seems caused by sql table "vmail.last_login".
Could you please turn on debug mode in Dovecot and try again? Show me full log under /var/log/dovecot/dovecot.log related to this error.

Let me know if this captures what you need...

Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: Loading modules from directory: /usr/lib/dovecot/modules
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: Module loaded: /usr/lib/dovecot/modules/lib01_acl_plugin.so
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: Module loaded: /usr/lib/dovecot/modules/lib02_imap_acl_plugin.so
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: Module loaded: /usr/lib/dovecot/modules/lib10_last_login_plugin.so
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: Module loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: Module loaded: /usr/lib/dovecot/modules/lib11_imap_quota_plugin.so
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: Module loaded: /usr/lib/dovecot/modules/lib15_notify_plugin.so
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: Module loaded: /usr/lib/dovecot/modules/lib20_mail_log_plugin.so
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: Module loaded: /usr/lib/dovecot/modules/lib20_mailbox_alias_plugin.so
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: Module loaded: /usr/lib/dovecot/modules/lib95_imap_sieve_plugin.so
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: Added userdb setting: mail=maildir:~/Maildir
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: Added userdb setting: plugin/master_user=myUser@myDomain
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: Added userdb setting: plugin/quota_rule=*:bytes=524288000
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: Effective uid=2000, gid=2000, home=/var/vmail/vmail1/myDomain/e/v/e/myUser-2024.07.30.18.01.20/
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: dict(proxy)<myUser@myDomain>: Starting transaction
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: dict(proxy)<myUser@myDomain>: Setting 'shared/last-login/imap/myUser@myDomain/myDomain' to '1722477748'
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: dict(proxy)<myUser@myDomain>: conn unix:/run/dovecot/dict: Connecting
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: dict(proxy)<myUser@myDomain>: conn unix:/run/dovecot/dict (pid=17029,uid=0): Client connected (fd=8)
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: Quota root: name=user backend=dict args=:proxy::quotadict
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: Quota rule: root=user mailbox=* bytes=524288000 messages=0
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: Quota warning: bytes=524288000 (100%) messages=0 reverse=no command=quota-warning 100 myUser@myDomain
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: Quota warning: bytes=498073600 (95%) messages=0 reverse=no command=quota-warning 95 myUser@myDomain
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: Quota warning: bytes=471859200 (90%) messages=0 reverse=no command=quota-warning 90 myUser@myDomain
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: Quota warning: bytes=445644800 (85%) messages=0 reverse=no command=quota-warning 85 myUser@myDomain
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: Quota grace: root=user bytes=52428800 (10%)
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: quota-dict: user=myUser@myDomain, uri=proxy::quotadict, noenforcing=0
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: Namespace : type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:~/Maildir
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: maildir++: root=/var/vmail/vmail1/myDomain/e/v/e/myUser-2024.07.30.18.01.20//Maildir, index=, indexpvt=, control=, inbox=/var/vmail/vmail1/myDomain/e/v/e/myUser-2024.07.30.18.01.20//Maildir, alt=
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: acl: initializing backend with data: vfile
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: acl: acl username = myUser@myDomain
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: acl: owner = 1
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: acl vfile: Global ACLs disabled
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: Namespace : type=shared, prefix=Shared/%u/, sep=/, inbox=no, hidden=no, list=children, subscriptions=yes location=maildir:%Lh/Maildir/:INDEX=%Lh/Maildir/Shared/%Ld/%Ln
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: shared: root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: acl: initializing backend with data: vfile
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: acl: acl username = myUser@myDomain
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: acl: owner = 0
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: acl vfile: Global ACLs disabled
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: quota: quota_over_flag check: quota_over_script unset - skipping
Aug  1 02:02:28 mail dovecot: imap: Error: DETAIL:  Key (username, domain)=(myUser@myDomain, myDomain) already exists. (reply took 0.048 secs (0.000 in dict wait, 0.045 in other ioloops, 0.000 in locks, async-id reply 0.035 secs ago, started on dict-server 0.038 secs ago, took 0.038 secs))
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: dict(proxy)<myUser@myDomain>: Dict transaction finished
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: dict(proxy)<myUser@myDomain>: Waiting for dict to finish pending operations
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: dict(proxy)<myUser@myDomain>: conn unix:/run/dovecot/dict (pid=17029,uid=0): Disconnected: Connection closed (fd=8)
Aug  1 02:02:28 mail dovecot: imap(myUser@myDomain)<18201><kmpWmpUeWNpC6sgz>: Debug: dict(proxy)<myUser@myDomain>: Waiting for dict to finish pending operations
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<17136><nq9yTpUe29hriWvy>: Debug: dict(proxy)<myUser@myDomain>: Waiting for dict to finish pending operations
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<17131><bXpvTpUe2NhriWvy>: Debug: dict(proxy)<myUser@myDomain>: Waiting for dict to finish pending operations
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<17136><nq9yTpUe29hriWvy>: Debug: Mailbox Junk: Mailbox opened because: SELECT
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<17131><bXpvTpUe2NhriWvy>: Debug: Mailbox INBOX: Mailbox opened because: SELECT
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: Loading modules from directory: /usr/lib/dovecot/modules
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: Module loaded: /usr/lib/dovecot/modules/lib01_acl_plugin.so
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: Module loaded: /usr/lib/dovecot/modules/lib02_imap_acl_plugin.so
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: Module loaded: /usr/lib/dovecot/modules/lib10_last_login_plugin.so
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: Module loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: Module loaded: /usr/lib/dovecot/modules/lib11_imap_quota_plugin.so
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: Module loaded: /usr/lib/dovecot/modules/lib15_notify_plugin.so
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: Module loaded: /usr/lib/dovecot/modules/lib20_mail_log_plugin.so
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: Module loaded: /usr/lib/dovecot/modules/lib20_mailbox_alias_plugin.so
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: Module loaded: /usr/lib/dovecot/modules/lib95_imap_sieve_plugin.so
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: Added userdb setting: mail=maildir:~/Maildir
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: Added userdb setting: plugin/master_user=myUser@myDomain
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: Added userdb setting: plugin/quota_rule=*:bytes=524288000
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: Effective uid=2000, gid=2000, home=/var/vmail/vmail1/myDomain/e/v/e/myUser-2024.07.30.18.01.20/
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: dict(proxy)<myUser@myDomain>: Starting transaction
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: dict(proxy)<myUser@myDomain>: Setting 'shared/last-login/imap/myUser@myDomain/myDomain' to '1722477798'
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: dict(proxy)<myUser@myDomain>: conn unix:/run/dovecot/dict: Connecting
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: dict(proxy)<myUser@myDomain>: conn unix:/run/dovecot/dict (pid=17029,uid=0): Client connected (fd=8)
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: Quota root: name=user backend=dict args=:proxy::quotadict
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: Quota rule: root=user mailbox=* bytes=524288000 messages=0
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: Quota warning: bytes=524288000 (100%) messages=0 reverse=no command=quota-warning 100 myUser@myDomain
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: Quota warning: bytes=498073600 (95%) messages=0 reverse=no command=quota-warning 95 myUser@myDomain
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: Quota warning: bytes=471859200 (90%) messages=0 reverse=no command=quota-warning 90 myUser@myDomain
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: Quota warning: bytes=445644800 (85%) messages=0 reverse=no command=quota-warning 85 myUser@myDomain
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: Quota grace: root=user bytes=52428800 (10%)
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: quota-dict: user=myUser@myDomain, uri=proxy::quotadict, noenforcing=0
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: Namespace : type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:~/Maildir
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: maildir++: root=/var/vmail/vmail1/myDomain/e/v/e/myUser-2024.07.30.18.01.20//Maildir, index=, indexpvt=, control=, inbox=/var/vmail/vmail1/myDomain/e/v/e/myUser-2024.07.30.18.01.20//Maildir, alt=
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: acl: initializing backend with data: vfile
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: acl: acl username = myUser@myDomain
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: acl: owner = 1
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: acl vfile: Global ACLs disabled
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: Namespace : type=shared, prefix=Shared/%u/, sep=/, inbox=no, hidden=no, list=children, subscriptions=yes location=maildir:%Lh/Maildir/:INDEX=%Lh/Maildir/Shared/%Ld/%Ln
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: shared: root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: acl: initializing backend with data: vfile
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: acl: acl username = myUser@myDomain
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: acl: owner = 0
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: acl vfile: Global ACLs disabled
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: quota: quota_over_flag check: quota_over_script unset - skipping
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: dict(proxy)<myUser@myDomain>: Dict transaction finished
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: dict(proxy)<myUser@myDomain>: Waiting for dict to finish pending operations
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: dict(proxy)<myUser@myDomain>: conn unix:/run/dovecot/dict (pid=17029,uid=0): Disconnected: Connection closed (fd=8)
Aug  1 02:03:18 mail dovecot: imap(myUser@myDomain)<18241><7lBOnZUeK9lriWvy>: Debug: dict(proxy)<myUser@myDomain>: Waiting for dict to finish pending operations
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><>: Debug: Loading modules from directory: /usr/lib/dovecot/modules
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><>: Debug: Module loaded: /usr/lib/dovecot/modules/lib01_acl_plugin.so
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><>: Debug: Module loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><>: Debug: Module loaded: /usr/lib/dovecot/modules/lib15_notify_plugin.so
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><>: Debug: Module loaded: /usr/lib/dovecot/modules/lib20_mail_log_plugin.so
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><>: Debug: Module loaded: /usr/lib/dovecot/modules/lib20_mailbox_alias_plugin.so
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><>: Debug: auth-master: userdb lookup(myUser@myDomain): Started userdb lookup
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><>: Debug: auth-master: conn unix:/run/dovecot/auth-userdb: Connecting
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><>: Debug: auth-master: conn unix:/run/dovecot/auth-userdb (pid=17029,uid=0): Client connected (fd=14)
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><>: Debug: auth-master: userdb lookup(myUser@myDomain): auth USER input: myUser@myDomain master_user=myUser@myDomain home=/var/vmail/vmail1/myDomain/e/v/e/myUser-2024.07.30.18.01.20/ mail=maildir:~/Maildir quota_rule=*:bytes=524288000
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><>: Debug: auth-master: userdb lookup(myUser@myDomain): Finished userdb lookup (username=myUser@myDomain master_user=myUser@myDomain home=/var/vmail/vmail1/myDomain/e/v/e/myUser-2024.07.30.18.01.20/ mail=maildir:~/Maildir quota_rule=*:bytes=524288000)
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><>: Debug: Added userdb setting: mail=maildir:~/Maildir
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><>: Debug: Added userdb setting: plugin/master_user=myUser@myDomain
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><>: Debug: Added userdb setting: plugin/quota_rule=*:bytes=524288000
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><OLbyBA7tqmZfRwAAZfUG1g>: Debug: Effective uid=2000, gid=2000, home=/var/vmail/vmail1/myDomain/e/v/e/myUser-2024.07.30.18.01.20/
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><OLbyBA7tqmZfRwAAZfUG1g>: Debug: Quota root: name=user backend=dict args=:proxy::quotadict
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><OLbyBA7tqmZfRwAAZfUG1g>: Debug: Quota rule: root=user mailbox=* bytes=524288000 messages=0
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><OLbyBA7tqmZfRwAAZfUG1g>: Debug: Quota warning: bytes=524288000 (100%) messages=0 reverse=no command=quota-warning 100 myUser@myDomain
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><OLbyBA7tqmZfRwAAZfUG1g>: Debug: Quota warning: bytes=498073600 (95%) messages=0 reverse=no command=quota-warning 95 myUser@myDomain
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><OLbyBA7tqmZfRwAAZfUG1g>: Debug: Quota warning: bytes=471859200 (90%) messages=0 reverse=no command=quota-warning 90 myUser@myDomain
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><OLbyBA7tqmZfRwAAZfUG1g>: Debug: Quota warning: bytes=445644800 (85%) messages=0 reverse=no command=quota-warning 85 myUser@myDomain
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><OLbyBA7tqmZfRwAAZfUG1g>: Debug: Quota grace: root=user bytes=52428800 (10%)
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><OLbyBA7tqmZfRwAAZfUG1g>: Debug: quota-dict: user=myUser@myDomain, uri=proxy::quotadict, noenforcing=0
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><OLbyBA7tqmZfRwAAZfUG1g>: Debug: Namespace : type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:~/Maildir
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><OLbyBA7tqmZfRwAAZfUG1g>: Debug: maildir++: root=/var/vmail/vmail1/myDomain/e/v/e/myUser-2024.07.30.18.01.20//Maildir, index=, indexpvt=, control=, inbox=/var/vmail/vmail1/myDomain/e/v/e/myUser-2024.07.30.18.01.20//Maildir, alt=
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><OLbyBA7tqmZfRwAAZfUG1g>: Debug: acl: initializing backend with data: vfile
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><OLbyBA7tqmZfRwAAZfUG1g>: Debug: acl: acl username = myUser@myDomain
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><OLbyBA7tqmZfRwAAZfUG1g>: Debug: acl: owner = 1
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><OLbyBA7tqmZfRwAAZfUG1g>: Debug: acl vfile: Global ACLs disabled
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><OLbyBA7tqmZfRwAAZfUG1g>: Debug: Namespace : type=shared, prefix=Shared/%u/, sep=/, inbox=no, hidden=no, list=children, subscriptions=yes location=maildir:%Lh/Maildir/:INDEX=%Lh/Maildir/Shared/%Ld/%Ln
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><OLbyBA7tqmZfRwAAZfUG1g>: Debug: shared: root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><OLbyBA7tqmZfRwAAZfUG1g>: Debug: acl: initializing backend with data: vfile
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><OLbyBA7tqmZfRwAAZfUG1g>: Debug: acl: acl username = myUser@myDomain
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><OLbyBA7tqmZfRwAAZfUG1g>: Debug: acl: owner = 0
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><OLbyBA7tqmZfRwAAZfUG1g>: Debug: acl vfile: Global ACLs disabled
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><OLbyBA7tqmZfRwAAZfUG1g>: Debug: quota: quota_over_flag check: quota_over_script unset - skipping
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><OLbyBA7tqmZfRwAAZfUG1g>: Debug: dict(proxy)<myUser@myDomain>: Looking up 'priv/quota/storage'
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><OLbyBA7tqmZfRwAAZfUG1g>: Debug: dict(proxy)<myUser@myDomain>: Looking up (async) 'priv/quota/storage'
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><OLbyBA7tqmZfRwAAZfUG1g>: Debug: dict(proxy)<myUser@myDomain>: conn unix:/run/dovecot/dict: Connecting
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><OLbyBA7tqmZfRwAAZfUG1g>: Debug: dict(proxy)<myUser@myDomain>: conn unix:/run/dovecot/dict (pid=17029,uid=0): Client connected (fd=15)
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><OLbyBA7tqmZfRwAAZfUG1g>: Debug: dict(proxy)<myUser@myDomain>: Lookup finished for 'priv/quota/storage': found
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><OLbyBA7tqmZfRwAAZfUG1g>: Debug: dict(proxy)<myUser@myDomain>: Lookup finished for 'priv/quota/storage': found
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><OLbyBA7tqmZfRwAAZfUG1g>: Debug: dict(proxy)<myUser@myDomain>: Waiting for dict to finish pending operations
Aug  1 02:03:58 mail dovecot: quota-status(myUser@myDomain)<18271><OLbyBA7tqmZfRwAAZfUG1g>: Debug: dict(proxy)<myUser@myDomain>: conn unix:/run/dovecot/dict (pid=17029,uid=0): Disconnected: Connection closed (fd=15)

4

Re: dovecot log: imap: Error: DETAIL: Key (username, domain) already exis

ZhangHuangbin wrote:

Show me full log under /var/log/dovecot/dovecot.log related to this error.

ZhangHuangbin, here's another log, this time including what I believe is the associated imp log...

imap.log:

Aug  1 16:58:54 mail dovecot: imap-login: Login: user=<myUser@myDomain>, method=PLAIN, rip=clientIP, lip=serverIP, mpid=22577, TLS, TLSv1.2 with cipher cipherID (256/256 bits), session=<mzA8IKIeJfJriWvy>
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Disconnected: Logged out in=36 out=605 deleted=0 expunged=0 trashed=0 hdr_count=0 hdr_bytes=0 body_count=0 body_bytes=0
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Error: last_login_dict: Failed to write value: dict-server returned failure: sql dict: commit failed: ERROR:  duplicate key value violates unique constraint "last_login_pkey"

dovecot.log

Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: Loading modules from directory: /usr/lib/dovecot/modules
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: Module loaded: /usr/lib/dovecot/modules/lib01_acl_plugin.so
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: Module loaded: /usr/lib/dovecot/modules/lib02_imap_acl_plugin.so
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: Module loaded: /usr/lib/dovecot/modules/lib10_last_login_plugin.so
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: Module loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: Module loaded: /usr/lib/dovecot/modules/lib11_imap_quota_plugin.so
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: Module loaded: /usr/lib/dovecot/modules/lib15_notify_plugin.so
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: Module loaded: /usr/lib/dovecot/modules/lib20_mail_log_plugin.so
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: Module loaded: /usr/lib/dovecot/modules/lib20_mailbox_alias_plugin.so
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: Module loaded: /usr/lib/dovecot/modules/lib95_imap_sieve_plugin.so
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: Added userdb setting: mail=maildir:~/Maildir
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: Added userdb setting: plugin/master_user=myUser@myDomain
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: Added userdb setting: plugin/quota_rule=*:bytes=524288000
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: Effective uid=2000, gid=2000, home=/var/vmail/vmail1/myDomain/e/v/e/myUser-2024.07.30.18.01.20/
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: dict(proxy)<myUser@myDomain>: Starting transaction
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: dict(proxy)<myUser@myDomain>: Setting 'shared/last-login/imap/myUser@myDomain/myDomain' to '1722531534'
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: dict(proxy)<myUser@myDomain>: conn unix:/run/dovecot/dict: Connecting
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: dict(proxy)<myUser@myDomain>: conn unix:/run/dovecot/dict (pid=614,uid=0): Client connected (fd=8)
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: Quota root: name=user backend=dict args=:proxy::quotadict
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: Quota rule: root=user mailbox=* bytes=524288000 messages=0
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: Quota warning: bytes=524288000 (100%) messages=0 reverse=no command=quota-warning 100 myUser@myDomain
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: Quota warning: bytes=498073600 (95%) messages=0 reverse=no command=quota-warning 95 myUser@myDomain
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: Quota warning: bytes=471859200 (90%) messages=0 reverse=no command=quota-warning 90 myUser@myDomain
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: Quota warning: bytes=445644800 (85%) messages=0 reverse=no command=quota-warning 85 myUser@myDomain
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: Quota grace: root=user bytes=52428800 (10%)
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: quota-dict: user=myUser@myDomain, uri=proxy::quotadict, noenforcing=0
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: Namespace : type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:~/Maildir
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: maildir++: root=/var/vmail/vmail1/myDomain/e/v/e/myUser-2024.07.30.18.01.20//Maildir, index=, indexpvt=, control=, inbox=/var/vmail/vmail1/myDomain/e/v/e/myUser-2024.07.30.18.01.20//Maildir, alt=
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: acl: initializing backend with data: vfile
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: acl: acl username = myUser@myDomain
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: acl: owner = 1
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: acl vfile: Global ACLs disabled
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: Namespace : type=shared, prefix=Shared/%u/, sep=/, inbox=no, hidden=no, list=children, subscriptions=yes location=maildir:%Lh/Maildir/:INDEX=%Lh/Maildir/Shared/%Ld/%Ln
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: shared: root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: acl: initializing backend with data: vfile
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: acl: acl username = myUser@myDomain
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: acl: owner = 0
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: acl vfile: Global ACLs disabled
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: quota: quota_over_flag check: quota_over_script unset - skipping
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: dict(proxy)<myUser@myDomain>: Waiting for dict to finish pending operations
Aug  1 16:58:54 mail dovecot: imap: Error: DETAIL:  Key (username, domain)=(myUser@myDomain, myDomain) already exists. (reply took 0.058 secs (0.014 in dict wait, 0.034 in other ioloops, 0.000 in locks, async-id reply 0.038 secs ago, started on dict-server 0.041 secs ago, took 0.041 secs))
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: dict(proxy)<myUser@myDomain>: Dict transaction finished
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: dict(proxy)<myUser@myDomain>: conn unix:/run/dovecot/dict (pid=614,uid=0): Disconnected: Connection closed (fd=8)
Aug  1 16:58:54 mail dovecot: imap(myUser@myDomain)<22577><mzA8IKIeJfJriWvy>: Debug: dict(proxy)<myUser@myDomain>: Waiting for dict to finish pending operations

5

Re: dovecot log: imap: Error: DETAIL: Key (username, domain) already exis

I'm working on it. Stay tuned.

6

Re: dovecot log: imap: Error: DETAIL: Key (username, domain) already exis

I cannot reproduce this issue locally (both iRedMail and iRedMail Enterprise Edition).
Is it possible to give me direct ssh access with root privilege, and a testing email account to reproduce the issue?

7

Re: dovecot log: imap: Error: DETAIL: Key (username, domain) already exis

ZhangHuangbin wrote:

I cannot reproduce this issue locally (both iRedMail and iRedMail Enterprise Edition).
Is it possible to give me direct ssh access with root privilege, and a testing email account to reproduce the issue?

Hi ZhangHuangbin,

Apologies for the delay.  I missed your latest post somehow.

I cannot immediately provide ssh access with root privilege, but I was able to re-create the issue -- re-imaging the server, re-installing iRedMail with postgreSQL and then re-doing the steps to get SpamAssassin.  I realize I didn't test to see if the PG primary key error happens before running the SpamAssassin install.

Happy to test again and run any instructions.  If that's not practical on your end, let me know and I'll see what else I can work out.

8

Re: dovecot log: imap: Error: DETAIL: Key (username, domain) already exis

communque wrote:

re-imaging the server, re-installing iRedMail with postgreSQL and then re-doing the steps to get SpamAssassin.

What do you mean "get SpamAssassin"?

I cannot reproduce this issue locally.

9

Re: dovecot log: imap: Error: DETAIL: Key (username, domain) already exis

ZhangHuangbin wrote:
communque wrote:

re-imaging the server, re-installing iRedMail with postgreSQL and then re-doing the steps to get SpamAssassin.

What do you mean "get SpamAssassin"?

I cannot reproduce this issue locally.

get SpamAssassin: Refers to what my (possibly mistaken) understanding that setting up SpamAssassin learning via dragging to/from Junk folder requires additional installation.  Let me know if I misunderstood.  I was attempting to get it set up in postgreSQL.

But before getting into that: I re-imaged the OS again and re-installed iRedMail.
This time I did NOT attempt to set up bayes in postgres, so the only steps were those to install iRedMail + certbot for LetsEncrypt and then used iredmail's webmail UI to set up a single email user.

There's no additional customization of any kind.

Nonetheless I'm seeing the duplicate key error already, so it's definitely something coming from the installation process.

I am able to send/receive emails successfully, at least for a while.  After a day or emails stop sending/receiving, and I re-boot the iRedMail server to get things working again.  I don't know if that's related to the error.

10

Re: dovecot log: imap: Error: DETAIL: Key (username, domain) already exis

communque wrote:

Nonetheless I'm seeing the duplicate key error already

How did you trigger this issue? Login to webmail and refresh? Or refresh multiple MUA / webmail with same account at the same time?

I can not reproduce this issue locally.

11

Re: dovecot log: imap: Error: DETAIL: Key (username, domain) already exis

ZhangHuangbin wrote:

How did you trigger this issue? Login to webmail and refresh? Or refresh multiple MUA / webmail with same account at the same time?

Triggered by sending a single email from Apple Mail

Also triggered by sending a single email from iOS Mail

Also triggered by sending a single email via NodeMailerJS

Basically any and all attempts to send emails to this iRedMail account will trigger the 'duplicate key' error

Emails arriving on this server are few and far between at the moment, so it's very easy to distinguish what's sent when.  No emails are being sent simultaneously.  All emails are coming from external servers, none from the iRedMail server in question.

Also confirmed: This email server stops receiving emails at a certain point (TBD) every day.  At around 9am / 10am UTC a backlog of emails arrives -- as if the server machine falls asleep and then later wakes up.  The iRedMail server machine is a remotely-hosted using Ubuntu 24.04 LTS (Jammy), not a desktop machine.  No energy saver software has been installed, and I believe Ubuntu does not include energy savers by default.

12

Re: dovecot log: imap: Error: DETAIL: Key (username, domain) already exis

ZhangHuangbin wrote:
communque wrote:

Nonetheless I'm seeing the duplicate key error already

How did you trigger this issue? Login to webmail and refresh? Or refresh multiple MUA / webmail with same account at the same time?

I can not reproduce this issue locally.

@ZhangHuangbin, in case this is helpful, I re-imaged the machine again, re-installed iRedMail and am pasting all the steps...

All executed as root

All commands under root user, in /root (home) directory

> lsb_release -a
    No LSB modules are available.
    Distributor ID:    Ubuntu
    Description:    Ubuntu 22.04.4 LTS
    Release:    22.04
    Codename:    jammy

> apt-get update

> apt-get upgrade

> vi /etc/hostname
    mail
    [leave.whatver.install.created]

> vi /etc/hosts
    [added to the first line after 127.0.0.1]
    mail.mydomain.com mail localhost
    ['localhost' was already there]

> sudo apt-get install -y gzip dialog
  │ Newer kernel available                                                   │ 
  │                                                                          │ 
  │ The currently running kernel version is 5.15.0-97-generic which is not   │ 
  │ the expected kernel version 5.15.0-117-generic.                          │ 
  │                                                                          │ 
  │ Restarting the system to load the new kernel will not be handled         │ 
  │ automatically, so you should consider rebooting.
  <OK>

OK'd that
                     ┌────┤ Daemons using outdated libraries ├─────┐
                │                                             │ 
                │                                             │ 
                │ Which services should be restarted?         │ 
                │                                             │ 
                │    [*] cron.service                     ↑   │ 
                │    [ ] dbus.service                     ▮   │ 
                │    [ ] getty@tty1.service               ▒   │ 
                │    [*] haveged.service                  ▒   │ 
                │    [*] lw-telegraf.service              ▒   │ 
                │    [ ] ModemManager.service             ▒   │ 
                │    [*] multipathd.service               ▒   │ 
                │    [ ] networkd-dispatcher.service      ▒   │ 
                │    [*] packagekit.service               ▒   │ 
                │    [*] polkit.service                   ↓   │ 
                │                                             │ 
                │                                             │ 
                │          <Ok>              <Cancel>         │ 
                │                                             │ 
                └─────────────────────────────────────────────┘ 

[Ok'd the above, leaving starred default entries as they appeared, no changes]

    Restarting services...
     etc/needrestart/restart.d/systemd-manager
    systemctl restart cron.service haveged.service lw-telegraf.service multipathd.service packagekit.service polkit.service serial-getty@ttyS0.service systemd-journald.service systemd-networkd.service systemd-resolved.service systemd-udevd.service udisks2.service
    Service restarts being deferred:
    systemctl restart ModemManager.service
    /etc/needrestart/restart.d/dbus.service
    systemctl restart getty@tty1.service
    systemctl restart networkd-dispatcher.service
    systemctl restart systemd-logind.service
    systemctl restart unattended-upgrades.service
    systemctl restart user@0.service

    No containers need to be restarted.

    No user sessions are running outdated binaries.

    No VM guests are running outdated hypervisor (qemu) binaries on this host.

> reboot [to "load new kernel"]

> wget https://github.com/iredmail/iRedMail/archive/refs/tags/1.7.1.tar.gz

> tar zxf 1.7.1.tar.gz

> cd iRedMail-1.7.1

> bash iRedMail.sh

    Please specify a directory (in lowercase) used to store user mailboxes. [etc]
    > /var/vmail [default]

    Choose a web server you want to run
    > Nginx

    Choose a preferred backend used to store mail accounts
    > PostgreSQL

    Password for PostgreSQL administrator
    > ****

    Domain
    > mydomain.com

    Password for the mail domain administrator
    > ****

    Optional components
    [*] soundcubemail
    [ ] SOGo
    [*] netdata
    [*] iRedAdmin
    [*] Fail2ban
    <NEXT>

    Continue? [y|N]
    > y

    < Question > Would you like to use firewall rules provided by iRedMail?
    < Question > File: /etc/nftables.conf, with SSHD ports: 22. [Y|n]
    > y

    < Question > Restart firewall now (with ssh ports: 22)? [y|N]
    > y

    * Please reboot your system to enable all mail services.
> reboot

From https://docs.iredmail.org/letsencrypt.html

> apt install -y certbot

> certbot certonly --webroot --dry-run -w /var/www/html -d mail.mydomain.com
The dry run was successful.

> certbot certonly --webroot -w /var/www/html -d mail.mydomain.com
[install successful]

> mv /etc/ssl/certs/iRedMail.crt{,.bak}
> mv /etc/ssl/private/iRedMail.key{,.bak}
> ln -s /etc/letsencrypt/live/mail.mydomain.com/fullchain.pem /etc/ssl/certs/iRedMail.crt
> ln -s /etc/letsencrypt/live/mail.mydomain.com/privkey.pem /etc/ssl/private/iRedMail.key
> systemctl restart postfix dovecot nginx

Added new user at https://mail.mydomain.com/iredadmin/
myuser@mydomain.com

First incoming email immediately producers the duplicate key error, listed in imap.log and dovecot.log

I'm wondering if there's a bug in the iRedMail installer when it comes to postgreSQL?

13

Re: dovecot log: imap: Error: DETAIL: Key (username, domain) already exis

Weird, i cannot reproduce this issue locally.
Is it possible to give me direct ssh access with root privilege for troubleshooting?
Contact us via email: support _at_ iredmail.org

14

Re: dovecot log: imap: Error: DETAIL: Key (username, domain) already exis

ZhangHuangbin wrote:

Weird, i cannot reproduce this issue locally.
Is it possible to give me direct ssh access with root privilege for troubleshooting?
Contact us via email: support _at_ iredmail.org

Hi ZhangHuangbin, in an effort to give you root access I started from scratch yet again but this time on a completely different server, with a different VPS provider, albeit same version OS (Ubuntu 22.04) and same version iRedMail.

Lo and behold problem solved: I'm not seeing any of the duplicate key / postgres errors I was reporting earlier and emails are going through just fine.

I'm thinking that suggests there was something about the VPS provider's Ubuntu image that somehow gave rise to this issue, but I agree with you it is weird.  Any thoughts on your end?

If you want to check out the problem server I can set that up for you, but changing VPS providers in this case did the trick.

15

Re: dovecot log: imap: Error: DETAIL: Key (username, domain) already exis

ZhangHuangbin wrote:

Weird, i cannot reproduce this issue locally.
Is it possible to give me direct ssh access with root privilege for troubleshooting?
Contact us via email: support _at_ iredmail.org

**UPDATE** The "duplicate key" error is back.
I'll get you set up with root access.

16

Re: dovecot log: imap: Error: DETAIL: Key (username, domain) already exis

communque wrote:

I'll get you set up with root access.

Sent you an email.  LMK here and via email we're corrected -- minimal security confirmation at least -- and I'll send the login creds.

Thx.

17

Re: dovecot log: imap: Error: DETAIL: Key (username, domain) already exis

Seems i didn't get your email. sad

18

Re: dovecot log: imap: Error: DETAIL: Key (username, domain) already exis

ZhangHuangbin wrote:

Seems i didn't get your email. sad


Hmmmm sent again to support@iredmail.org

19 (edited by communque 2024-08-20 08:55:56)

Re: dovecot log: imap: Error: DETAIL: Key (username, domain) already exis

**PROBLEM SOLVED** thanks to @ZhangHuangbin

Upgraded to Ubuntu 24.04 from 22.04 and so far no more problem with primary key errors in postgres.

20 (edited by camel1cz 2024-12-05 16:07:10)

Re: dovecot log: imap: Error: DETAIL: Key (username, domain) already exis

If you don't want/cannot upgrade, here is a workaround using postgresql trigger:

-- Trigger definition
CREATE OR REPLACE FUNCTION upsert_last_login() 
RETURNS TRIGGER AS $$
BEGIN
    -- Test if entry already exists
    IF EXISTS (SELECT 1 FROM last_login WHERE username = NEW.username AND domain = NEW.domain) THEN
        -- Update non NULL values
        UPDATE last_login
        SET 
            imap = COALESCE(NEW.imap, imap),
            pop3 = COALESCE(NEW.pop3, pop3),
            lda = COALESCE(NEW.lda, lda)
        WHERE username = NEW.username AND domain = NEW.domain;
        RETURN NULL; -- Prohibits insert of new row
    ELSE
        RETURN NEW; -- If entry doesn't exist yet, proceed with insert
    END IF;
END;
$$ LANGUAGE plpgsql;

-- activate the trigger on insert
CREATE TRIGGER trigger_last_login_upsert
BEFORE INSERT ON last_login
FOR EACH ROW
EXECUTE FUNCTION upsert_last_login();

21

Re: dovecot log: imap: Error: DETAIL: Key (username, domain) already exis

Thanks for sharing.