dsync-trouble

Thu Nov 4 07:51:49 UTC 2021

That's in IMAP process, not in doveadm process.

Can you try obtaining the core and producing gdb bt full for it?

Please refer to https://www.dovecot.org/bugreport-mail/ for more details.

Aki

> On 04/11/2021 09:50 Hanns Mattes <hanns at hannsmattes.de> wrote:
> 
>  
> 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