Re: Crash when using dict quotas with sqlite database

3 Feb 2019 · *=*


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