Hi,
we get errors about corrupted indexes and we are losing flags with mdbox on
NFSv4:
Error: Recent flags state corrupted for mailbox
Error: Corrupted dbox file
Error: Corrupted transaction log file
It looks like a LMTP director problem. The user has IMAP IDLE connections
open and lmtp delivers to another host. This leads to nfs corruption problems.
The user is logged into mail04 and has some IMAP IDLE mailbox connections open:
mail04:~# ps -ef|grep someuser
vmail 5217 23918 0 Jun07 ? 00:00:00 dovecot/imap [someu...@example.de
10.129.3.190 IDLE]
vmail 8623 23918 0 Jun07 ? 00:00:00 dovecot/imap [someu...@example.de
10.129.3.233 IDLE]
vmail 20279 23918 0 00:37 ? 00:00:00 dovecot/imap [someu...@example.de
10.129.3.213 IDLE]
If postfix on mail01/dcmailbox01 receives an incoming mail now, the director on
mail01
does NOT direct LMTP to the responsible host mail04/dcmailbox04 (10.129.3.190),
but delivers it locally to mail01 (10.129.3.193), which leads to file
corruption.
mail01:~# doveadm -c /etc/dovecot-director/dovecot-director.conf director
status someu...@example.de
Current: not assigned
Hashed: 10.129.3.193
Initial config: 10.129.3.193
mail01:~# host 10.129.3.193
193.3.129.10.in-addr.arpa domain name pointer dcmailbox01.example.net.
mail01 runs the lmtp proxy and lmtp delivery,
even though the user is logged in via IMAP IDLE on mail04:
mail01:~# grep "^Jun 8 03:36:.*someu...@example.de" /var/log/server/dovecot.log
Jun 8 03:36:02 10.129.3.233 dovecot: lmtp(27124): Debug: auth input:
someu...@example.de home=/mail/dovecot/example.de/someuser uid=501 gid=123
quota_rule=*:bytes=5000M:messages=0
Jun 8 03:36:02 10.129.3.233 dovecot: lmtp(27124, someu...@example.de): Debug:
Effective uid=501, gid=123, home=/mail/dovecot/example.de/someuser
Jun 8 03:36:02 10.129.3.233 dovecot: lmtp(27124, someu...@example.de): Debug:
Quota root: name=User quota backend=dict args=:proxy::quota
Jun 8 03:36:02 10.129.3.233 dovecot: lmtp(27124, someu...@example.de): Debug:
Quota rule: root=User quota mailbox=* bytes=5242880000 messages=0
Jun 8 03:36:02 10.129.3.233 dovecot: lmtp(27124, someu...@example.de): Debug:
Quota rule: root=User quota mailbox=Trash bytes=+104857600 messages=0
Jun 8 03:36:02 10.129.3.233 dovecot: lmtp(27124, someu...@example.de): Debug:
Quota warning: bytes=4980736000 (95%) messages=0 reverse=no
command=quota-warning 95 someu...@example.de
Jun 8 03:36:02 10.129.3.233 dovecot: lmtp(27124, someu...@example.de): Debug:
Quota warning: bytes=4194304000 (80%) messages=0 reverse=no
command=quota-warning 80 someu...@example.de
Jun 8 03:36:02 10.129.3.233 dovecot: lmtp(27124, someu...@example.de): Debug:
dict quota: user=someu...@example.de, uri=proxy::quota, noenforcing=0
Jun 8 03:36:02 10.129.3.233 dovecot: lmtp(27124, someu...@example.de): Debug:
fs: root=/mail/dovecot/example.de/someuser/mail, index=, control=, inbox=, alt=
Jun 8 03:36:02 10.129.3.233 dovecot: lmtp(27124, someu...@example.de): Debug:
Namespace : Using permissions from /mail/dovecot/example.de/someuser/mail:
mode=0700 gid=-1
Jun 8 03:36:02 10.129.3.233 dovecot: lmtp(27124, someu...@example.de): Debug:
sieve: include: sieve_global_dir is not set; it is currently not possible to
include `:global' scripts.
Jun 8 03:36:02 10.129.3.233 dovecot: lmtp(27124, someu...@example.de): Debug:
jOv8JgJX0U/0aQAA3l+BKA: sieve: using sieve path for user's script:
/mail/dovecot/example.de/someuser/.dovecot.sieve
Jun 8 03:36:02 10.129.3.233 dovecot: lmtp(27124, someu...@example.de): Debug:
jOv8JgJX0U/0aQAA3l+BKA: sieve: opening script
/mail/dovecot/example.de/someuser/.dovecot.sieve
Jun 8 03:36:02 10.129.3.233 dovecot: lmtp(27124, someu...@example.de): Debug:
jOv8JgJX0U/0aQAA3l+BKA: sieve: script binary
/mail/dovecot/example.de/someuser/.dovecot.svbin successfully loaded
Jun 8 03:36:02 10.129.3.233 dovecot: lmtp(27124, someu...@example.de): Debug:
jOv8JgJX0U/0aQAA3l+BKA: sieve: binary save: not saving binary
/mail/dovecot/example.de/someuser/.dovecot.svbin, because
it is already stored
Jun 8 03:36:02 10.129.3.233 dovecot: lmtp(27124, someu...@example.de): Debug:
jOv8JgJX0U/0aQAA3l+BKA: sieve: executing script from
/mail/dovecot/example.de/someuser/.dovecot.svbin
Jun 8 03:36:02 10.129.3.213 dovecot: lmtp(23404): Debug: auth input:
user=someu...@example.de proxy port=19024 host=10.129.3.193 proxy_refresh=450
Jun 8 03:36:02 10.129.3.233 dovecot: lmtp(27124, someu...@example.de):
jOv8JgJX0U/0aQAA3l+BKA: sieve: mailbox: deliver:
msgid=<201206080136.q581a1rc024...@iolite.ham.srv.mcs.de>
from=serv...@cityline.net: stored mail into mailbox 'INBOX'
Jun 8 03:36:02 10.129.3.213 dovecot: lmtp(23406): Debug: auth input:
user=someu...@example.de proxy port=19024 host=10.129.3.193 proxy_refresh=450
Jun 8 03:36:02 10.129.3.233 dovecot: lmtp(27125): Debug: auth input:
someu...@example.de home=/mail/dovecot/example.de/someuser uid=501 gid=123
quota_rule=*:bytes=5000M:messages=0
Jun 8 03:36:02 10.129.3.233 dovecot: lmtp(27125, someu...@example.de): Debug:
Effective uid=501, gid=123, home=/mail/dovecot/example.de/someuser
Jun 8 03:36:02 10.129.3.233 dovecot: lmtp(27125, someu...@example.de): Debug:
Quota root: name=User quota backend=dict args=:proxy::quota
Jun 8 03:36:02 10.129.3.233 dovecot: lmtp(27125, someu...@example.de): Debug:
Quota rule: root=User quota mailbox=* bytes=5242880000 messages=0
Jun 8 03:36:02 10.129.3.233 dovecot: lmtp(27125, someu...@example.de): Debug:
Quota rule: root=User quota mailbox=Trash bytes=+104857600 messages=0
Jun 8 03:36:02 10.129.3.233 dovecot: lmtp(27125, someu...@example.de): Debug:
Quota warning: bytes=4980736000 (95%) messages=0 reverse=no
command=quota-warning 95 someu...@example.de
Jun 8 03:36:02 10.129.3.233 dovecot: lmtp(27125, someu...@example.de): Debug:
Quota warning: bytes=4194304000 (80%) messages=0 reverse=no
command=quota-warning 80 someu...@example.de
Jun 8 03:36:02 10.129.3.233 dovecot: lmtp(27125, someu...@example.de): Debug:
dict quota: user=someu...@example.de, uri=proxy::quota, noenforcing=0
Jun 8 03:36:02 10.129.3.233 dovecot: lmtp(27125, someu...@example.de): Debug:
fs: root=/mail/dovecot/example.de/someuser/mail, index=, control=, inbox=, alt=
Jun 8 03:36:02 10.129.3.233 dovecot: lmtp(27125, someu...@example.de): Debug:
Namespace : Using permissions from /mail/dovecot/example.de/someuser/mail:
mode=0700 gid=-1
Jun 8 03:36:02 10.129.3.233 dovecot: lmtp(27125, someu...@example.de): Debug:
sieve: include: sieve_global_dir is not set; it is currently not possible to
include `:global' scripts.
Jun 8 03:36:02 10.129.3.233 dovecot: lmtp(27125, someu...@example.de): Debug:
gWijMAJX0U/1aQAA3l+BKA: sieve: using sieve path for user's script:
/mail/dovecot/example.de/someuser/.dovecot.sieve
Jun 8 03:36:02 10.129.3.233 dovecot: lmtp(27125, someu...@example.de): Debug:
gWijMAJX0U/1aQAA3l+BKA: sieve: opening script
/mail/dovecot/example.de/someuser/.dovecot.sieve
Jun 8 03:36:02 10.129.3.233 dovecot: lmtp(27125, someu...@example.de): Debug:
gWijMAJX0U/1aQAA3l+BKA: sieve: script binary
/mail/dovecot/example.de/someuser/.dovecot.svbin successfully loaded
Jun 8 03:36:02 10.129.3.233 dovecot: lmtp(27125, someu...@example.de): Debug:
gWijMAJX0U/1aQAA3l+BKA: sieve: binary save: not saving binary
/mail/dovecot/example.de/someuser/.dovecot.svbin, because
it is already stored
Jun 8 03:36:02 10.129.3.233 dovecot: lmtp(27125, someu...@example.de): Debug:
gWijMAJX0U/1aQAA3l+BKA: sieve: executing script from
/mail/dovecot/example.de/someuser/.dovecot.svbin
Jun 8 03:36:02 10.129.3.233 dovecot: lmtp(27125, someu...@example.de):
gWijMAJX0U/1aQAA3l+BKA: sieve: mailbox: deliver:
msgid=<201206080136.q581a1t0024...@iolite.ham.srv.mcs.de>
from=serv...@cityline.net: stored mail into mailbox 'INBOX'
The "user logged on via IMAP on mail04" and "lmtp delivery on mail01"
seems to lead to corruption of mdbox indexes:
Jun 8 03:36:03 10.129.3.200 dovecot: mailbox: mail: imap(someu...@example.de):
Error: Corrupted transaction log file
/mail/dovecot/example.de/someuser/mail/mailboxes/INBOX/dbox-
Mails/dovecot.index.log seq 82: Invalid transaction log size (32856 vs 32824):
/mail/dovecot/example.de/someuser/mail/mailboxes/INBOX/dbox-Mails/dovecot.index.log
(sync_offset=32856)
Jun 8 03:36:03 10.129.3.200 dovecot: mailbox: mail: imap(someu...@example.de):
Error: Index
/mail/dovecot/example.de/someuser/mail/mailboxes/INBOX/dbox-Mails/dovecot.index:
Lost log for seq=82
offset=32856
Jun 8 03:36:03 10.129.3.200 dovecot: mailbox: mail: imap(someu...@example.de):
Warning: fscking index file
/mail/dovecot/example.de/someuser/mail/mailboxes/INBOX/dbox-Mails/dovecot.index
Jun 8 03:36:03 10.129.3.200 dovecot: mailbox: mail: imap(someu...@example.de):
Error: Fixed index file
/mail/dovecot/example.de/someuser/mail/mailboxes/INBOX/dbox-Mails/dovecot.index:
log_file_seq 82
-> 83
Jun 8 03:36:38 10.129.3.200 dovecot: mailbox: mail: imap(someu...@example.de):
Error: Transaction log file
/mail/dovecot/example.de/someuser/mail/mailboxes/INBOX/dbox-Mails/dovecot.index.log.2:
marked corrupted
How to enable the LMTP director to deliver to the correct mailbox host?
Configuration of mailbox and director of mail01 is attached.
Regards,
Daniel
# 2.0.20: /etc/dovecot/dovecot.conf
# OS: Linux 2.6.32-40-server x86_64 Ubuntu 10.04.4 LTS
auth_cache_negative_ttl = 0
auth_cache_size = 10 M
auth_cache_ttl = 1 mins
auth_debug = yes
auth_verbose = yes
auth_verbose_passwords = sha1
deliver_log_format = mailbox: deliver: msgid=%m from=%f: %$
dict {
quota = mysql:/etc/dovecot/conf.d/dovecot-dict-sql.conf.ext
}
disable_plaintext_auth = no
instance_name = dovecot-mailbox
lda_mailbox_autocreate = yes
lda_mailbox_autosubscribe = yes
login_greeting = Mailbox
login_log_format = mailbox: login: %$: %s
login_trusted_networks = 10.129.3.0/24
mail_debug = yes
mail_fsync = always
mail_gid = vmail
mail_home = /mail/dovecot/%d/%n
mail_location = mdbox:~/mail
mail_log_prefix = "mailbox: mail: %s(%u): "
mail_plugins = quota
mail_privileged_group = vmail
mail_uid = vmail
managesieve_implementation_string = Sieve
managesieve_notify_capability = mailto
managesieve_sieve_capability = fileinto reject envelope encoded-character
vacation subaddress comparator-i;ascii-numeric relational regex imap4flags copy
include variables body enotify environment mailbox date ihave
mdbox_rotate_interval = 1 weeks
mdbox_rotate_size = 50 M
mmap_disable = yes
passdb {
args = /etc/dovecot/conf.d/dovecot-sql.conf.ext
driver = sql
}
plugin {
quota = dict:User quota::proxy::quota
quota_rule = *:storage=10G
quota_rule2 = Trash:storage=+100M
quota_warning = storage=95%% quota-warning 95 %u
quota_warning2 = storage=80%% quota-warning 80 %u
sieve = ~/.dovecot.sieve
sieve_dir = ~/sieve
}
protocols = imap pop3 lmtp sieve
service auth {
unix_listener auth-userdb {
group = dovecot
mode = 0660
user = dovecot
}
}
service dict {
unix_listener dict {
group = vmail
mode = 0660
}
}
service imap-login {
inet_listener imap {
port = 19143
}
}
service lmtp {
inet_listener lmtp {
address = *
port = 19024
}
}
service managesieve-login {
inet_listener sieve {
port = 19200
}
}
service pop3-login {
inet_listener pop3 {
port = 19110
}
}
service quota-warning {
executable = script /usr/local/bin/quota-warning
extra_groups = dovecot
unix_listener quota-warning {
user = vmail
}
user = vmail
}
ssl = no
userdb {
driver = prefetch
}
userdb {
args = /etc/dovecot/conf.d/dovecot-sql.conf.ext
driver = sql
}
verbose_proctitle = yes
protocol imap {
imap_client_workarounds = delay-newmail tb-extra-mailbox-sep
mail_plugins = quota imap_quota
}
protocol lmtp {
mail_plugins = quota sieve
}
# 2.0.20: /etc/dovecot-director/dovecot-director.conf
# OS: Linux 2.6.32-40-server x86_64 Ubuntu 10.04.4 LTS
auth_debug = yes
auth_verbose = yes
auth_verbose_passwords = sha1
base_dir = /var/run/dovecot-director
deliver_log_format = director: deliver: msgid=%m from=%f: %$
director_mail_servers = 10.129.3.193 10.129.3.192 10.129.3.191 10.129.3.190
director_servers = 10.129.3.193 10.129.3.192 10.129.3.191 10.129.3.190
instance_name = dovecot-director
lmtp_proxy = yes
login_greeting = Mail Balancer
login_log_format = director: login: %$: %s
login_trusted_networks = 10.129.3.0/24
mail_debug = yes
mail_fsync = always
mail_gid = vmail
mail_home = /mail/dovecot/%d/%n
mail_location = mdbox:~/mail
mail_log_prefix = "director: mail: %s(%u): "
mail_privileged_group = vmail
mail_uid = vmail
managesieve_notify_capability = mailto
managesieve_sieve_capability = fileinto reject envelope encoded-character
vacation subaddress comparator-i;ascii-numeric relational regex imap4flags copy
include variables body enotify environment mailbox date ihave
mmap_disable = yes
passdb {
args = proxy=y nopassword=y user=%n@dovecotmail.%d
driver = static
}
protocols = imap pop3 lmtp sieve
service auth {
unix_listener auth-userdb {
user = dovecot
}
}
service director {
fifo_listener login/proxy-notify {
mode = 0666
}
inet_listener {
port = 9090
}
unix_listener director-userdb {
mode = 0600
}
unix_listener login/director {
mode = 0666
}
}
service imap-login {
executable = imap-login director
inet_listener imap {
port = 20143
}
inet_listener imaps {
port = 20993
ssl = yes
}
}
service lmtp {
inet_listener lmtp {
address = *
port = 20024
}
}
service managesieve-login {
inet_listener sieve {
port = 20200
}
}
service pop3-login {
executable = pop3-login director
inet_listener pop3 {
port = 20110
}
inet_listener pop3s {
port = 20995
ssl = yes
}
}
ssl_cert = </etc/certs/wildcard.example.net.crt
ssl_key = </etc/certs/wildcard.example.net.key
verbose_proctitle = yes
protocol lmtp {
auth_socket_path = director-userdb
passdb {
args = proxy=y nopassword=y port=19024
driver = static
}
}
protocol sieve {
auth_socket_path = director-userdb
passdb {
args = proxy=y nopassword=y port=19200
driver = static
}
}
protocol imap {
imap_client_workarounds = delay-newmail tb-extra-mailbox-sep
}
