Crash when using dict quotas with sqlite database

Sun Feb 3 21:35:03 EET 2019

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/ab80122c68bfe5c3dbae2b4d782f4181122710a1.patch
>
> Aki
>
>> On 03 February 2019 at 20:06 Aki Tuomi <aki.tuomi at open-xchange.com> wrote:
>>
>>
>> Can you try out the attached patch?
>>
>> Aki
>>
>>> On 03 February 2019 at 17:17 Marcel Menzel <mail at 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 at 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 at open-xchange.com
>>>>> <mailto:aki.tuomi at 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 at mcl.gg
>>>>>> <mailto:mail at 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/b291ff1fd61b47639a2db99bd858c9511945f4ab.patch
>>>>>>
>>>>>>>> helps?
>>>>>>>>
>>>>>>>> Aki
>>>>>>>>>> On 03 February 2019 at 16:20 Marcel Menzel < mail at mcl.gg
>>>>>>> <mailto:mail at mcl.gg>
>>>>>>>> <mailto: mail at mcl.gg <mailto:mail at 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 at mcl.gg
>>>>>> <mailto:mail at mcl.gg>
>>>>>>>>>> <mailto: mail at mcl.gg <mailto:mail at mcl.gg>>
>>>>>>>>>> <mailto: mail at mcl.gg <mailto:mail at mcl.gg> <mailto: mail at mcl.gg
>>>>>> <mailto:mail at 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