dsync-trouble

Thu Nov 4 07:50:29 UTC 2021

Hi, Aki,

Am 04.11.21 um 08:29 schrieb Aki Tuomi:
> Hi!

I'm afraid, my problem ist not restricted to doveadm, I can't login to
the server:

Nov  4 08:41:32 freebsd dovecot[81830]: imap-login: Login:
user=<test at hanauix.de>, method=CRAM-MD5, rip=94.79.154.202,
lip=46.4.85.45, mpid=25795, TLS, session=<Kd/Ip/HPouFeT5rK>
Nov  4 08:41:32 freebsd dovecot[81830]:
imap(test at hanauix.de)<25795><Kd/Ip/HPouFeT5rK>: Panic: file array.c:
line 10 (array_idx_modifiable_i): assertion failed: (idx <
array->buffer->used / array->element_size)
Nov  4 08:41:32 freebsd dovecot[81830]:
imap(test at hanauix.de)<25795><Kd/Ip/HPouFeT5rK>: Fatal: master:
service(imap): child 25795 killed with signal 6 (core not dumped -
https://dovecot.org/bugreport.html#coredumps)

and on the replication-partner I get also ssl-related errors:

2021-11-04T08:41:23.147574+01:00 mail dovecot: doveadm(46.4.85.45):
Error: SSL handshake failed: SSL_accept() failed: error:1408F10B:SSL
routines:ssl3_get_record:wrong version number

> Can you send output of 
> 
> doveadm -D sync -u xxx at zzz.de tcps:mail.bruecko.de

(remote machine: 2021-11-04T08:47:08.899932+01:00 mail dovecot: doveadm:
Error: read(SSL 46.4.85.45) failed: EOF (last sent=handshake, last
recv=handshake)

here's the output

root at freebsd:/usr/local/etc/dovecot/conf.d# doveadm -D sync -u
test at hanauix.de tcps:mail.bruecko.de
Debug: Loading modules from directory: /usr/local/lib/dovecot/doveadm
Debug: Skipping module doveadm_acl_plugin, because dlopen() failed:
/usr/local/lib/dovecot/doveadm/lib10_doveadm_acl_plugin.so: Undefined
symbol "acl_user_module" (this is usually intentional, so just ignore
this message)
Debug: Skipping module doveadm_quota_plugin, because dlopen() failed:
/usr/local/lib/dovecot/doveadm/lib10_doveadm_quota_plugin.so: Undefined
symbol "quota_user_module" (this is usually intentional, so just ignore
this message)
Debug: Module loaded:
/usr/local/lib/dovecot/doveadm/lib10_doveadm_sieve_plugin.so
Debug: Skipping module doveadm_fts_lucene_plugin, because dlopen()
failed:
/usr/local/lib/dovecot/doveadm/lib20_doveadm_fts_lucene_plugin.so:
Undefined symbol "lucene_index_init" (this is usually intentional, so
just ignore this message)
Debug: Skipping module doveadm_fts_plugin, because dlopen() failed:
/usr/local/lib/dovecot/doveadm/lib20_doveadm_fts_plugin.so: Undefined
symbol "fts_list_backend" (this is usually intentional, so just ignore
this message)
Debug: Skipping module doveadm_mail_crypt_plugin, because dlopen()
failed: /usr/local/lib/dovecot/doveadm/libdoveadm_mail_crypt_plugin.so:
Undefined symbol "mail_crypt_user_get_public_key" (this is usually
intentional, so just ignore this message)
Nov 04 08:49:59 Debug: Loading modules from directory:
/usr/local/lib/dovecot
Nov 04 08:49:59 Debug: Module loaded:
/usr/local/lib/dovecot/lib01_acl_plugin.so
Nov 04 08:49:59 Debug: Module loaded:
/usr/local/lib/dovecot/lib10_quota_plugin.so
Nov 04 08:49:59 Debug: Module loaded:
/usr/local/lib/dovecot/lib15_notify_plugin.so
Nov 04 08:49:59 Debug: Module loaded:
/usr/local/lib/dovecot/lib20_fts_plugin.so
Nov 04 08:49:59 Debug: Module loaded:
/usr/local/lib/dovecot/lib20_zlib_plugin.so
Nov 04 08:49:59 Debug: Module loaded:
/usr/local/lib/dovecot/lib21_fts_xapian_plugin.so
Nov 04 08:49:59 Debug: Loading modules from directory:
/usr/local/lib/dovecot/doveadm
Nov 04 08:49:59 Debug: Module loaded:
/usr/local/lib/dovecot/doveadm/lib10_doveadm_acl_plugin.so
Nov 04 08:49:59 Debug: Module loaded:
/usr/local/lib/dovecot/doveadm/lib10_doveadm_quota_plugin.so
Nov 04 08:49:59 Debug: Skipping module doveadm_fts_lucene_plugin,
because dlopen() failed:
/usr/local/lib/dovecot/doveadm/lib20_doveadm_fts_lucene_plugin.so:
Undefined symbol "lucene_index_init" (this is usually intentional, so
just ignore this message)
Nov 04 08:49:59 Debug: Module loaded:
/usr/local/lib/dovecot/doveadm/lib20_doveadm_fts_plugin.so
Nov 04 08:49:59 Debug: Skipping module doveadm_mail_crypt_plugin,
because dlopen() failed:
/usr/local/lib/dovecot/doveadm/libdoveadm_mail_crypt_plugin.so:
Undefined symbol "mail_crypt_user_get_public_key" (this is usually
intentional, so just ignore this message)
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug: auth-master: passdb
lookup(test at hanauix.de): Started passdb lookup
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug: auth-master: conn
unix:/var/run/dovecot/auth-userdb: Connecting
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug: auth-master: conn
unix:/var/run/dovecot/auth-userdb (uid=0): Client connected (fd=9)
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug: auth-master: passdb
lookup(test at hanauix.de): auth PASS input: user=test at hanauix.de
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug: auth-master: passdb
lookup(test at hanauix.de): Finished passdb lookup (user=test at hanauix.de )
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><>: Debug: auth-master:
userdb lookup(test at hanauix.de): Started userdb lookup
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><>: Debug: auth-master:
userdb lookup(test at hanauix.de): auth USER input: test at hanauix.de
home=/virtualmail/hanauix.de/test uid=2001 gid=2001
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><>: Debug: auth-master:
userdb lookup(test at hanauix.de): Finished userdb lookup
(username=test at hanauix.de home=/virtualmail/hanauix.de/test uid=2001
gid=2001)
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): auth-master: passdb lookup(test at hanauix.de):
Started passdb lookup
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): auth-master: conn
unix:/var/run/dovecot/auth-userdb: Connecting
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): auth-master: conn
unix:/var/run/dovecot/auth-userdb (pid=1374,uid=0): Client connected (fd=9)
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): auth-master: passdb lookup(test at hanauix.de):
auth PASS input: user=test at hanauix.de
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): auth-master: passdb lookup(test at hanauix.de):
Finished passdb lookup (user=test at hanauix.de )
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): auth-master: userdb lookup(test at hanauix.de):
Started userdb lookup
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): auth-master: userdb lookup(test at hanauix.de):
auth USER input: test at hanauix.de home=/virtualmail/hanauix.de/test
uid=2001 gid=2001
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): auth-master: userdb lookup(test at hanauix.de):
Finished userdb lookup (username=test at hanauix.de
home=/virtualmail/hanauix.de/test uid=2001 gid=2001)
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): Effective uid=2001, gid=2001,
home=/virtualmail/hanauix.de/test
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): Quota root: name=User quota backend=dict
args=:file:/virtualmail/hanauix.de/test/dovecot-quota
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): Quota rule: root=User quota mailbox=*
bytes=2621440000 messages=0
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): Quota rule: root=User quota mailbox=INBOX/Trash
bytes=+262144000 (10%) messages=0
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): Quota warning: bytes=2490368000 (95%)
messages=0 reverse=no command=quota-warning 95 test at hanauix.de
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): Quota warning: bytes=2097152000 (80%)
messages=0 reverse=no command=quota-warning 80 test at hanauix.de
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): Quota warning: bytes=1966080000 (75%)
messages=0 reverse=no command=quota-warning 75 test at hanauix.de
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): Quota grace: root=User quota bytes=262144000
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): dict quota: user=test at hanauix.de,
uri=file:/virtualmail/hanauix.de/test/dovecot-quota, noenforcing=0
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): Namespace inbox: type=private, prefix=INBOX/,
sep=/, inbox=yes, hidden=no, list=yes, subscriptions=yes
location=mdbox:~/mdbox
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): fs: root=/virtualmail/hanauix.de/test/mdbox,
index=, indexpvt=, control=, inbox=, alt=
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): acl: initializing backend with data: vfile
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): acl: acl username = test at hanauix.de
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): acl: owner = 1
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): acl vfile: Global ACLs disabled
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): Namespace : type=shared, prefix=shared/%u/,
sep=/, inbox=no, hidden=no, list=children, subscriptions=yes
location=mdbox:%h/mdbox
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): shared: root=/var/run/dovecot, index=,
indexpvt=, control=, inbox=, alt=
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): fts: Indexes disabled for namespace 'shared/%u/'
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): acl: initializing backend with data: vfile
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): acl: acl username = test at hanauix.de
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): acl: owner = 0
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): acl vfile: Global ACLs disabled
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): Namespace : type=public, prefix=Public/, sep=/,
inbox=no, hidden=no, list=yes, subscriptions=yes
location=mdbox:/virtualmail/public:INDEXPVT=/virtualmail/hanauix.de/test/mdbox/Public
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): fs: root=/virtualmail/public, index=,
indexpvt=/virtualmail/hanauix.de/test/mdbox/Public, control=, inbox=, alt=
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): acl: initializing backend with data: vfile
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): acl: acl username = test at hanauix.de
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): acl: owner = 0
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): acl vfile: Global ACLs disabled
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): Namespace : type=private, prefix=, sep=,
inbox=no, hidden=yes, list=no, subscriptions=no location=fail::LAYOUT=none
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): none: root=, index=, indexpvt=, control=,
inbox=, alt=
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): fts: Indexes disabled for namespace ''
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): quota: quota_over_flag check: quota_over_script
unset - skipping
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): trash plugin: Added 'INBOX/Trash' with priority 1
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): trash plugin: Added 'INBOX/Sent' with priority 2
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug:
remote(mail.bruecko.de): trash plugin: Added 'INBOX/Sent Messages' with
priority 2
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><rP3vIaeQg2HTEAEAA4a8sQ>:
Debug: Effective uid=2001, gid=2001, home=/virtualmail/hanauix.de/test
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><rP3vIaeQg2HTEAEAA4a8sQ>:
Debug: dict(file): dict created
(uri=file:/virtualmail/shared-mailboxes.db, base_dir=/var/run/dovecot)
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><rP3vIaeQg2HTEAEAA4a8sQ>:
Debug: Quota root: name=User quota backend=dict
args=:file:/virtualmail/hanauix.de/test/dovecot-quota
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><rP3vIaeQg2HTEAEAA4a8sQ>:
Debug: Quota rule: root=User quota mailbox=* bytes=2621440000 messages=0
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><rP3vIaeQg2HTEAEAA4a8sQ>:
Debug: Quota rule: root=User quota mailbox=INBOX/Trash bytes=+262144000
(10%) messages=0
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><rP3vIaeQg2HTEAEAA4a8sQ>:
Debug: Quota warning: bytes=2490368000 (95%) messages=0 reverse=no
command=quota-warning 95 test at hanauix.de
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><rP3vIaeQg2HTEAEAA4a8sQ>:
Debug: Quota warning: bytes=2097152000 (80%) messages=0 reverse=no
command=quota-warning 80 test at hanauix.de
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><rP3vIaeQg2HTEAEAA4a8sQ>:
Debug: Quota warning: bytes=1966080000 (75%) messages=0 reverse=no
command=quota-warning 75 test at hanauix.de
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><rP3vIaeQg2HTEAEAA4a8sQ>:
Debug: Quota grace: root=User quota bytes=262144000
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><rP3vIaeQg2HTEAEAA4a8sQ>:
Debug: quota-dict: user=test at hanauix.de,
uri=file:/virtualmail/hanauix.de/test/dovecot-quota, noenforcing=0
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><rP3vIaeQg2HTEAEAA4a8sQ>:
Debug: dict(file): dict created
(uri=file:/virtualmail/hanauix.de/test/dovecot-quota,
base_dir=/var/run/dovecot)
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><rP3vIaeQg2HTEAEAA4a8sQ>:
Debug: Namespace inbox: type=private, prefix=INBOX/, sep=/, inbox=yes,
hidden=no, list=yes, subscriptions=yes location=mdbox:~/mdbox
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><rP3vIaeQg2HTEAEAA4a8sQ>:
Debug: fs: root=/virtualmail/hanauix.de/test/mdbox, index=, indexpvt=,
control=, inbox=, alt=
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><rP3vIaeQg2HTEAEAA4a8sQ>:
Debug: acl: initializing backend with data: vfile
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><rP3vIaeQg2HTEAEAA4a8sQ>:
Debug: acl: acl username = test at hanauix.de
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><rP3vIaeQg2HTEAEAA4a8sQ>:
Debug: acl: owner = 1
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><rP3vIaeQg2HTEAEAA4a8sQ>:
Debug: acl vfile: Global ACLs disabled
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><rP3vIaeQg2HTEAEAA4a8sQ>:
Debug: Namespace : type=shared, prefix=shared/%u/, sep=/, inbox=no,
hidden=no, list=children, subscriptions=yes location=mdbox:%h/mdbox
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><rP3vIaeQg2HTEAEAA4a8sQ>:
Debug: shared: root=/var/run/dovecot, index=, indexpvt=, control=,
inbox=, alt=
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><rP3vIaeQg2HTEAEAA4a8sQ>:
Debug: fts: Indexes disabled for namespace 'shared/%u/'
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><rP3vIaeQg2HTEAEAA4a8sQ>:
Debug: acl: initializing backend with data: vfile
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><rP3vIaeQg2HTEAEAA4a8sQ>:
Debug: acl: acl username = test at hanauix.de
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><rP3vIaeQg2HTEAEAA4a8sQ>:
Debug: acl: owner = 0
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><rP3vIaeQg2HTEAEAA4a8sQ>:
Debug: acl vfile: Global ACLs disabled
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><rP3vIaeQg2HTEAEAA4a8sQ>:
Debug: Namespace : type=public, prefix=Public/, sep=/, inbox=no,
hidden=no, list=yes, subscriptions=yes
location=mdbox:/virtualmail/public:INDEXPVT=/virtualmail/hanauix.de/test/mdbox/Public
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><rP3vIaeQg2HTEAEAA4a8sQ>:
Debug: fs: root=/virtualmail/public, index=,
indexpvt=/virtualmail/hanauix.de/test/mdbox/Public, control=, inbox=, alt=
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><rP3vIaeQg2HTEAEAA4a8sQ>:
Debug: acl: initializing backend with data: vfile
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><rP3vIaeQg2HTEAEAA4a8sQ>:
Debug: acl: acl username = test at hanauix.de
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><rP3vIaeQg2HTEAEAA4a8sQ>:
Debug: acl: owner = 0
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><rP3vIaeQg2HTEAEAA4a8sQ>:
Debug: acl vfile: Global ACLs disabled
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><rP3vIaeQg2HTEAEAA4a8sQ>:
Debug: Namespace : type=private, prefix=, sep=, inbox=no, hidden=yes,
list=no, subscriptions=no location=fail::LAYOUT=none
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><rP3vIaeQg2HTEAEAA4a8sQ>:
Debug: none: root=, index=, indexpvt=, control=, inbox=, alt=
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><rP3vIaeQg2HTEAEAA4a8sQ>:
Debug: fts: Indexes disabled for namespace ''
Nov 04 08:49:59 doveadm(test at hanauix.de)<69843><rP3vIaeQg2HTEAEAA4a8sQ>:
Debug: quota: quota_over_flag check: quota_over_script unset - skipping
Nov 04 08:49:59 doveadm(test at hanauix.de): Debug: brain M: Namespace
INBOX/ has location mdbox:~/mdbox
Nov 04 08:49:59 doveadm(test at hanauix.de): Panic: file array.c: line 10
(array_idx_modifiable_i): assertion failed: (idx < array->buffer->used /
array->element_size)
Abort

Thanks for Your help
Regards Hanns