Re: Crash when using dict quotas with sqlite database

3 Feb 2019 · *=*


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