[Dovecot] backtrace from postgres dict
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1
Hi,
since I enabled ACLs I get following backtrace. It looks like that it happens if the ACLs had been changed only. Also, it looks like that it always happens 1 minute after last "dict: Info: pgsql(localhost): Connected to database dovecot", no matter if the user is logged in (and idle) or logged off. Postgres logs: "could not receive data from client: Connection reset by peer" and "unexpected EOF on client connection".
Is there some TCP keep alive issue? Postgres is using the "system default" for TCP keep alive. I'm currently testing ACLs via telnet, so the activity with the ACL dict is pretty low, hence, an idle timeout would make much sense.
# ../../sbin/dovecot --version 2.1.10 (a4f02f6c0d32)
dict connect string: connect = host=localhost dbname=db user=user
2012-11-28 10:03:39 dict: Info: pgsql(localhost): Connected to database dovecot 2012-11-28 10:03:39 dict: Info: pgsql(localhost): Connected to database dovecot 2012-11-28 10:03:39 dict: Info: pgsql(localhost): Connected to database dovecot
2012-11-28 10:03:58 IMAP(user) [22922]: Info: Disconnected: Logged out in=23 out=763
2012-11-28 10:04:41 dict: Panic: file driver-pgsql.c: line 84 (driver_pgsql_set_state): assertion failed: (state == SQL_DB_STATE_BUSY || db->cur_result == NULL)
2012-11-28 10:04:41 dict: Error: Raw backtrace: /usr/local/dovecot-2.1.10/lib/dovecot/libdovecot.so.0(+0x4857a) [0x7f91f511157a] -> /usr/local/dovecot-2.1.10/lib/dovecot/libdovecot.so.0(+0x485c6) [0x7f91f51115c6] -> /usr/local/dovecot-2.1.10/lib/dovecot/libdovecot.so.0(i_error+0) [0x7f91f50e4eaf] -> dovecot2.1/dict() [0x40aa36] -> dovecot2.1/dict() [0x40aa91] -> dovecot2.1/dict() [0x40bed3] -> dovecot2.1/dict() [0x409504]
- -> dovecot2.1/dict(sql_db_cache_deinit+0x20) [0x408a60] -> dovecot2.1/dict(main+0x169) [0x405a59] -> /lib/libc.so.6(__libc_start_main+0xfd) [0x7f91f4b5cc8d] -> dovecot2.1/dict() [0x404bb9]
2012-11-28 10:04:41 dict: Fatal: master: service(dict): child 22923 killed with signal 6 (core not dumped)
Steffen Kaiser -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.11 (GNU/Linux)
iQEVAwUBULXbiGoxLS8a3A9mAQI9Ywf/YItPO4fFT70HcuwCkDXgx0Sn7CEyXu2j +1VzOu3R/TMs1rcxYJIvWiei6Nk3wXywzQl84POadJn61Yf2NuT80nMxwBsBbgio e+0oRE9JNVSjtvX5l7kehEdUDQjqRRKyrhWG9KDlpjWidGsYh7pQg0rDtp3UwG57 HuSBMiBAZ9t9sC2DXjn9wT9vweH3gMIhc/K5U0BLF5JG/K8UAKc5QBUgezjIYzvn KP90TJ4RoZ2vnPzmWfeIsjffRBvvC6UUgWmU02e2H9xJxzF32Nix0s8YWi7G91sH Ei057HW5NsKNDtp6B5fYk+xCpC6ucQiwFSr/ZG+uZCAdtTd2qmf60g== =tQYK -----END PGP SIGNATURE-----
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1
On Wed, 28 Nov 2012, Steffen Kaiser wrote:
hmm, it seems to be more than just an idle timeout.
since I enabled ACLs I get following backtrace. It looks like that it happens if the ACLs had been changed only. Also, it looks like that it always happens 1 minute after last "dict: Info: pgsql(localhost): Connected to database dovecot", no matter if the user is logged in (and idle) or logged off. Postgres logs: "could not receive data from client: Connection reset by peer" and "unexpected EOF on client connection".
Is there some TCP keep alive issue? Postgres is using the "system default" for TCP keep alive. I'm currently testing ACLs via telnet, so the activity with the ACL dict is pretty low, hence, an idle timeout would make much sense.
When I use this script:
( echo 1 login user pass sleep 1 echo 2 getacl Junk sleep 1 for a in $(seq 1 ${1-4}); do echo 3-$a deleteAcl Junk user2 sleep 30 echo 3-$a SetAcl Junk user2 kxilrsc sleep 30 done echo + logout ) | nc -q1 localhost 143
I get (attached are more lines of the log):
2012-11-28 11:08:07 dict: Info: pgsql(localhost): Connected to database dovecot scanning for dovecot-acl 2012-11-28 11:09:07 dict: Info: pgsql(localhost): Connected to database dovecot scanning for dovecot-acl 2012-11-28 11:09:37 dict: Info: pgsql(localhost): Connected to database dovecot scanning for dovecot-acl 2012-11-28 11:10:07 dict: Error: dict sql iterate failed: Not connected to database 2012-11-28 11:10:07 IMAP(user) [23358]: Error: acl: dict iteration failed, can't update dict scanning for dovecot-acl
After that the connection is broken and I get the backtrace eventually.
# ../../sbin/dovecot --version 2.1.10 (a4f02f6c0d32)
dict connect string: connect = host=localhost dbname=db user=user
Steffen Kaiser -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.11 (GNU/Linux)
iQEVAwUBULXqy2oxLS8a3A9mAQL4+Af+PQIzpT0/kbot90jYRYmRBA96frDlDubc lsl9iktKGYyxLOQXRLLcUpOgzWqUvxoLtsCMlkcOG8tjyQLr2OsAufnVUL7LUH8y iGIi8lZjfHRUQWWLgC6KG0eNOMT5PEGLB5dBcqMZxsgENjoe0SEYf3SN2bT7UxR7 N6/cbU+qnQ/IVpCCcFTtY1Nv7pHcpBwt7IQqaLTdFJ2OQBtUCFsZlkH2SArBZktC 82rHKvHkN4rsYiOhKQFyG3p7mmdmq3snUpP9fvUE+2nxsIQw2BIht8gGPMsuVoTb DC1JjE6JGuj4z3HrEs2tYRHgnTUuUn2j28bXIp2gNDLUQzbL5DLfLQ== =XUQP -----END PGP SIGNATURE-----
-----BEGIN PGP SIGNED MESSAGE----- Hash: SHA1
On Wed, 28 Nov 2012, Steffen Kaiser wrote:
with Dovecot v2.1.12 I do no get those panics anymore.
2012-11-28 10:04:41 dict: Panic: file driver-pgsql.c: line 84 (driver_pgsql_set_state): assertion failed: (state == SQL_DB_STATE_BUSY || db->cur_result == NULL)
2012-11-28 10:04:41 dict: Error: Raw backtrace: /usr/local/dovecot-2.1.10/lib/dovecot/libdovecot.so.0(+0x4857a) [0x7f91f511157a] -> /usr/local/dovecot-2.1.10/lib/dovecot/libdovecot.so.0(+0x485c6) [0x7f91f51115c6] -> /usr/local/dovecot-2.1.10/lib/dovecot/libdovecot.so.0(i_error+0) [0x7f91f50e4eaf] -> dovecot2.1/dict() [0x40aa36] -> dovecot2.1/dict() [0x40aa91] -> dovecot2.1/dict() [0x40bed3] -> dovecot2.1/dict() [0x409504] - -> dovecot2.1/dict(sql_db_cache_deinit+0x20) [0x408a60] -> dovecot2.1/dict(main+0x169) [0x405a59] -> /lib/libc.so.6(__libc_start_main+0xfd) [0x7f91f4b5cc8d] -> dovecot2.1/dict() [0x404bb9]
2012-11-28 10:04:41 dict: Fatal: master: service(dict): child 22923 killed with signal 6 (core not dumped)
Steffen Kaiser -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.11 (GNU/Linux)
iQEVAwUBUNM9LGoxLS8a3A9mAQJaoQgAu5LfaqmVcdFWMF0Z+DrQvLz1xlSIP35+ cJxI7gYKh21LzpSB2iJ2DjccRUJDZRupqpIwSDLuiFYp7ORktrrO6ohieXrDM7z1 VcFO1kU2vbTYIbOloN724pSy1oFxTsec5TTi5zlL9WFjSTW2pP9oFbcSan+43ADo gUSwm69F57GIZvOGyMSb1o83JCXRI83IajtgFtcIBuTqn6TC+zMolC2rC35ElZdM EqkXMnGBKLNjxdp+hsro2i59bahzlIO4eigrRNFDTbiM8fInFen9BK40OnXkF2Ni n7kh9Zx+8EDE2ayWFKaPz0hXZbbQSXcWdkfHjc/TBV9DPk2YY7BTSw== =V/8J -----END PGP SIGNATURE-----
participants (1)
-
Steffen Kaiser