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@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: 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

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: director(212.183.164.161:9090/out): Handshake finished in 0.000 secs (bytes in=61, bytes out=383, 0+0 USERs received, last input 0.000 s ago, last output 0.000 s ago, connected 0.000 s ago, 207 peak output buffer size, 0.000 CPU secs since connected)

Sep 11 03:25:25 imap-front4 dovecot: director: director(212.183.164.163/in): Host 192.168.1.142 vhost count changed from 100 to 0

Sep 11 03:25:25 imap-front4 dovecot: director: director(212.183.164.163/in): Host 192.168.1.143 vhost count changed from 100 to 100

Sep 11 03:25:25 imap-front4 dovecot: director: director(212.183.164.163/in): Host 192.168.1.144 vhost count changed from 100 to 100

Sep 11 03:25:25 imap-front4 dovecot: director: director(212.183.164.163/in): Host 192.168.1.145 vhost count changed from 100 to 0

Sep 11 03:25:25 imap-front4 dovecot: director: director(212.183.164.163/in): Host 192.168.1.216 vhost count changed from 100 to 100

Sep 11 03:25:25 imap-front4 dovecot: director: director(212.183.164.163/in): Host 192.168.1.217 vhost count changed from 100 to 0

Sep 11 03:25:25 imap-front4 dovecot: director: director(212.183.164.163/in): Host 192.168.1.218 vhost count changed from 100 to 0

Sep 11 03:25:25 imap-front4 dovecot: director: director(212.183.164.163/in): Host 192.168.1.219 vhost count changed from 100 to 0

Sep 11 03:25:25 imap-front4 dovecot: director: director(212.183.164.163/in): Handshake finished in 0.004 secs (bytes in=59526, bytes out=56, 1566+0 USERs received, last input 0.000 s ago, last output 0.004 s ago, connected 0.004 s ago, 0 peak output buffer size, 0.000 CPU secs since connected)

Sep 11 03:25:25 imap-front4 dovecot: director: director(212.183.164.163:9090/left): Host 192.168.1.142 vhost count changed from 0 to 100

Sep 11 03:25:25 imap-front4 dovecot: director: Error: Director 212.183.164.163:9090/left disconnected: Connection closed: read(size=842) failed: Connection reset by peer (bytes in=60270, bytes out=269, 1566+1 USERs received, last input 0.000 s ago, last output 0.000 s ago, connected 0.165 s ago, 41 peak output buffer size, 0.000 CPU secs since connected)

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: Error: Director 212.183.164.163/in disconnected: Connection closed: read(size=1024) failed: Connection reset by peer (bytes in=0, bytes out=56, 0+0 USERs received, last output 0.003 s ago, connected 0.003 s ago, 0 peak output buffer size, 0.000 CPU secs since connected, handshake ME not received)

Sep 11 03:25:25 imap-front4 dovecot: director: Incoming connection from director 212.183.164.162/in

Sep 11 03:25:25 imap-front4 dovecot: director: director(212.183.164.162/in): Handshake finished in 0.002 secs (bytes in=59528, bytes out=56, 1566+0 USERs received, last input 0.000 s ago, last output 0.002 s ago, connected 0.002 s ago, 0 peak output buffer size, 0.000 CPU secs since connected)

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: Error: Director 212.183.164.163/in disconnected: Connection closed: read(size=848) failed: Connection reset by peer (bytes in=176, bytes out=56, 0+0 USERs received, last input 0.000 s ago, last output 0.001 s ago, connected 0.001 s ago, 0 peak output buffer size, 0.000 CPU secs since connected, handshake DONE not received)

Sep 11 03:25:25 imap-front4 dovecot: director: Warning: Director 212.183.164.162:9090/left disconnected us with reason: CONNECT requested

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: director(212.183.164.163/in): Handshake finished in 0.000 secs (bytes in=383, bytes out=56, 0+0 USERs received, last input 0.000 s ago, last output 0.000 s ago, connected 0.000 s ago, 0 peak output buffer size, 0.000 CPU secs since connected)

Sep 11 03:25:40 imap-front4 dovecot: director: director(212.183.164.161:9090/right): Host 192.168.1.145 vhost count changed from 0 to 100

Sep 11 03:25:40 imap-front4 dovecot: director: Error: Director 212.183.164.161:9090/right disconnected: Connection closed: read(size=506) failed: Connection reset by peer (bytes in=4572, bytes out=6048, 0+103 USERs received, last input 0.000 s ago, last output 0.000 s ago, connected 15.458 s ago, 471 peak output buffer size, 0.008 CPU secs since connected)

Sep 11 03:25:40 imap-front4 dovecot: director: Connecting to 212.183.164.162:9090 (as 212.183.164.164): Reconnecting after disconnection

Sep 11 03:25:40 imap-front4 dovecot: director: director(212.183.164.162:9090/out): Handshake finished in 0.004 secs (bytes in=61, bytes out=59681, 0+0 USERs received, 1570 USERs sent in handshake, last input 0.000 s ago, last output 0.003 s ago, connected 0.004 s ago, 8191 peak output buffer size, 0.000 CPU secs since connected)

Sep 11 03:25:40 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:40 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=59681, 0+0 USERs received, 1570 USERs sent in handshake, last input 0.014 s ago, last output 0.014 s ago, connected 0.014 s ago, 8191 peak output buffer size, 0.004 CPU secs since connected, handshake DONE not received)

Sep 11 03:25:40 imap-front4 dovecot: director: Connecting to 212.183.164.162:9090 (as 212.183.164.164): Reconnecting after disconnection

Sep 11 03:25:40 imap-front4 dovecot: director: director(212.183.164.162:9090/out): Handshake finished in 0.003 secs (bytes in=61, bytes out=59681, 0+0 USERs received, 1570 USERs sent in handshake, last input 0.000 s ago, last output 0.003 s ago, connected 0.003 s ago, 8191 peak output buffer size, 0.000 CPU secs since connected)

Sep 11 03:25:40 imap-front4 dovecot: director: director(212.183.164.161:9090/out): Handshake finished in 0.009 secs (bytes in=61, bytes out=59681, 0+0 USERs received, 1570 USERs sent in handshake, last input 0.000 s ago, last output 0.009 s ago, connected 0.009 s ago, 8191 peak output buffer size, 0.004 CPU secs since connected)

Sep 11 03:25:55 imap-front4 dovecot: director: doveadm: Host 192.168.1.217 vhost count changed from 0 to 100

Sep 11 03:25:55 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:55 imap-front4 dovecot: director: Fatal: master: service(director): child 4395 killed with signal 6 (core dumps disabled)

Sep 11 03:25:55 imap-front4 dovecot: director: Connecting to 212.183.164.161:9090 (as 212.183.164.164): Initial connection

Sep 11 03:25:55 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:55 imap-front4 dovecot: director: Fatal: master: service(director): child 4404 killed with signal 6 (core dumps disabled)

Sep 11 03:25:55 imap-front4 dovecot: director: Connecting to 212.183.164.161:9090 (as 212.183.164.164): Initial connection

Sep 11 03:25:55 imap-front4 dovecot: director: director(212.183.164.161:9090/out): Handshake finished in 0.000 secs (bytes in=61, bytes out=383, 0+0 USERs received, last input 0.000 s ago, last output 0.000 s ago, connected 0.000 s ago, 207 peak output buffer size, 0.000 CPU secs since connected)

Sep 11 03:25:55 imap-front4 dovecot: director: Incoming connection from director 212.183.164.163/in

Sep 11 03:25:55 imap-front4 dovecot: director: director(212.183.164.163/in): Host 192.168.1.142 vhost count changed from 100 to 100

Sep 11 03:25:55 imap-front4 dovecot: director: director(212.183.164.163/in): Host 192.168.1.143 vhost count changed from 100 to 100

Sep 11 03:25:55 imap-front4 dovecot: director: director(212.183.164.163/in): Host 192.168.1.144 vhost count changed from 100 to 100

Sep 11 03:25:55 imap-front4 dovecot: director: director(212.183.164.163/in): Host 192.168.1.145 vhost count changed from 100 to 100

Sep 11 03:25:55 imap-front4 dovecot: director: director(212.183.164.163/in): Host 192.168.1.216 vhost count changed from 100 to 100

Sep 11 03:25:55 imap-front4 dovecot: director: director(212.183.164.163/in): Host 192.168.1.217 vhost count changed from 100 to 100

Sep 11 03:25:55 imap-front4 dovecot: director: director(212.183.164.163/in): Host 192.168.1.218 vhost count changed from 100 to 0

Sep 11 03:25:55 imap-front4 dovecot: director: director(212.183.164.163/in): Host 192.168.1.219 vhost count changed from 100 to 0

Sep 11 03:25:55 imap-front4 dovecot: director: director(212.183.164.163/in): Handshake finished in 0.005 secs (bytes in=59684, bytes out=56, 1570+0 USERs received, last input 0.000 s ago, last output 0.005 s ago, connected 0.005 s ago, 0 peak output buffer size, 0.004 CPU secs since connected)

Sep 11 03:25:55 imap-front4 dovecot: director: director(212.183.164.163:9090/left): Host 192.168.1.218 vhost count changed from 0 to 100

Sep 11 03:25:55 imap-front4 dovecot: director: Error: Director 212.183.164.163:9090/left disconnected: Connection closed: read(size=751) failed: Connection reset by peer (bytes in=60317, bytes out=207, 1570+2 USERs received, last input 0.001 s ago, last output 0.001 s ago, connected 0.191 s ago, 37 peak output buffer size, 0.004 CPU secs since connected)

Sep 11 03:25:55 imap-front4 dovecot: director: Incoming connection from director 212.183.164.162/in

Sep 11 03:25:55 imap-front4 dovecot: director: director(212.183.164.162/in): Handshake finished in 0.003 secs (bytes in=59686, bytes out=56, 1570+0 USERs received, last input 0.000 s ago, last output 0.003 s ago, connected 0.003 s ago, 0 peak output buffer size, 0.000 CPU secs since connected)

Sep 11 03:25:55 imap-front4 dovecot: director: Incoming connection from director 212.183.164.163/in

Sep 11 03:25:55 imap-front4 dovecot: director: Error: Director 212.183.164.163/in disconnected: Connection closed: read(size=1024) failed: Connection reset by peer (bytes in=0, bytes out=56, 0+0 USERs received, last output 0.001 s ago, connected 0.001 s ago, 0 peak output buffer size, 0.000 CPU secs since connected, handshake ME not received)

Sep 11 03:25:56 imap-front4 dovecot: director: Incoming connection from director 212.183.164.163/in

Sep 11 03:25:56 imap-front4 dovecot: director: director(212.183.164.163/in): Handshake finished in 0.000 secs (bytes in=383, bytes out=56, 0+0 USERs received, last input 0.000 s ago, last output 0.000 s ago, connected 0.000 s ago, 0 peak output buffer size, 0.000 CPU secs since connected)

Sep 11 03:25:56 imap-front4 dovecot: director: Warning: Director 212.183.164.162:9090/left disconnected us with reason: CONNECT requested

Sep 11 03:26:10 imap-front4 dovecot: director: director(212.183.164.161:9090/right): Host 192.168.1.219 vhost count changed from 0 to 100

Sep 11 03:26:10 imap-front4 dovecot: director: Error: Director 212.183.164.161:9090/right disconnected: Connection closed: read(size=955) failed: Connection reset by peer (bytes in=6172, bytes out=6095, 0+140 USERs received, last input 0.001 s ago, last output 0.000 s ago, connected 15.493 s ago, 477 peak output buffer size, 0.016 CPU secs since connected)

Sep 11 03:26:10 imap-front4 dovecot: director: Connecting to 212.183.164.162:9090 (as 212.183.164.164): Reconnecting after disconnection

Sep 11 03:26:10 imap-front4 dovecot: director: director(212.183.164.162:9090/out): Handshake finished in 0.003 secs (bytes in=61, bytes out=59686, 0+0 USERs received, 1570 USERs sent in handshake, last input 0.000 s ago, last output 0.002 s ago, connected 0.003 s ago, 8192 peak output buffer size, 0.000 CPU secs since connected)

Sep 11 03:26: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:26:10 imap-front4 dovecot: director: director(212.183.164.161:9090/out): Handshake finished in 0.006 secs (bytes in=102, bytes out=59686, 0+1 USERs received, 1570 USERs sent in handshake, last input 0.000 s ago, last output 0.005 s ago, connected 0.006 s ago, 8192 peak output buffer size, 0.000 CPU secs since connected)

Incidents like the above one occurs every few hours.

Please note that in the previous version I've used on the very same machine (2.1.10) I only had some thing like this, and about once a day:

Aug 31 10:01:08 imap-front4 dovecot: director: Warning: Delaying new user requests until ring is synced

Aug 31 10:01:09 imap-front4 dovecot: director: Error: director(212.183.164.161:9090/right): Output buffer full, disconnecting

Aug 31 10:01:11 imap-front4 dovecot: director: Warning: Ring is synced, continuing delayed requests