Re: Crash when using dict quotas with sqlite database

3 Feb 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/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>> 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