Crash when using dict quotas with sqlite database
Hello,
After I configured a SQLite backed dict quota backend, the dict process crashes every time a quota operation is happening.
SQLite: 3.26.0
Dovecot: 2.3.4 (0ecbaf23d)
Linux: 4.20.4.a-1-hardened #1 SMP PREEMPT Fri Jan 25 01:24:51 CET 2019 x86_64 GNU/Linux (Arch Linux)
Filesystem: BTRFS
I can't get any debug output from Dovecot, even after setting log_debug = cat:* event:* source:* field:*=*
dovecot[6457]: dict(6687): Debug: sqlite: Finished query 'BEGIN TRANSACTION' in 0 msecs dovecot[6457]: dict(6687): Fatal: master: service(dict): child 6687 killed with signal 11 (core dumped)
I've attached the output of dovecot -n and the coredump file from systemd-coredump.
Kind regards,
Marcel Menzel
On 01/02/2019 20:40, Marcel Menzel wrote:
Hello,
After I configured a SQLite backed dict quota backend, the dict process crashes every time a quota operation is happening.
SQLite: 3.26.0
Dovecot: 2.3.4 (0ecbaf23d)
Linux: 4.20.4.a-1-hardened #1 SMP PREEMPT Fri Jan 25 01:24:51 CET 2019 x86_64 GNU/Linux (Arch Linux)
Filesystem: BTRFS
I can't get any debug output from Dovecot, even after setting log_debug = cat:* event:* source:* field:*=*
dovecot[6457]: dict(6687): Debug: sqlite: Finished query 'BEGIN TRANSACTION' in 0 msecs dovecot[6457]: dict(6687): Fatal: master: service(dict): child 6687 killed with signal 11 (core dumped)
I've attached the output of dovecot -n and the coredump file from systemd-coredump.
Kind regards,
Marcel Menzel
Any chance of posting a backtrace?
John
Hello John,
I tried (until now) to get a valuable backtrace, but it seems that GDB can't resolve all symbols. This is what systemd-coredump is giving me:
Stack trace of thread 22359: #0 0x0000638167eaf062 event_unref (libdovecot.so.0) #1 0x000004a58a212151 n/a (dict) #2 0x000004a58a211333 n/a (dict) #3 0x000004a58a20514d n/a (dict) #4 0x0000638167e556f2 dict_transaction_begin (libdovecot.so.0) #5 0x000004a58a203b06 n/a (dict) #6 0x000004a58a2045ff dict_command_input (dict) #7 0x000004a58a202a31 n/a (dict) #8 0x000004a58a202b35 n/a (dict) #9 0x0000638167eaacfd io_loop_call_io (libdovecot.so.0) #10 0x0000638167eac635 io_loop_handler_run_internal (libdovecot.so.0) #11 0x0000638167eaadc7 io_loop_handler_run (libdovecot.so.0) #12 0x0000638167eaaf68 io_loop_run (libdovecot.so.0) #13 0x0000638167e1b36a master_service_run (libdovecot.so.0) #14 0x000004a58a202300 main (dict) #15 0x0000638167a17223 __libc_start_main (libc.so.6) #16 0x000004a58a2023fe _start (dict)
GDB's "bt full" won't give anything more here, I might compile Dovecot with debug symbols enabled as soon as I have a little more time:
(gdb) bt full #0 0x0000638167eaf062 in event_unref () from /usr/lib/dovecot/libdovecot.so.0 No symbol table info available. #1 0x000004a58a212151 in ?? () No symbol table info available. #2 0x000004a58a211333 in ?? () No symbol table info available. #3 0x000004a58a20514d in ?? () No symbol table info available. #4 0x0000638167e556f2 in dict_transaction_begin () from /usr/lib/dovecot/libdovecot.so.0 No symbol table info available. #5 0x000004a58a203b06 in ?? () No symbol table info available. #6 0x000004a58a2045ff in dict_command_input () No symbol table info available. #7 0x000004a58a202a31 in ?? () No symbol table info available. #8 0x000004a58a202b35 in ?? () No symbol table info available. #9 0x0000638167eaacfd in io_loop_call_io () from /usr/lib/dovecot/libdovecot.so.0 No symbol table info available. #10 0x0000638167eac635 in io_loop_handler_run_internal () from /usr/lib/dovecot/libdovecot.so.0 No symbol table info available. #11 0x0000638167eaadc7 in io_loop_handler_run () from /usr/lib/dovecot/libdovecot.so.0 No symbol table info available. #12 0x0000638167eaaf68 in io_loop_run () from /usr/lib/dovecot/libdovecot.so.0 No symbol table info available. #13 0x0000638167e1b36a in master_service_run () from /usr/lib/dovecot/libdovecot.so.0 No symbol table info available. #14 0x000004a58a202300 in main () No symbol table info available.
- Marcel
Am 03.02.2019 um 09:08 schrieb John Fawcett:
On 01/02/2019 20:40, Marcel Menzel wrote:
Hello,
After I configured a SQLite backed dict quota backend, the dict process crashes every time a quota operation is happening.
SQLite: 3.26.0
Dovecot: 2.3.4 (0ecbaf23d)
Linux: 4.20.4.a-1-hardened #1 SMP PREEMPT Fri Jan 25 01:24:51 CET 2019 x86_64 GNU/Linux (Arch Linux)
Filesystem: BTRFS
I can't get any debug output from Dovecot, even after setting log_debug = cat:* event:* source:* field:*=*
dovecot[6457]: dict(6687): Debug: sqlite: Finished query 'BEGIN TRANSACTION' in 0 msecs dovecot[6457]: dict(6687): Fatal: master: service(dict): child 6687 killed with signal 11 (core dumped)
I've attached the output of dovecot -n and the coredump file from systemd-coredump.
Kind regards,
Marcel Menzel
Any chance of posting a backtrace?
John
Hello Aki,
Arch Linux doesn't have install-able debug symbols for Dovecot. That's why I just compiled the package for myself with enabled debug symbols (by editing the makepkg.conf).
I've attached the output from gdb's bt full.
- Marcel
Am 03.02.2019 um 14:45 schrieb Aki Tuomi:
You need to install debug symbols. Not sure how this is done in arch linux though.
Aki
On 03 February 2019 at 15:02 Marcel Menzel < mail@mcl.gg <mailto:mail@mcl.gg>> wrote:
Hello John,
I tried (until now) to get a valuable backtrace, but it seems that GDB can't resolve all symbols. This is what systemd-coredump is giving me:
Stack trace of thread 22359: #0 0x0000638167eaf062 event_unref (libdovecot.so.0) #1 0x000004a58a212151 n/a (dict) #2 0x000004a58a211333 n/a (dict) #3 0x000004a58a20514d n/a (dict) #4 0x0000638167e556f2 dict_transaction_begin (libdovecot.so.0) #5 0x000004a58a203b06 n/a (dict) #6 0x000004a58a2045ff dict_command_input (dict) #7 0x000004a58a202a31 n/a (dict) #8 0x000004a58a202b35 n/a (dict) #9 0x0000638167eaacfd io_loop_call_io (libdovecot.so.0) #10 0x0000638167eac635 io_loop_handler_run_internal (libdovecot.so.0) #11 0x0000638167eaadc7 io_loop_handler_run (libdovecot.so.0) #12 0x0000638167eaaf68 io_loop_run (libdovecot.so.0) #13 0x0000638167e1b36a master_service_run (libdovecot.so.0) #14 0x000004a58a202300 main (dict) #15 0x0000638167a17223 __libc_start_main (libc.so.6) #16 0x000004a58a2023fe _start (dict)
GDB's "bt full" won't give anything more here, I might compile Dovecot with debug symbols enabled as soon as I have a little more time:
(gdb) bt full #0 0x0000638167eaf062 in event_unref () from /usr/lib/dovecot/libdovecot.so.0 No symbol table info available. #1 0x000004a58a212151 in ?? () No symbol table info available. #2 0x000004a58a211333 in ?? () No symbol table info available. #3 0x000004a58a20514d in ?? () No symbol table info available. #4 0x0000638167e556f2 in dict_transaction_begin () from /usr/lib/dovecot/libdovecot.so.0 No symbol table info available. #5 0x000004a58a203b06 in ?? () No symbol table info available. #6 0x000004a58a2045ff in dict_command_input () No symbol table info available. #7 0x000004a58a202a31 in ?? () No symbol table info available. #8 0x000004a58a202b35 in ?? () No symbol table info available. #9 0x0000638167eaacfd in io_loop_call_io () from /usr/lib/dovecot/libdovecot.so.0 No symbol table info available. #10 0x0000638167eac635 in io_loop_handler_run_internal () from /usr/lib/dovecot/libdovecot.so.0 No symbol table info available. #11 0x0000638167eaadc7 in io_loop_handler_run () from /usr/lib/dovecot/libdovecot.so.0 No symbol table info available. #12 0x0000638167eaaf68 in io_loop_run () from /usr/lib/dovecot/libdovecot.so.0 No symbol table info available. #13 0x0000638167e1b36a in master_service_run () from /usr/lib/dovecot/libdovecot.so.0 No symbol table info available. #14 0x000004a58a202300 in main () No symbol table info available.
- Marcel
On 01/02/2019 20:40, Marcel Menzel wrote:
Hello,
After I configured a SQLite backed dict quota backend, the dict
Am 03.02.2019 um 09:08 schrieb John Fawcett: process
crashes every time a quota operation is happening.
SQLite: 3.26.0
Dovecot: 2.3.4 (0ecbaf23d)
Linux: 4.20.4.a-1-hardened #1 SMP PREEMPT Fri Jan 25 01:24:51 CET 2019 x86_64 GNU/Linux (Arch Linux)
Filesystem: BTRFS
I can't get any debug output from Dovecot, even after setting log_debug = cat:* event:* source:* field:*=*
dovecot[6457]: dict(6687): Debug: sqlite: Finished query 'BEGIN TRANSACTION' in 0 msecs dovecot[6457]: dict(6687): Fatal: master: service(dict): child 6687 killed with signal 11 (core dumped)
I've attached the output of dovecot -n and the coredump file from systemd-coredump.
Kind regards,
Marcel Menzel
Any chance of posting a backtrace? John
Aki Tuomi
Hello Aki,
unfortunately, this patch is already in my source files, as patch refuses to apply it:
-> Applying patch fix-sqlite.patch patching file src/lib-sql/driver-sqlite.c Reversed (or previously applied) patch detected! Skipping patch. 2 out of 2 hunks ignored -- saving rejects to file src/lib-sql/driver-sqlite.c.rej
I verified it by looking in the source code and indeed, this patch is already applied.
- Marcel
Am 03.02.2019 um 15:25 schrieb Aki Tuomi:
Can you try if applying
https://github.com/dovecot/core/commit/b291ff1fd61b47639a2db99bd858c9511945f...
helps?
Aki
On 03 February 2019 at 16:20 Marcel Menzel < mail@mcl.gg <mailto:mail@mcl.gg>> wrote:
Hello Aki,
Arch Linux doesn't have install-able debug symbols for Dovecot. That's why I just compiled the package for myself with enabled debug symbols (by editing the makepkg.conf).
I've attached the output from gdb's bt full.
- Marcel
Am 03.02.2019 um 14:45 schrieb Aki Tuomi:
You need to install debug symbols. Not sure how this is done in arch linux though. Aki
On 03 February 2019 at 15:02 Marcel Menzel < mail@mcl.gg <mailto:mail@mcl.gg> <mailto: mail@mcl.gg <mailto:mail@mcl.gg>>> wrote:
Hello John,
I tried (until now) to get a valuable backtrace, but it seems that GDB can't resolve all symbols. This is what systemd-coredump is giving me:
Stack trace of thread 22359: #0 0x0000638167eaf062 event_unref (libdovecot.so.0) #1 0x000004a58a212151 n/a (dict) #2 0x000004a58a211333 n/a (dict) #3 0x000004a58a20514d n/a (dict) #4 0x0000638167e556f2 dict_transaction_begin (libdovecot.so.0) #5 0x000004a58a203b06 n/a (dict) #6 0x000004a58a2045ff dict_command_input (dict) #7 0x000004a58a202a31 n/a (dict) #8 0x000004a58a202b35 n/a (dict) #9 0x0000638167eaacfd io_loop_call_io (libdovecot.so.0) #10 0x0000638167eac635 io_loop_handler_run_internal (libdovecot.so.0) #11 0x0000638167eaadc7 io_loop_handler_run (libdovecot.so.0) #12 0x0000638167eaaf68 io_loop_run (libdovecot.so.0) #13 0x0000638167e1b36a master_service_run (libdovecot.so.0) #14 0x000004a58a202300 main (dict) #15 0x0000638167a17223 __libc_start_main (libc.so.6) #16 0x000004a58a2023fe _start (dict)
GDB's "bt full" won't give anything more here, I might compile Dovecot with debug symbols enabled as soon as I have a little more time:
(gdb) bt full #0 0x0000638167eaf062 in event_unref () from /usr/lib/dovecot/libdovecot.so.0 No symbol table info available. #1 0x000004a58a212151 in ?? () No symbol table info available. #2 0x000004a58a211333 in ?? () No symbol table info available. #3 0x000004a58a20514d in ?? () No symbol table info available. #4 0x0000638167e556f2 in dict_transaction_begin () from /usr/lib/dovecot/libdovecot.so.0 No symbol table info available. #5 0x000004a58a203b06 in ?? () No symbol table info available. #6 0x000004a58a2045ff in dict_command_input () No symbol table info available. #7 0x000004a58a202a31 in ?? () No symbol table info available. #8 0x000004a58a202b35 in ?? () No symbol table info available. #9 0x0000638167eaacfd in io_loop_call_io () from /usr/lib/dovecot/libdovecot.so.0 No symbol table info available. #10 0x0000638167eac635 in io_loop_handler_run_internal () from /usr/lib/dovecot/libdovecot.so.0 No symbol table info available. #11 0x0000638167eaadc7 in io_loop_handler_run () from /usr/lib/dovecot/libdovecot.so.0 No symbol table info available. #12 0x0000638167eaaf68 in io_loop_run () from /usr/lib/dovecot/libdovecot.so.0 No symbol table info available. #13 0x0000638167e1b36a in master_service_run () from /usr/lib/dovecot/libdovecot.so.0 No symbol table info available. #14 0x000004a58a202300 in main () No symbol table info available.
- Marcel
On 01/02/2019 20:40, Marcel Menzel wrote:
Hello,
After I configured a SQLite backed dict quota backend, the dict
Am 03.02.2019 um 09:08 schrieb John Fawcett: process
crashes every time a quota operation is happening.
SQLite: 3.26.0
Dovecot: 2.3.4 (0ecbaf23d)
Linux: 4.20.4.a-1-hardened #1 SMP PREEMPT Fri Jan 25 01:24:51 CET 2019 x86_64 GNU/Linux (Arch Linux)
Filesystem: BTRFS
I can't get any debug output from Dovecot, even after setting log_debug = cat:* event:* source:* field:*=*
dovecot[6457]: dict(6687): Debug: sqlite: Finished query 'BEGIN TRANSACTION' in 0 msecs dovecot[6457]: dict(6687): Fatal: master: service(dict): child 6687 killed with signal 11 (core dumped)
I've attached the output of dovecot -n and the coredump file from systemd-coredump.
Kind regards,
Marcel Menzel
Any chance of posting a backtrace? John
Aki Tuomi
Aki Tuomi
All I did was
- create a sqlite database with: # sqlite3 /tmp/storage.db (/run only to test for perm issues in other folders)
- change it's owner to mail (that's the user owning the mail files): # chown mail:mail /tmp/storage.db
- point dovecot to the file in "dovecot-dict-sql.conf.ext" with "connect = /tmp/storage.db"
- enable quota in "90-quota.conf" with "quota = dict:User quota::proxy::quota" in the plugin section (sample config file taken from sources)
- changing the dict section in dovecot.conf to:
dict { quota = sqlite:/etc/dovecot/dovecot-dict-sql.conf.ext expire = sqlite:/etc/dovecot/dovecot-dict-sql.conf.ext }
After this, a simple "doveadm quota recalc -u mail@mcl.gg" is enough to cause a dict crash.
While tinkering with the config (and making a small mistake where i moved the file and dovecot complaining about
doveadm: Error: dict quota: Quota update failed: dict-server returned failure: sql dict: commit failed: out of memory (reply took 0.041 secs (0.001 in dict wait, 0.000 in other ioloops, 0.001 in locks, async-id reply 0.000 secs ago, started on dict-server 0.041 secs ago, took 0.000 secs)) - Quota is now desynced
And reloading it afterwards, my log got filled with like 200 lines containing
dovecot[6213]: dict(6301): Warning: Event 0x67a90293830 leaked (parent=0x67a9027c890): driver-sqlite.c:173
- Marcel
Am 03.02.2019 um 15:57 schrieb Aki Tuomi:
Can you provide steps on how to reproduce this? Tracked as DOP-899
On 03 February 2019 at 16:50 Aki Tuomi < aki.tuomi@open-xchange.com <mailto:aki.tuomi@open-xchange.com>> wrote:
Right it was already in 2.3.4. Looking more closely this looks like use after free. We'll look into this.
Aki
On 03 February 2019 at 16:44 Marcel Menzel < mail@mcl.gg <mailto:mail@mcl.gg>> wrote:
Hello Aki,
unfortunately, this patch is already in my source files, as patch refuses to apply it:
-> Applying patch fix-sqlite.patch patching file src/lib-sql/driver-sqlite.c Reversed (or previously applied) patch detected! Skipping patch. 2 out of 2 hunks ignored -- saving rejects to file src/lib-sql/driver-sqlite.c.rej
I verified it by looking in the source code and indeed, this patch is already applied.
- Marcel
Am 03.02.2019 um 15:25 schrieb Aki Tuomi:
Can you try if applying
https://github.com/dovecot/core/commit/b291ff1fd61b47639a2db99bd858c9511945f...
helps?
Aki
> On 03 February 2019 at 16:20 Marcel Menzel < mail@mcl.gg <mailto:mail@mcl.gg> <mailto: mail@mcl.gg <mailto:mail@mcl.gg>>> wrote:
> > Hello Aki,
Arch Linux doesn't have install-able debug symbols for Dovecot. That's why I just compiled the package for myself with enabled debug symbols (by editing the makepkg.conf).
I've attached the output from gdb's bt full.
- Marcel
You need to install debug symbols. Not sure how this is done in arch linux though. Aki > On 03 February 2019 at 15:02 Marcel Menzel < mail@mcl.gg <mailto:mail@mcl.gg> > <mailto: mail@mcl.gg <mailto:mail@mcl.gg>> > <mailto: mail@mcl.gg <mailto:mail@mcl.gg> <mailto: mail@mcl.gg <mailto:mail@mcl.gg>>>> wrote: > > Hello John, > > I tried (until now) to get a valuable backtrace, but it seems
Am 03.02.2019 um 14:45 schrieb Aki Tuomi: that GDB
> can't resolve all symbols. > This is what systemd-coredump is giving me: > > Stack trace of thread 22359: > #0 0x0000638167eaf062 event_unref (libdovecot.so.0) > #1 0x000004a58a212151 n/a (dict) > #2 0x000004a58a211333 n/a (dict) > #3 0x000004a58a20514d n/a (dict) > #4 0x0000638167e556f2 dict_transaction_begin (libdovecot.so.0) > #5 0x000004a58a203b06 n/a (dict) > #6 0x000004a58a2045ff dict_command_input (dict) > #7 0x000004a58a202a31 n/a (dict) > #8 0x000004a58a202b35 n/a (dict) > #9 0x0000638167eaacfd io_loop_call_io (libdovecot.so.0) > #10 0x0000638167eac635 io_loop_handler_run_internal (libdovecot.so.0) > #11 0x0000638167eaadc7 io_loop_handler_run (libdovecot.so.0) > #12 0x0000638167eaaf68 io_loop_run (libdovecot.so.0) > #13 0x0000638167e1b36a master_service_run (libdovecot.so.0) > #14 0x000004a58a202300 main (dict) > #15 0x0000638167a17223 __libc_start_main (libc.so.6) > #16 0x000004a58a2023fe _start (dict) > > GDB's "bt full" won't give anything more here, I might compile Dovecot > with debug symbols enabled as soon as I have a little more time: > > (gdb) bt full > #0 0x0000638167eaf062 in event_unref () from > /usr/lib/dovecot/libdovecot.so.0 > No symbol table info available. > #1 0x000004a58a212151 in ?? () > No symbol table info available. > #2 0x000004a58a211333 in ?? () > No symbol table info available. > #3 0x000004a58a20514d in ?? () > No symbol table info available. > #4 0x0000638167e556f2 in dict_transaction_begin () from > /usr/lib/dovecot/libdovecot.so.0 > No symbol table info available. > #5 0x000004a58a203b06 in ?? () > No symbol table info available. > #6 0x000004a58a2045ff in dict_command_input () > No symbol table info available. > #7 0x000004a58a202a31 in ?? () > No symbol table info available. > #8 0x000004a58a202b35 in ?? () > No symbol table info available. > #9 0x0000638167eaacfd in io_loop_call_io () from > /usr/lib/dovecot/libdovecot.so.0 > No symbol table info available. > #10 0x0000638167eac635 in io_loop_handler_run_internal () from > /usr/lib/dovecot/libdovecot.so.0 > No symbol table info available. > #11 0x0000638167eaadc7 in io_loop_handler_run () from > /usr/lib/dovecot/libdovecot.so.0 > No symbol table info available. > #12 0x0000638167eaaf68 in io_loop_run () from > /usr/lib/dovecot/libdovecot.so.0 > No symbol table info available. > #13 0x0000638167e1b36a in master_service_run () from > /usr/lib/dovecot/libdovecot.so.0 > No symbol table info available. > #14 0x000004a58a202300 in main () > No symbol table info available. > > - Marcel > > Am 03.02.2019 um 09:08 schrieb John Fawcett: >> On 01/02/2019 20:40, Marcel Menzel wrote: >>> Hello, > >> > >> After I configured a SQLite backed dict quota backend, the dict > process > >> crashes every time a quota operation is happening. > >> > >> SQLite: 3.26.0 > >> > >> Dovecot: 2.3.4 (0ecbaf23d) > >> > >> Linux: 4.20.4.a-1-hardened #1 SMP PREEMPT Fri Jan 25 01:24:51 CET > 2019 > >> x86_64 GNU/Linux (Arch Linux) > >> > >> Filesystem: BTRFS > >> > >> > >> I can't get any debug output from Dovecot, even after setting > log_debug > >> = cat:* event:* source:* field:*=* > >> > >> dovecot[6457]: dict(6687): Debug: sqlite: Finished query 'BEGIN > >> TRANSACTION' in 0 msecs > >> dovecot[6457]: dict(6687): Fatal: master: service(dict): child 6687 > >> killed with signal 11 (core dumped) > >> > >> > >> I've attached the output of dovecot -n and the coredump file from > >> systemd-coredump. > >> > >> > >> Kind regards, > >> > >> Marcel Menzel > >> >> Any chance of posting a backtrace? >> John
Aki Tuomi
Aki Tuomi
Aki Tuomi
Aki Tuomi
Can you try out the attached patch?
Aki
On 03 February 2019 at 17:17 Marcel Menzel <mail@mcl.gg> wrote:
All I did was
- create a sqlite database with: # sqlite3 /tmp/storage.db (/run only to test for perm issues in other folders)
- change it's owner to mail (that's the user owning the mail files): # chown mail:mail /tmp/storage.db
- point dovecot to the file in "dovecot-dict-sql.conf.ext" with "connect = /tmp/storage.db"
- enable quota in "90-quota.conf" with "quota = dict:User quota::proxy::quota" in the plugin section (sample config file taken from sources)
- changing the dict section in dovecot.conf to:
dict { quota = sqlite:/etc/dovecot/dovecot-dict-sql.conf.ext expire = sqlite:/etc/dovecot/dovecot-dict-sql.conf.ext }
After this, a simple "doveadm quota recalc -u mail@mcl.gg" is enough to cause a dict crash.
While tinkering with the config (and making a small mistake where i moved the file and dovecot complaining about
doveadm: Error: dict quota: Quota update failed: dict-server returned failure: sql dict: commit failed: out of memory (reply took 0.041 secs (0.001 in dict wait, 0.000 in other ioloops, 0.001 in locks, async-id reply 0.000 secs ago, started on dict-server 0.041 secs ago, took 0.000 secs)) - Quota is now desynced
And reloading it afterwards, my log got filled with like 200 lines containing
dovecot[6213]: dict(6301): Warning: Event 0x67a90293830 leaked (parent=0x67a9027c890): driver-sqlite.c:173
- Marcel
Am 03.02.2019 um 15:57 schrieb Aki Tuomi:
Can you provide steps on how to reproduce this? Tracked as DOP-899
On 03 February 2019 at 16:50 Aki Tuomi < aki.tuomi@open-xchange.com <mailto:aki.tuomi@open-xchange.com>> wrote:
Right it was already in 2.3.4. Looking more closely this looks like use after free. We'll look into this.
Aki
On 03 February 2019 at 16:44 Marcel Menzel < mail@mcl.gg <mailto:mail@mcl.gg>> wrote:
Hello Aki,
unfortunately, this patch is already in my source files, as patch refuses to apply it:
-> Applying patch fix-sqlite.patch patching file src/lib-sql/driver-sqlite.c Reversed (or previously applied) patch detected! Skipping patch. 2 out of 2 hunks ignored -- saving rejects to file src/lib-sql/driver-sqlite.c.rej
I verified it by looking in the source code and indeed, this patch is already applied.
- Marcel
Am 03.02.2019 um 15:25 schrieb Aki Tuomi:
Can you try if applying
https://github.com/dovecot/core/commit/b291ff1fd61b47639a2db99bd858c9511945f...
> helps?
Aki > > On 03 February 2019 at 16:20 Marcel Menzel < mail@mcl.gg <mailto:mail@mcl.gg> <mailto: mail@mcl.gg <mailto:mail@mcl.gg>>> wrote:
> > >> Hello Aki,
Arch Linux doesn't have install-able debug symbols for Dovecot. That's why I just compiled the package for myself with enabled debug symbols (by editing the makepkg.conf).
I've attached the output from gdb's bt full.
- Marcel
Am 03.02.2019 um 14:45 schrieb Aki Tuomi: > You need to install debug symbols. Not sure how this is done in arch > linux though. > Aki >> On 03 February 2019 at 15:02 Marcel Menzel < mail@mcl.gg <mailto:mail@mcl.gg> >> <mailto: mail@mcl.gg <mailto:mail@mcl.gg>> >> <mailto: mail@mcl.gg <mailto:mail@mcl.gg> <mailto: mail@mcl.gg <mailto:mail@mcl.gg>>>> wrote: >> >> Hello John, >> >> I tried (until now) to get a valuable backtrace, but it seems that GDB >> can't resolve all symbols. >> This is what systemd-coredump is giving me: >> >> Stack trace of thread 22359: >> #0 0x0000638167eaf062 event_unref (libdovecot.so.0) >> #1 0x000004a58a212151 n/a (dict) >> #2 0x000004a58a211333 n/a (dict) >> #3 0x000004a58a20514d n/a (dict) >> #4 0x0000638167e556f2 dict_transaction_begin (libdovecot.so.0) >> #5 0x000004a58a203b06 n/a (dict) >> #6 0x000004a58a2045ff dict_command_input (dict) >> #7 0x000004a58a202a31 n/a (dict) >> #8 0x000004a58a202b35 n/a (dict) >> #9 0x0000638167eaacfd io_loop_call_io (libdovecot.so.0) >> #10 0x0000638167eac635 io_loop_handler_run_internal (libdovecot.so.0) >> #11 0x0000638167eaadc7 io_loop_handler_run (libdovecot.so.0) >> #12 0x0000638167eaaf68 io_loop_run (libdovecot.so.0) >> #13 0x0000638167e1b36a master_service_run (libdovecot.so.0) >> #14 0x000004a58a202300 main (dict) >> #15 0x0000638167a17223 __libc_start_main (libc.so.6) >> #16 0x000004a58a2023fe _start (dict) >> >> GDB's "bt full" won't give anything more here, I might compile Dovecot >> with debug symbols enabled as soon as I have a little more time: >> >> (gdb) bt full >> #0 0x0000638167eaf062 in event_unref () from >> /usr/lib/dovecot/libdovecot.so.0 >> No symbol table info available. >> #1 0x000004a58a212151 in ?? () >> No symbol table info available. >> #2 0x000004a58a211333 in ?? () >> No symbol table info available. >> #3 0x000004a58a20514d in ?? () >> No symbol table info available. >> #4 0x0000638167e556f2 in dict_transaction_begin () from >> /usr/lib/dovecot/libdovecot.so.0 >> No symbol table info available. >> #5 0x000004a58a203b06 in ?? () >> No symbol table info available. >> #6 0x000004a58a2045ff in dict_command_input () >> No symbol table info available. >> #7 0x000004a58a202a31 in ?? () >> No symbol table info available. >> #8 0x000004a58a202b35 in ?? () >> No symbol table info available. >> #9 0x0000638167eaacfd in io_loop_call_io () from >> /usr/lib/dovecot/libdovecot.so.0 >> No symbol table info available. >> #10 0x0000638167eac635 in io_loop_handler_run_internal () from >> /usr/lib/dovecot/libdovecot.so.0 >> No symbol table info available. >> #11 0x0000638167eaadc7 in io_loop_handler_run () from >> /usr/lib/dovecot/libdovecot.so.0 >> No symbol table info available. >> #12 0x0000638167eaaf68 in io_loop_run () from >> /usr/lib/dovecot/libdovecot.so.0 >> No symbol table info available. >> #13 0x0000638167e1b36a in master_service_run () from >> /usr/lib/dovecot/libdovecot.so.0 >> No symbol table info available. >> #14 0x000004a58a202300 in main () >> No symbol table info available. >> >> - Marcel >> >> Am 03.02.2019 um 09:08 schrieb John Fawcett: >>> On 01/02/2019 20:40, Marcel Menzel wrote: >>>> Hello, >> >> >> >> After I configured a SQLite backed dict quota backend, the dict >> process >> >> crashes every time a quota operation is happening. >> >> >> >> SQLite: 3.26.0 >> >> >> >> Dovecot: 2.3.4 (0ecbaf23d) >> >> >> >> Linux: 4.20.4.a-1-hardened #1 SMP PREEMPT Fri Jan 25 01:24:51 CET >> 2019 >> >> x86_64 GNU/Linux (Arch Linux) >> >> >> >> Filesystem: BTRFS >> >> >> >> >> >> I can't get any debug output from Dovecot, even after setting >> log_debug >> >> = cat:* event:* source:* field:*=* >> >> >> >> dovecot[6457]: dict(6687): Debug: sqlite: Finished query 'BEGIN >> >> TRANSACTION' in 0 msecs >> >> dovecot[6457]: dict(6687): Fatal: master: service(dict): child 6687 >> >> killed with signal 11 (core dumped) >> >> >> >> >> >> I've attached the output of dovecot -n and the coredump file from >> >> systemd-coredump. >> >> >> >> >> >> Kind regards, >> >> >> >> Marcel Menzel >> >> >>> Any chance of posting a backtrace? >>> John > > --- > Aki Tuomi
Aki Tuomi
Aki Tuomi
Aki Tuomi
...and then I found the commit I was looking for. It's fixed in https://github.com/dovecot/core/commit/ab80122c68bfe5c3dbae2b4d782f418112271...
Aki
On 03 February 2019 at 20:06 Aki Tuomi <aki.tuomi@open-xchange.com> wrote:
Can you try out the attached patch?
Aki
On 03 February 2019 at 17:17 Marcel Menzel <mail@mcl.gg> wrote:
All I did was
- create a sqlite database with: # sqlite3 /tmp/storage.db (/run only to test for perm issues in other folders)
- change it's owner to mail (that's the user owning the mail files): # chown mail:mail /tmp/storage.db
- point dovecot to the file in "dovecot-dict-sql.conf.ext" with "connect = /tmp/storage.db"
- enable quota in "90-quota.conf" with "quota = dict:User quota::proxy::quota" in the plugin section (sample config file taken from sources)
- changing the dict section in dovecot.conf to:
dict { quota = sqlite:/etc/dovecot/dovecot-dict-sql.conf.ext expire = sqlite:/etc/dovecot/dovecot-dict-sql.conf.ext }
After this, a simple "doveadm quota recalc -u mail@mcl.gg" is enough to cause a dict crash.
While tinkering with the config (and making a small mistake where i moved the file and dovecot complaining about
doveadm: Error: dict quota: Quota update failed: dict-server returned failure: sql dict: commit failed: out of memory (reply took 0.041 secs (0.001 in dict wait, 0.000 in other ioloops, 0.001 in locks, async-id reply 0.000 secs ago, started on dict-server 0.041 secs ago, took 0.000 secs)) - Quota is now desynced
And reloading it afterwards, my log got filled with like 200 lines containing
dovecot[6213]: dict(6301): Warning: Event 0x67a90293830 leaked (parent=0x67a9027c890): driver-sqlite.c:173
- Marcel
Am 03.02.2019 um 15:57 schrieb Aki Tuomi:
Can you provide steps on how to reproduce this? Tracked as DOP-899
On 03 February 2019 at 16:50 Aki Tuomi < aki.tuomi@open-xchange.com <mailto:aki.tuomi@open-xchange.com>> wrote:
Right it was already in 2.3.4. Looking more closely this looks like use after free. We'll look into this.
Aki
On 03 February 2019 at 16:44 Marcel Menzel < mail@mcl.gg <mailto:mail@mcl.gg>> wrote:
Hello Aki,
unfortunately, this patch is already in my source files, as patch refuses to apply it:
-> Applying patch fix-sqlite.patch patching file src/lib-sql/driver-sqlite.c Reversed (or previously applied) patch detected! Skipping patch. 2 out of 2 hunks ignored -- saving rejects to file src/lib-sql/driver-sqlite.c.rej
I verified it by looking in the source code and indeed, this patch is already applied.
- Marcel
Am 03.02.2019 um 15:25 schrieb Aki Tuomi:
> Can you try if applying > > https://github.com/dovecot/core/commit/b291ff1fd61b47639a2db99bd858c9511945f...
> > > helps? > > Aki > > > On 03 February 2019 at 16:20 Marcel Menzel < mail@mcl.gg <mailto:mail@mcl.gg> > <mailto: mail@mcl.gg <mailto:mail@mcl.gg>>> wrote: > > > > > >> > Hello Aki, > > Arch Linux doesn't have install-able debug symbols for Dovecot. That's > why I just compiled the package for myself with enabled debug symbols > (by editing the makepkg.conf). > > I've attached the output from gdb's bt full. > > - Marcel > > Am 03.02.2019 um 14:45 schrieb Aki Tuomi: >> You need to install debug symbols. Not sure how this is done in arch >> linux though. >> Aki >>> On 03 February 2019 at 15:02 Marcel Menzel < mail@mcl.gg <mailto:mail@mcl.gg> >>> <mailto: mail@mcl.gg <mailto:mail@mcl.gg>> >>> <mailto: mail@mcl.gg <mailto:mail@mcl.gg> <mailto: mail@mcl.gg <mailto:mail@mcl.gg>>>> wrote: > >> > >> Hello John, > >> > >> I tried (until now) to get a valuable backtrace, but it seems that > GDB > >> can't resolve all symbols. > >> This is what systemd-coredump is giving me: > >> > >> Stack trace of thread 22359: > >> #0 0x0000638167eaf062 event_unref (libdovecot.so.0) > >> #1 0x000004a58a212151 n/a (dict) > >> #2 0x000004a58a211333 n/a (dict) > >> #3 0x000004a58a20514d n/a (dict) > >> #4 0x0000638167e556f2 dict_transaction_begin (libdovecot.so.0) > >> #5 0x000004a58a203b06 n/a (dict) > >> #6 0x000004a58a2045ff dict_command_input (dict) > >> #7 0x000004a58a202a31 n/a (dict) > >> #8 0x000004a58a202b35 n/a (dict) > >> #9 0x0000638167eaacfd io_loop_call_io (libdovecot.so.0) > >> #10 0x0000638167eac635 io_loop_handler_run_internal (libdovecot.so.0) > >> #11 0x0000638167eaadc7 io_loop_handler_run (libdovecot.so.0) > >> #12 0x0000638167eaaf68 io_loop_run (libdovecot.so.0) > >> #13 0x0000638167e1b36a master_service_run (libdovecot.so.0) > >> #14 0x000004a58a202300 main (dict) > >> #15 0x0000638167a17223 __libc_start_main (libc.so.6) > >> #16 0x000004a58a2023fe _start (dict) > >> > >> GDB's "bt full" won't give anything more here, I might compile > Dovecot > >> with debug symbols enabled as soon as I have a little more time: > >> > >> (gdb) bt full > >> #0 0x0000638167eaf062 in event_unref () from > >> /usr/lib/dovecot/libdovecot.so.0 > >> No symbol table info available. > >> #1 0x000004a58a212151 in ?? () > >> No symbol table info available. > >> #2 0x000004a58a211333 in ?? () > >> No symbol table info available. > >> #3 0x000004a58a20514d in ?? () > >> No symbol table info available. > >> #4 0x0000638167e556f2 in dict_transaction_begin () from > >> /usr/lib/dovecot/libdovecot.so.0 > >> No symbol table info available. > >> #5 0x000004a58a203b06 in ?? () > >> No symbol table info available. > >> #6 0x000004a58a2045ff in dict_command_input () > >> No symbol table info available. > >> #7 0x000004a58a202a31 in ?? () > >> No symbol table info available. > >> #8 0x000004a58a202b35 in ?? () > >> No symbol table info available. > >> #9 0x0000638167eaacfd in io_loop_call_io () from > >> /usr/lib/dovecot/libdovecot.so.0 > >> No symbol table info available. > >> #10 0x0000638167eac635 in io_loop_handler_run_internal () from > >> /usr/lib/dovecot/libdovecot.so.0 > >> No symbol table info available. > >> #11 0x0000638167eaadc7 in io_loop_handler_run () from > >> /usr/lib/dovecot/libdovecot.so.0 > >> No symbol table info available. > >> #12 0x0000638167eaaf68 in io_loop_run () from > >> /usr/lib/dovecot/libdovecot.so.0 > >> No symbol table info available. > >> #13 0x0000638167e1b36a in master_service_run () from > >> /usr/lib/dovecot/libdovecot.so.0 > >> No symbol table info available. > >> #14 0x000004a58a202300 in main () > >> No symbol table info available. > >> > >> - Marcel > >> > >> Am 03.02.2019 um 09:08 schrieb John Fawcett: > >>> On 01/02/2019 20:40, Marcel Menzel wrote: > >>>> Hello, > >> >> > >> >> After I configured a SQLite backed dict quota backend, the dict > >> process > >> >> crashes every time a quota operation is happening. > >> >> > >> >> SQLite: 3.26.0 > >> >> > >> >> Dovecot: 2.3.4 (0ecbaf23d) > >> >> > >> >> Linux: 4.20.4.a-1-hardened #1 SMP PREEMPT Fri Jan 25 01:24:51 CET > >> 2019 > >> >> x86_64 GNU/Linux (Arch Linux) > >> >> > >> >> Filesystem: BTRFS > >> >> > >> >> > >> >> I can't get any debug output from Dovecot, even after setting > >> log_debug > >> >> = cat:* event:* source:* field:*=* > >> >> > >> >> dovecot[6457]: dict(6687): Debug: sqlite: Finished query 'BEGIN > >> >> TRANSACTION' in 0 msecs > >> >> dovecot[6457]: dict(6687): Fatal: master: service(dict): child > 6687 > >> >> killed with signal 11 (core dumped) > >> >> > >> >> > >> >> I've attached the output of dovecot -n and the coredump file from > >> >> systemd-coredump. > >> >> > >> >> > >> >> Kind regards, > >> >> > >> >> Marcel Menzel > >> >> > >>> Any chance of posting a backtrace? > >>> John > > >> --- >> Aki Tuomi
> --- Aki Tuomi
>
Aki Tuomi
Aki Tuomi
Hello Aki,
Applying the patch from GitHub indeed fixed the problem for me.
- Marcel
Am 03.02.2019 um 19:08 schrieb Aki Tuomi:
...and then I found the commit I was looking for. It's fixed in https://github.com/dovecot/core/commit/ab80122c68bfe5c3dbae2b4d782f418112271...
Aki
On 03 February 2019 at 20:06 Aki Tuomi <aki.tuomi@open-xchange.com> wrote:
Can you try out the attached patch?
Aki
On 03 February 2019 at 17:17 Marcel Menzel <mail@mcl.gg> wrote:
All I did was
- create a sqlite database with: # sqlite3 /tmp/storage.db (/run only to test for perm issues in other folders)
- change it's owner to mail (that's the user owning the mail files): # chown mail:mail /tmp/storage.db
- point dovecot to the file in "dovecot-dict-sql.conf.ext" with "connect = /tmp/storage.db"
- enable quota in "90-quota.conf" with "quota = dict:User quota::proxy::quota" in the plugin section (sample config file taken from sources)
- changing the dict section in dovecot.conf to:
dict { quota = sqlite:/etc/dovecot/dovecot-dict-sql.conf.ext expire = sqlite:/etc/dovecot/dovecot-dict-sql.conf.ext }
After this, a simple "doveadm quota recalc -u mail@mcl.gg" is enough to cause a dict crash.
While tinkering with the config (and making a small mistake where i moved the file and dovecot complaining about
doveadm: Error: dict quota: Quota update failed: dict-server returned failure: sql dict: commit failed: out of memory (reply took 0.041 secs (0.001 in dict wait, 0.000 in other ioloops, 0.001 in locks, async-id reply 0.000 secs ago, started on dict-server 0.041 secs ago, took 0.000 secs)) - Quota is now desynced
And reloading it afterwards, my log got filled with like 200 lines containing
dovecot[6213]: dict(6301): Warning: Event 0x67a90293830 leaked (parent=0x67a9027c890): driver-sqlite.c:173
- Marcel
Am 03.02.2019 um 15:57 schrieb Aki Tuomi:
Can you provide steps on how to reproduce this? Tracked as DOP-899
On 03 February 2019 at 16:50 Aki Tuomi < aki.tuomi@open-xchange.com <mailto:aki.tuomi@open-xchange.com>> wrote:
Right it was already in 2.3.4. Looking more closely this looks like use after free. We'll look into this.
Aki
On 03 February 2019 at 16:44 Marcel Menzel < mail@mcl.gg <mailto:mail@mcl.gg>> wrote:
Hello Aki,
unfortunately, this patch is already in my source files, as patch refuses to apply it:
-> Applying patch fix-sqlite.patch patching file src/lib-sql/driver-sqlite.c Reversed (or previously applied) patch detected! Skipping patch. 2 out of 2 hunks ignored -- saving rejects to file src/lib-sql/driver-sqlite.c.rej
I verified it by looking in the source code and indeed, this patch is already applied.
- Marcel
Am 03.02.2019 um 15:25 schrieb Aki Tuomi:
>> Can you try if applying >> >> https://github.com/dovecot/core/commit/b291ff1fd61b47639a2db99bd858c9511945f...
>> helps? >> >> Aki >>>> On 03 February 2019 at 16:20 Marcel Menzel < mail@mcl.gg > <mailto:mail@mcl.gg> >> <mailto: mail@mcl.gg <mailto:mail@mcl.gg>>> wrote: >> >>>> >> Hello Aki, >> >> Arch Linux doesn't have install-able debug symbols for Dovecot. That's >> why I just compiled the package for myself with enabled debug symbols >> (by editing the makepkg.conf). >> >> I've attached the output from gdb's bt full. >> >> - Marcel >> >> Am 03.02.2019 um 14:45 schrieb Aki Tuomi: >>> You need to install debug symbols. Not sure how this is done in arch >>> linux though. >>> Aki >>>> On 03 February 2019 at 15:02 Marcel Menzel < mail@mcl.gg <mailto:mail@mcl.gg> >>>> <mailto: mail@mcl.gg <mailto:mail@mcl.gg>> >>>> <mailto: mail@mcl.gg <mailto:mail@mcl.gg> <mailto: mail@mcl.gg <mailto:mail@mcl.gg>>>> wrote: >>>> Hello John, >>>> >>>> I tried (until now) to get a valuable backtrace, but it seems that >> GDB >>>> can't resolve all symbols. >>>> This is what systemd-coredump is giving me: >>>> >>>> Stack trace of thread 22359: >>>> #0 0x0000638167eaf062 event_unref (libdovecot.so.0) >>>> #1 0x000004a58a212151 n/a (dict) >>>> #2 0x000004a58a211333 n/a (dict) >>>> #3 0x000004a58a20514d n/a (dict) >>>> #4 0x0000638167e556f2 dict_transaction_begin (libdovecot.so.0) >>>> #5 0x000004a58a203b06 n/a (dict) >>>> #6 0x000004a58a2045ff dict_command_input (dict) >>>> #7 0x000004a58a202a31 n/a (dict) >>>> #8 0x000004a58a202b35 n/a (dict) >>>> #9 0x0000638167eaacfd io_loop_call_io (libdovecot.so.0) >>>> #10 0x0000638167eac635 io_loop_handler_run_internal (libdovecot.so.0) >>>> #11 0x0000638167eaadc7 io_loop_handler_run (libdovecot.so.0) >>>> #12 0x0000638167eaaf68 io_loop_run (libdovecot.so.0) >>>> #13 0x0000638167e1b36a master_service_run (libdovecot.so.0) >>>> #14 0x000004a58a202300 main (dict) >>>> #15 0x0000638167a17223 __libc_start_main (libc.so.6) >>>> #16 0x000004a58a2023fe _start (dict) >>>> >>>> GDB's "bt full" won't give anything more here, I might compile >> Dovecot >>>> with debug symbols enabled as soon as I have a little more time: >>>> >>>> (gdb) bt full >>>> #0 0x0000638167eaf062 in event_unref () from >>>> /usr/lib/dovecot/libdovecot.so.0 >>>> No symbol table info available. >>>> #1 0x000004a58a212151 in ?? () >>>> No symbol table info available. >>>> #2 0x000004a58a211333 in ?? () >>>> No symbol table info available. >>>> #3 0x000004a58a20514d in ?? () >>>> No symbol table info available. >>>> #4 0x0000638167e556f2 in dict_transaction_begin () from >>>> /usr/lib/dovecot/libdovecot.so.0 >>>> No symbol table info available. >>>> #5 0x000004a58a203b06 in ?? () >>>> No symbol table info available. >>>> #6 0x000004a58a2045ff in dict_command_input () >>>> No symbol table info available. >>>> #7 0x000004a58a202a31 in ?? () >>>> No symbol table info available. >>>> #8 0x000004a58a202b35 in ?? () >>>> No symbol table info available. >>>> #9 0x0000638167eaacfd in io_loop_call_io () from >>>> /usr/lib/dovecot/libdovecot.so.0 >>>> No symbol table info available. >>>> #10 0x0000638167eac635 in io_loop_handler_run_internal () from >>>> /usr/lib/dovecot/libdovecot.so.0 >>>> No symbol table info available. >>>> #11 0x0000638167eaadc7 in io_loop_handler_run () from >>>> /usr/lib/dovecot/libdovecot.so.0 >>>> No symbol table info available. >>>> #12 0x0000638167eaaf68 in io_loop_run () from >>>> /usr/lib/dovecot/libdovecot.so.0 >>>> No symbol table info available. >>>> #13 0x0000638167e1b36a in master_service_run () from >>>> /usr/lib/dovecot/libdovecot.so.0 >>>> No symbol table info available. >>>> #14 0x000004a58a202300 in main () >>>> No symbol table info available. >>>> >>>> - Marcel >>>> >>>> Am 03.02.2019 um 09:08 schrieb John Fawcett: >>>>> On 01/02/2019 20:40, Marcel Menzel wrote: >>>>>> Hello, >>>>>> >>>>>> After I configured a SQLite backed dict quota backend, the dict >>>> process >>>>>> crashes every time a quota operation is happening. >>>>>> >>>>>> SQLite: 3.26.0 >>>>>> >>>>>> Dovecot: 2.3.4 (0ecbaf23d) >>>>>> >>>>>> Linux: 4.20.4.a-1-hardened #1 SMP PREEMPT Fri Jan 25 01:24:51 CET >>>> 2019 >>>>>> x86_64 GNU/Linux (Arch Linux) >>>>>> >>>>>> Filesystem: BTRFS >>>>>> >>>>>> >>>>>> I can't get any debug output from Dovecot, even after setting >>>> log_debug >>>>>> = cat:* event:* source:* field:*=* >>>>>> >>>>>> dovecot[6457]: dict(6687): Debug: sqlite: Finished query 'BEGIN >>>>>> TRANSACTION' in 0 msecs >>>>>> dovecot[6457]: dict(6687): Fatal: master: service(dict): child >> 6687 >>>>>> killed with signal 11 (core dumped) >>>>>> >>>>>> >>>>>> I've attached the output of dovecot -n and the coredump file from >>>>>> systemd-coredump. >>>>>> >>>>>> >>>>>> Kind regards, >>>>>> >>>>>> Marcel Menzel >>>>>> >>>>> Any chance of posting a backtrace? >>>>> John >>> --- >>> Aki Tuomi >> --- > Aki Tuomi >
Aki Tuomi
Aki Tuomi
participants (3)
-
Aki Tuomi
-
John Fawcett
-
Marcel Menzel