Crash when using dict quotas with sqlite database

Sun Feb 3 20:08:59 EET 2019

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