thr3ads.net - dovecot - Auth process sometimes stop responding after upgrade [Sep 2018]

If this information is useful, please help other people find it:
Share via:

Simone Lazzaris

2018-Sep-07 13:50 UTC

Auth process sometimes stop responding after upgrade

Some more information: the issue has just occurred, again on an instance without
the
"service_count = 0" configuration directive on pop3-login.

I've observed that while the issue is occurring, the director process goes
100% CPU. I've
straced the process. It is seemingly looping:

...
...
epoll_ctl(13, EPOLL_CTL_ADD, 78, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, 
{u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_DEL, 78, {0, {u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_ADD, 78, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, 
{u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_DEL, 78, {0, {u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_ADD, 78, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, 
{u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_DEL, 78, {0, {u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_ADD, 78, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, 
{u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_DEL, 78, {0, {u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_ADD, 78, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, 
{u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_DEL, 78, {0, {u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_ADD, 78, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, 
{u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_DEL, 78, {0, {u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_ADD, 78, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, 
{u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_DEL, 78, {0, {u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_ADD, 78, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, 
{u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_DEL, 78, {0, {u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_ADD, 78, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, 
{u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_DEL, 78, {0, {u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_ADD, 78, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, 
{u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_DEL, 78, {0, {u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_ADD, 78, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, 
{u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_DEL, 78, {0, {u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_ADD, 78, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, 
{u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_DEL, 78, {0, {u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_ADD, 78, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, 
{u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_DEL, 78, {0, {u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_ADD, 78, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, 
{u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_DEL, 78, {0, {u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_ADD, 78, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, 
{u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_DEL, 78, {0, {u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_ADD, 78, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, 
{u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_DEL, 78, {0, {u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_ADD, 78, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, 
{u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_DEL, 78, {0, {u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_ADD, 78, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, 
{u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_DEL, 78, {0, {u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_ADD, 78, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, 
{u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_DEL, 78, {0, {u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_ADD, 78, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, 
{u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_DEL, 78, {0, {u32=149035320, u64=149035320}}) = 0
epoll_ctl(13, EPOLL_CTL_ADD, 78, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, 
{u32=149035320, u64=149035320}}) = 0
...
...
...

FD 13 is "anon_inode:[eventpoll]"

Killing (with -9) the director process, without stopping or restarting the
service, restores
the correct behaviour.



*Simone Lazzaris*
*Qcom S.p.A.*
simone.lazzaris at qcom.it[1] | www.qcom.it[2]
* LinkedIn[3]* | *Facebook[4]*
[5] 






--------
[1] mailto:simone.lazzaris at qcom.it
[2] https://www.qcom.it
[3] https://www.linkedin.com/company/qcom-spa
[4] http://www.facebook.com/qcomspa
[5] https://www.qcom.it/includes/email-banner.gif
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<https://dovecot.org/pipermail/dovecot/attachments/20180907/1b50d5fb/attachment-0001.html>

Timo Sirainen

2018-Sep-07 16:43 UTC

head link

Auth process sometimes stop responding after upgrade

On 7 Sep 2018, at 16.50, Simone Lazzaris <s.lazzaris at interactive.eu>
wrote:> 
> Some more information: the issue has just occurred, again on an instance
without the "service_count = 0" configuration directive on pop3-login.
>  
> I've observed that while the issue is occurring, the director process
goes 100% CPU. I've straced the process. It is seemingly looping:
>  
> ...
> ...
> epoll_ctl(13, EPOLL_CTL_ADD, 78, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP,
{u32=149035320, u64=149035320}}) = 0
> epoll_ctl(13, EPOLL_CTL_DEL, 78, {0, {u32=149035320, u64=149035320}}) = 0
> epoll_ctl(13, EPOLL_CTL_ADD, 78, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP,
{u32=149035320, u64=149035320}}) = 0
> epoll_ctl(13, EPOLL_CTL_DEL, 78, {0, {u32=149035320, u64=149035320}}) = 0
> epoll_ctl(13, EPOLL_CTL_ADD, 78, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP,
{u32=149035320, u64=149035320}}) = 0
> epoll_ctl(13, EPOLL_CTL_DEL, 78, {0, {u32=149035320, u64=149035320}}) = 0
Nothing else but these epoll_ctl() calls? So it's gone to some loop where it
keeps calling io_add() and io_remove().
> FD 13 is "anon_inode:[eventpoll]"
What about fd 78? I guess some socket.

Could you also try two more things when it happens again:

ltrace -tt -e '*' -o ltrace.log -p <pid>
(My guess this isn't going to be very useful, but just in case it might
be..)

gdb -p <pid>
bt full
quit

Preferably install dovecot-dbg package also so the gdb backtrace output will be
better.

-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<https://dovecot.org/pipermail/dovecot/attachments/20180907/aab36594/attachment.html>

Timo Sirainen

2018-Sep-07 17:11 UTC

head link

Auth process sometimes stop responding after upgrade

On 7 Sep 2018, at 19.43, Timo Sirainen <tss at iki.fi>
wrote:> 
> On 7 Sep 2018, at 16.50, Simone Lazzaris <s.lazzaris at interactive.eu
<mailto:s.lazzaris at interactive.eu>> wrote:
>> 
>> Some more information: the issue has just occurred, again on an
instance without the "service_count = 0" configuration directive on
pop3-login.
>>  
>> I've observed that while the issue is occurring, the director
process goes 100% CPU. I've straced the process. It is seemingly looping:
>>  
>> ...
>> ...
>> epoll_ctl(13, EPOLL_CTL_ADD, 78, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP,
{u32=149035320, u64=149035320}}) = 0
>> epoll_ctl(13, EPOLL_CTL_DEL, 78, {0, {u32=149035320, u64=149035320}}) =
0
>> epoll_ctl(13, EPOLL_CTL_ADD, 78, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP,
{u32=149035320, u64=149035320}}) = 0
>> epoll_ctl(13, EPOLL_CTL_DEL, 78, {0, {u32=149035320, u64=149035320}}) =
0
>> epoll_ctl(13, EPOLL_CTL_ADD, 78, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP,
{u32=149035320, u64=149035320}}) = 0
>> epoll_ctl(13, EPOLL_CTL_DEL, 78, {0, {u32=149035320, u64=149035320}}) =
0
> 
> Nothing else but these epoll_ctl() calls? So it's gone to some loop
where it keeps calling io_add() and io_remove().
I'm guessing it's because of doveadm command handling issues, since
there's some weirdness in the code. Although I couldn't figure out
exactly why it would go to infinite loop there. But attached a patch that may
fix it, if you're able to test. We haven't noticed such infinite looping
in other installations or automated director stresstests though..

>> FD 13 is "anon_inode:[eventpoll]"
> 
> What about fd 78? I guess some socket.
> 
> Could you also try two more things when it happens again:
> 
> ltrace -tt -e '*' -o ltrace.log -p <pid>
> (My guess this isn't going to be very useful, but just in case it might
be..)
> 
> gdb -p <pid>
> bt full
> quit
> 
> Preferably install dovecot-dbg package also so the gdb backtrace output
will be better.
These would still be useful to verify whether I'm even on the right track.

-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<https://dovecot.org/pipermail/dovecot/attachments/20180907/14a8118c/attachment.html>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: 2417.patch
Type: application/octet-stream
Size: 1481 bytes
Desc: not available
URL:
<https://dovecot.org/pipermail/dovecot/attachments/20180907/14a8118c/attachment.obj>
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<https://dovecot.org/pipermail/dovecot/attachments/20180907/14a8118c/attachment-0001.html>

Simone Lazzaris

2018-Sep-08 11:56 UTC

head link

Auth process sometimes stop responding after upgrade

In data venerd? 7 settembre 2018 18:43:36 CEST, Timo Sirainen ha scritto:

Hi Timo;
it happened again, this time on a "high-performance" instance (e.g.,
WITH
service_count=0)
> On 7 Sep 2018, at 16.50, Simone Lazzaris <s.lazzaris at
interactive.eu> wrote:
> > Some more information: the issue has just occurred, again on an
instance
> > without the "service_count = 0" configuration directive on
pop3-login.
> Could you also try two more things when it happens again:
> 
> ltrace -tt -e '*' -o ltrace.log -p <pid>
> (My guess this isn't going to be very useful, but just in case it might
> be..)
Done; unfortunately, ltrace.log is empty.
> gdb -p <pid>
> bt full
> quit
> 
Here it is:

root at imapfront2:/usr/local/src/dovecot-2.2.36/src# gdb -p 31635
GNU gdb (GDB) 7.4.1-debian
Copyright (C) 2012 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later
<http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show
copying"
and "show warranty" for details.
This GDB was configured as "i486-linux-gnu".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Attaching to process 31635
Reading symbols from /usr/local/libexec/dovecot/director...done.
Reading symbols from /usr/local/lib/dovecot/libdovecot.so.0...done.
Loaded symbols for /usr/local/lib/dovecot/libdovecot.so.0
Reading symbols from /lib/i386-linux-gnu/i686/cmov/libc.so.6...(no debugging 
symbols found)...done.
Loaded symbols for /lib/i386-linux-gnu/i686/cmov/libc.so.6
Reading symbols from /lib/i386-linux-gnu/i686/cmov/libdl.so.2...(no debugging 
symbols found)...done.
Loaded symbols for /lib/i386-linux-gnu/i686/cmov/libdl.so.2
Reading symbols from /lib/i386-linux-gnu/i686/cmov/librt.so.1...(no debugging 
symbols found)...done.
Loaded symbols for /lib/i386-linux-gnu/i686/cmov/librt.so.1
Reading symbols from /lib/ld-linux.so.2...(no debugging symbols found)...done.
Loaded symbols for /lib/ld-linux.so.2
Reading symbols from /lib/i386-linux-gnu/i686/cmov/libpthread.so.0...(no 
debugging symbols found)...done.
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/i386-linux-gnu/i686/cmov/
libthread_db.so.1".
Loaded symbols for /lib/i386-linux-gnu/i686/cmov/libpthread.so.0
0xb76fa428 in __kernel_vsyscall ()
(gdb) bt full
#0  0xb76fa428 in __kernel_vsyscall ()
No symbol table info available.
#1  0xb752929e in epoll_ctl () from /lib/i386-linux-gnu/i686/cmov/libc.so.6
No symbol table info available.
#2  0xb7678aa0 in io_loop_handle_add (io=io at entry=0x815db90) at ioloop-
epoll.c:106
        ctx = 0x8144e98
        list = 0x814556c
        event = {events = 27, data = {ptr = 0x815c160, fd = 135643488, u32 = 
135643488, u64 = 135643488}}
        op = 1
        first = <optimized out>
#3  0xb7676a7d in io_add_file (fd=fd at entry=27, 
condition=condition at entry=IO_READ, 
    source_filename=source_filename at entry=0x805f7f4
"doveadm-connection.c",
source_linenum=source_linenum at entry=1070, 
    callback=callback at entry=0x8057e10 <doveadm_connection_input>, 
context=context at entry=0x8166398) at ioloop.c:64
        io = 0x815db90
        __FUNCTION__ = "io_add_file"
#4  0xb7676bef in io_add (fd=27, condition=condition at entry=IO_READ, 
    source_filename=source_filename at entry=0x805f7f4
"doveadm-connection.c",
source_linenum=source_linenum at entry=1070, 
    callback=callback at entry=0x8057e10 <doveadm_connection_input>, 
context=context at entry=0x8166398) at ioloop.c:87
        io = <optimized out>
        __FUNCTION__ = "io_add"
#5  0x08057135 in doveadm_connection_set_io (conn=conn at entry=0x8166398) at 
doveadm-connection.c:1070
No locals.
#6  0x08059528 in doveadm_connections_ring_synced () at doveadm-connection.c:
1171
        conn = 0x8166398
        callback = 0x8057f90 <doveadm_connection_cmd_run_synced>
#7  0xb76777b7 in io_loop_handle_timeouts_real (ioloop=0x8138678) at ioloop.c:
568
        timeout = 0x8165a38
        item = 0x8165a38
        tv = {tv_sec = 0, tv_usec = 0}
        tv_call = {tv_sec = 1536404874, tv_usec = 999375}
        t_id = 3
#8  io_loop_handle_timeouts (ioloop=ioloop at entry=0x8138678) at ioloop.c:581
        _data_stack_cur_id = 2
#9  0xb7678dd2 in io_loop_handler_run_internal (ioloop=ioloop at
entry=0x8138678)
at ioloop-epoll.c:196
        ctx = 0x8144e98
        events = 0x0
        event = 0x8138678
        list = <optimized out>
        io = <optimized out>
        tv = {tv_sec = 0, tv_usec = 0}
        events_count = 15
        msecs = 0
        ret = 0
        i = <optimized out>
        j = <optimized out>
        call = <optimized out>
        __FUNCTION__ = "io_loop_handler_run_internal"
#10 0xb7677496 in io_loop_handler_run (ioloop=ioloop at entry=0x8138678) at 
ioloop.c:649
No locals.
---Type <return> to continue, or q <return> to quit---
#11 0xb7677658 in io_loop_run (ioloop=0x8138678) at ioloop.c:624
        __FUNCTION__ = "io_loop_run"
#12 0xb75f045e in master_service_run (service=0x81385a8, 
callback=callback at entry=0x804d360 <client_connected>) at
master-service.c:719
No locals.
#13 0x0804cf5e in main (argc=1, argv=0x8138300) at main.c:366
        set_roots = {0x805f680, 0x0}
        test_port = 0
        error = <optimized out>
        debug = false
        c = <optimized out>
(gdb) quit
A debugging session is active.

        Inferior 1 [process 31635] will be detached.

Quit anyway? (y or n) y
> Preferably install dovecot-dbg package also so the gdb backtrace output
will
> be better.
Well, I've compiled dovecot from the source, so I don't have a package.
I'll
try your patch on a server or two, and see if it solve the issues for them.

-- 
Simone Lazzaris
Qcom SpA

Timo Sirainen

2018-Sep-10 07:58 UTC

head link

Auth process sometimes stop responding after upgrade

On 8 Sep 2018, at 15.18, Simone Lazzaris <simone.lazzaris at qcom.it>
wrote:> 
> Timo, unfortunately the patch doesn't compile;  I've moved the
declaration of
> "conn" one line up to make it work. 
Oops, I guess I was too much in a hurry to even compile it. Here's a new
patch that compiles and passes our director CI tests.



-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<https://dovecot.org/pipermail/dovecot/attachments/20180910/95f2210e/attachment.html>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: diff
Type: application/octet-stream
Size: 1835 bytes
Desc: not available
URL:
<https://dovecot.org/pipermail/dovecot/attachments/20180910/95f2210e/attachment.obj>
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<https://dovecot.org/pipermail/dovecot/attachments/20180910/95f2210e/attachment-0001.html>

Simone Lazzaris

2018-Sep-10 08:29 UTC

head link

Auth process sometimes stop responding after upgrade

In data luned? 10 settembre 2018 09:58:50 CEST, Timo Sirainen ha
scritto:> On 8 Sep 2018, at 15.18, Simone Lazzaris <simone.lazzaris at qcom.it>
wrote:
> > Timo, unfortunately the patch doesn't compile;  I've moved the
declaration
> > of "conn" one line up to make it work.
> 
> Oops, I guess I was too much in a hurry to even compile it. Here's a
new
> patch that compiles and passes our director CI tests.

This one is better :) I've compiled and installed the patched version on one
VM and it's working. In the next hours, if everything is ok, I'll
percolate
the change on the whole cluster. Let's see if the issue appears again.

The other cluster have been downgraded (saturday night) to 2.2.30.2 and it's
working fine: I couldn't afford to have issues on that one.

-- 
*Simone Lazzaris*
*Qcom S.p.A.*

Simone Lazzaris

2018-Sep-11 07:57 UTC

head link

Auth process sometimes stop responding after upgrade

In data luned? 10 settembre 2018 09:58:50 CEST, Timo Sirainen ha
scritto:> On 8 Sep 2018, at 15.18, Simone Lazzaris <simone.lazzaris at qcom.it>
wrote:
> > Timo, unfortunately the patch doesn't compile;  I've moved the
declaration
> > of "conn" one line up to make it work.
> 
> Oops, I guess I was too much in a hurry to even compile it. Here's a
new
> patch that compiles and passes our director CI tests.
Hi Timo;
after 24 hours of field testing, I can say that the issue is mostly gone. I say
"mostly"
because the service is working as far as the user is concerned, but I see some
strange
going on in the logs.

Grepping "director" in the log file, I can see that there are some
panic and some
comunication errors:

Sep 11 03:24:55 imap-front4 dovecot: director: doveadm: Host 192.168.1.143 vhost
count
changed from 100 to 0
Sep 11 03:24:55 imap-front4 dovecot: director: doveadm: Host 192.168.1.219 vhost
count
changed from 100 to 0
Sep 11 03:24:55 imap-front4 dovecot: director: doveadm: Host 192.168.1.218 vhost
count
changed from 100 to 0
Sep 11 03:24:55 imap-front4 dovecot: director: doveadm: Host 192.168.1.216 vhost
count
changed from 100 to 0
Sep 11 03:24:55 imap-front4 dovecot: director:
director(212.183.164.161:9090/right): Host
192.168.1.145 vhost count changed from 100 to 0
Sep 11 03:24:55 imap-front4 dovecot: director: doveadm: Host 192.168.1.217 vhost
count
changed from 100 to 0
Sep 11 03:24:55 imap-front4 dovecot: director: doveadm: Host 192.168.1.144 vhost
count
changed from 100 to 0
Sep 11 03:24:55 imap-front4 dovecot: director: doveadm: Host 192.168.1.145 vhost
count
changed from 0 to 0
Sep 11 03:24:55 imap-front4 dovecot: director: doveadm: Host 192.168.1.142 vhost
count
changed from 100 to 0
Sep 11 03:25:09 imap-front4 dovecot: director:
director(212.183.164.161:9090/right): Host
192.168.1.143 vhost count changed from 0 to 100
Sep 11 03:25:09 imap-front4 dovecot: director: Error: Director
212.183.164.161:9090/right
disconnected: Connection closed (bytes in=1116368, bytes out=1182555, 0+27319
USERs
received, last input 0.000 s ago, last output 0.000 s ago, connected 4602.589 s
ago, 481
peak output buffer size, 1.948 CPU secs since connected)
Sep 11 03:25:09 imap-front4 dovecot: director: Connecting to
212.183.164.161:9090 (as
212.183.164.164): Reconnecting after disconnection
Sep 11 03:25:09 imap-front4 dovecot: director: Error: Director
212.183.164.161:9090/out
disconnected: Connection closed: read(size=968) failed: Connection reset by peer
(bytes
in=56, bytes out=59143, 0+0 USERs received, 1556 USERs sent in handshake, last
input
0.002 s ago, last output 0.002 s ago, connected 0.024 s ago, 8190 peak output
buffer size,
0.004 CPU secs since connected, handshake DONE not received)
Sep 11 03:25:09 imap-front4 dovecot: director: Connecting to
212.183.164.162:9090 (as
212.183.164.164): Reconnecting after disconnection
Sep 11 03:25:09 imap-front4 dovecot: director:
director(212.183.164.162:9090/out):
Handshake finished in 0.006 secs (bytes in=61, bytes out=59173, 0+0 USERs
received, 1556
USERs sent in handshake, last input 0.000 s ago, last output 0.003 s ago,
connected 0.006 s
ago, 8190 peak output buffer size, 0.000 CPU secs since connected)
Sep 11 03:25:10 imap-front4 dovecot: director: Connecting to
212.183.164.161:9090 (as
212.183.164.164): Received CONNECT request from 212.183.164.162:9090/right -
replacing
current right 212.183.164.162:9090/right
Sep 11 03:25:10 imap-front4 dovecot: director:
director(212.183.164.161:9090/out):
Handshake finished in 0.004 secs (bytes in=61, bytes out=59332, 0+0 USERs
received, 1561
USERs sent in handshake, last input 0.000 s ago, last output 0.004 s ago,
connected 0.004 s
ago, 8190 peak output buffer size, 0.000 CPU secs since connected)
Sep 11 03:25:10 imap-front4 dovecot: director:
director(212.183.164.161:9090/right): Host
192.168.1.216 vhost count changed from 0 to 100
Sep 11 03:25:10 imap-front4 dovecot: director: Error: Director
212.183.164.161:9090/right
disconnected: Connection closed: read(size=558) failed: Connection reset by peer
(bytes
in=466, bytes out=60271, 0+6 USERs received, 1561 USERs sent in handshake, last
input
0.001 s ago, last output 0.000 s ago, connected 0.553 s ago, 8190 peak output
buffer size,
0.000 CPU secs since connected)
Sep 11 03:25:10 imap-front4 dovecot: director: Connecting to
212.183.164.162:9090 (as
212.183.164.164): Reconnecting after disconnection
Sep 11 03:25:10 imap-front4 dovecot: director:
director(212.183.164.162:9090/out):
Handshake finished in 0.005 secs (bytes in=61, bytes out=59372, 0+0 USERs
received, 1562
USERs sent in handshake, last input 0.000 s ago, last output 0.005 s ago,
connected 0.005 s
ago, 8192 peak output buffer size, 0.000 CPU secs since connected)
Sep 11 03:25:10 imap-front4 dovecot: director: Connecting to
212.183.164.161:9090 (as
212.183.164.164): Received CONNECT request from 212.183.164.162:9090/right -
replacing
current right 212.183.164.162:9090/right
Sep 11 03:25:10 imap-front4 dovecot: director:
director(212.183.164.161:9090/out):
Handshake finished in 0.007 secs (bytes in=61, bytes out=59372, 0+0 USERs
received, 1562
USERs sent in handshake, last input 0.000 s ago, last output 0.003 s ago,
connected 0.007 s
ago, 8516 peak output buffer size, 0.004 CPU secs since connected)
Sep 11 03:25:25 imap-front4 dovecot: director: doveadm: Host 192.168.1.144 vhost
count
changed from 0 to 100
Sep 11 03:25:25 imap-front4 dovecot: director: Panic: file doveadm-connection.c:
line 1097
(doveadm_connection_deinit): assertion failed: (conn->to_ring_sync_abort ==
NULL)
Sep 11 03:25:25 imap-front4 dovecot: director: Fatal: master: service(director):
child 2237
killed with signal 6 (core dumps disabled)
Sep 11 03:25:25 imap-front4 dovecot: director: Connecting to
212.183.164.161:9090 (as
212.183.164.164): Initial connection
Sep 11 03:25:25 imap-front4 dovecot: director: Incoming connection from director
212.183.164.163/in
Sep 11 03:25:25 imap-front4 dovecot: director: Panic: file doveadm-connection.c:
line 1097
(doveadm_connection_deinit): assertion failed: (conn->to_ring_sync_abort ==
NULL)
Sep 11 03:25:25 imap-front4 dovecot: director: Fatal: master: service(director):
child 4392
killed with signal 6 (core dumps disabled)
Sep 11 03:25:25 imap-front4 dovecot: director: Connecting to
212.183.164.161:9090 (as
212.183.164.164): Initial connection
Sep 11 03:25:25 imap-front4 dovecot: director: Incoming connection from director
212.183.164.163/in
Sep 11 03:25:25 imap-front4 dovecot: director: Panic: file doveadm-connection.c:
line 1097
(doveadm_connection_deinit): assertion failed: (conn->to_ring_sync_abort ==
NULL)
Sep 11 03:25:25 imap-front4 dovecot: director: Fatal: master: service(director):
child 4393
killed with signal 6 (core dumps disabled)
Sep 11 03:25:25 imap-front4 dovecot: director: Connecting to
212.183.164.161:9090 (as
212.183.164.164): Initial connection
Sep 11 03:25:25 imap-front4 dovecot: director: Incoming connection from director
212.183.164.163/in
Sep 11 03:25:25 imap-front4 dovecot: director: Panic: file doveadm-connection.c:
line 1097
(doveadm_connection_deinit): assertion failed: (conn->to_ring_sync_abort ==
NULL)
Sep 11 03:25:25 imap-front4 dovecot: director: Fatal: master: service(director):
child 4394
killed with signal 6 (core dumps disabled)
Sep 11 03:25:25 imap-front4 dovecot: director: Connecting to
212.183.164.161:9090 (as
212.183.164.164): Initial connection
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<https://dovecot.org/pipermail/dovecot/attachments/20180911/46b1e980/attachment-0001.html>

Possibly Parallel Threads

Search for more maybe matching threads

dovecot - Sep 2018 - Auth process sometimes stop responding after upgrade

Auth process sometimes stop responding after upgrade

Auth process sometimes stop responding after upgrade

Auth process sometimes stop responding after upgrade

Auth process sometimes stop responding after upgrade

Auth process sometimes stop responding after upgrade

Auth process sometimes stop responding after upgrade

Auth process sometimes stop responding after upgrade

Possibly Parallel Threads