thr3ads.net - dovecot - OOM in Dovecot 2.2.13 imap [Jun 2014]

If this information is useful, please help other people find it:
Share via:

Bernhard Schmidt

2014-Jun-23 12:18 UTC

OOM in Dovecot 2.2.13 imap

Hi,

we run Dovecot 2.2.13 on Debian Wheezy with a couple thousand mailboxes.
We have two users that repeatedly trigger an OOM condition with IMAP.

Jun 23 12:53:21 lxmhs74 dovecot: imap(USER): Fatal:
pool_system_realloc(268435456): Out of memory
Jun 23 12:53:21 lxmhs74 dovecot: imap(USER): Error: Raw backtrace:
/usr/lib/dovecot/libdovecot.so.0(+0x6c15f) [0x7f11766cc15f] ->
/usr/lib/dovecot/libdovecot.so.0(+0x6c1be) [0x7f11766cc1be] ->
/usr/lib/dovecot/libdovecot.so.0(i_error+0) [0x7f1176685568] ->
/usr/lib/dovecot/libdovecot.so.0(+0x81e80) [0x7f11766e1e80] ->
/usr/lib/dovecot/libdovecot.so.0(+0x86cda) [0x7f11766e6cda] ->
/usr/lib/dovecot/libdovecot.so.0(+0x86f96) [0x7f11766e6f96] ->
/usr/lib/dovecot/libdovecot.so.0(+0x87b48) [0x7f11766e7b48] ->
/usr/lib/dovecot/libdovecot.so.0(o_stream_sendv+0xcd) [0x7f11766e60cd] ->
/usr/lib/dovecot/libdovecot.so.0(o_stream_send+0x1a) [0x7f11766e615a] ->
/usr/lib/dovecot/modules/lib30_imap_zlib_plugin.so(+0x5849) [0x7f1175692849]
-> /usr/lib/dovecot/modules/lib30_imap_zlib_plugin.so(+0x5982)
[0x7f1175692982] ->
/usr/lib/dovecot/modules/lib30_imap_zlib_plugin.so(+0x5b62) [0x7f1175692b62]
-> /usr/lib/dovecot/libdovecot.so.0(o_stream_flush+0x4d) [0x7f11766e5d6d]
->
/usr/lib/dovecot/libdovecot.so.0(+0x85e2c) [0x7f11766e5e2c] -> dovecot/imap
[USER IP UID fetch](client_output+0xe9) [0x7f1176e8d269] ->
/usr/lib/dovecot/libdovecot.so.0(+0x879d5) [0x7f11766e79d5] ->
/usr/lib/dovecot/libdovecot.so.0(io_loop_call_io+0x4e) [0x7f11766dcfbe] ->
/usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run_internal+0xd7)
[0x7f11766ddfb7] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run+0x9)
[0x7f11766dd049] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_run+0x38)
[0x7f11766dd0c8] -> /usr/lib/dovecot/libdovecot.so.0(master_service_run+0x13)
[0x7f117668a7b3] -> dovecot/imap [USER IP UID fetch](main+0x2ae)
[0x7f1176e8152e] -> /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xfd)
[0x7f11762f3ead] -> dovecot/imap [USER IP UID fetch](+0xd69d)
[0x7f1176e8169d]
Jun 23 12:53:21 lxmhs74 dovecot: imap(USER): Fatal: master: service(imap): child
33659 killed with signal 6 (core dumped)

The gdb backtrace looks like this:

gdb) bt full
#0  0x00007f1176307475 in raise () from /lib/x86_64-linux-gnu/libc.so.6
No symbol table info available.
#1  0x00007f117630a6f0 in abort () from /lib/x86_64-linux-gnu/libc.so.6
No symbol table info available.
#2  0x00007f11766cc155 in default_fatal_finish (type=<optimized out>,
status=status at entry=83) at failures.c:193
        backtrace = 0x7f11789d4088
"/usr/lib/dovecot/libdovecot.so.0(+0x6c15f) [0x7f11766cc15f] ->
/usr/lib/dovecot/libdovecot.so.0(+0x6c1be) [0x7f11766cc1be] ->
/usr/lib/dovecot/libdovecot.so.0(i_error+0) [0x7f1176685568] ->
/usr/lib/d"...
#3  0x00007f11766cc1be in i_internal_fatal_handler (ctx=0x7fff5ffedfb0,
format=<optimized out>, args=<optimized out>) at failures.c:657
        status = 83
#4  0x00007f1176685568 in i_fatal_status (status=status at entry=83,
format=format at entry=0x7f1176702ba8 "pool_system_realloc(%lu): Out of
memory") at failures.c:295
        ctx = {type = LOG_TYPE_FATAL, exit_status = 83, timestamp = 0x0}
        args = {{gp_offset = 24, fp_offset = 48, overflow_arg_area =
0x7fff5ffee0a0, reg_save_area = 0x7fff5ffedfe0}}
#5  0x00007f11766e1e80 in pool_system_realloc (pool=<optimized out>,
mem=0x0, old_size=134217728, new_size=268435456) at mempool-system.c:134
        __FUNCTION__ = "pool_system_realloc"
#6  0x00007f11766e6cda in o_stream_grow_buffer (fstream=fstream at
entry=0x7f11789f41c0, bytes=<optimized out>) at ostream-file.c:440
        size = 268435456
        new_size = <optimized out>
        end_size = <optimized out>
#7  0x00007f11766e6f96 in o_stream_add (fstream=fstream at entry=0x7f11789f41c0,
data=0x7f11789fe549, size=12113) at ostream-file.c:501
        unused = <optimized out>
        sent = <optimized out>
        i = <optimized out>
#8  0x00007f11766e7b48 in o_stream_file_sendv (stream=0x7f11789f41c0,
iov=<optimized out>, iov_count=<optimized out>) at
ostream-file.c:588
        fstream = 0x7f11789f41c0
        size = <optimized out>
        total_size = <optimized out>
        added = <optimized out>
        optimal_size = <optimized out>
        i = <optimized out>
        ret = 0
        __FUNCTION__ = "o_stream_file_sendv"
#9  0x00007f11766e60cd in o_stream_sendv (stream=0x7f11789f4250, iov=iov at
entry=0x7fff5ffee1a0, iov_count=iov_count at entry=1) at ostream.c:239
        _stream = 0x7f11789f41c0
        i = <optimized out>
        total_size = 12113
        ret = <optimized out>
        __FUNCTION__ = "o_stream_sendv"
#10 0x00007f11766e615a in o_stream_send (stream=<optimized out>,
data=<optimized out>, size=size at entry=12113) at ostream.c:217
        iov = {iov_base = 0x7f11789fe549, iov_len = 12113}
#11 0x00007f1175692849 in o_stream_zlib_send_outbuf (zstream=0x7f11789f9340) at
ostream-zlib.c:94
        ret = <optimized out>
        size = 12113
#12 0x00007f1175692982 in o_stream_zlib_send_flush (zstream=zstream at
entry=0x7f11789f9340, final=final at entry=true) at ostream-zlib.c:189
        zs = 0x7f11789f9420
        len = <optimized out>
        done = false
        ret = <optimized out>
        flush = <optimized out>
        __FUNCTION__ = "o_stream_zlib_send_flush"
#13 0x00007f1175692b62 in o_stream_zlib_flush (stream=0x7f11789f9340) at
ostream-zlib.c:235
        zstream = 0x7f11789f9340
        ret = <optimized out>
#14 0x00007f11766e5d6d in o_stream_flush (stream=stream at entry=0x7f11789f93d0)
at ostream.c:157
        _stream = 0x7f11789f9340
        ret = 1
        __FUNCTION__ = "o_stream_flush"
#15 0x00007f11766e5e2c in o_stream_default_cork (_stream=0x7f11789f9340,
set=<optimized out>) at ostream.c:429
No locals.
#16 o_stream_default_cork (_stream=0x7f11789f9340, set=<optimized out>) at
ostream.c:422
No locals.
#17 0x00007f1176e8d269 in client_output (client=0x7f11789f4470) at
imap-client.c:1019
        ret = 0
        __FUNCTION__ = "client_output"
#18 0x00007f11766e79d5 in stream_send_io (fstream=0x7f11789f41c0) at
ostream-file.c:468
        ostream = 0x7f11789f4250
        ret = <optimized out>
#19 0x00007f11766dcfbe in io_loop_call_io (io=0x7f1178a5bbe0) at ioloop.c:441
        ioloop = 0x7f11789dc750
        t_id = 2
        __FUNCTION__ = "io_loop_call_io"
#20 0x00007f11766ddfb7 in io_loop_handler_run_internal (ioloop=ioloop at
entry=0x7f11789dc750) at ioloop-epoll.c:220
        ctx = 0x7f11789dd3e0
        events = 0x0
        event = 0x7f11789de250
        list = 0x7f11789dee40
        io = <optimized out>
        tv = {tv_sec = 297, tv_usec = 43980}
        events_count = <optimized out>
        msecs = <optimized out>
        ret = 1
        i = <optimized out>
        call = <optimized out>
        __FUNCTION__ = "io_loop_handler_run_internal"
#21 0x00007f11766dd049 in io_loop_handler_run (ioloop=ioloop at
entry=0x7f11789dc750) at ioloop.c:488
No locals.
#22 0x00007f11766dd0c8 in io_loop_run (ioloop=0x7f11789dc750) at ioloop.c:465
        __FUNCTION__ = "io_loop_run"
#23 0x00007f117668a7b3 in master_service_run (service=0x7f11789dc5e0,
callback=callback at entry=0x7f1176e96a00 <client_connected>) at
master-service.c:566
No locals.
#24 0x00007f1176e8152e in main (argc=1, argv=0x7f11789dc390) at main.c:400
        set_roots = {0x7f11770a4960, 0x0}
        login_set = {auth_socket_path = 0x7f11789d4048 "\001",
postlogin_socket_path = 0x0, postlogin_timeout_secs = 60, callback =
0x7f1176e96880 <login_client_connected>,
          failure_callback = 0x7f1176e96580 <login_client_failed>,
request_auth_token = 1}
        service_flags = <optimized out>
        storage_service_flags = <optimized out>
        username = 0x0
        c = <optimized out>

I already deleted the index, but the issue persists.

Bernhard

Steffen Kaiser

2014-Jun-23 14:38 UTC

head link

Re: OOM in Dovecot 2.2.13 imap

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

On Mon, 23 Jun 2014, Bernhard Schmidt wrote:>
> we run Dovecot 2.2.13 on Debian Wheezy with a couple thousand mailboxes.
> We have two users that repeatedly trigger an OOM condition with IMAP.
Do those users have mailboxes extra ordinary large or is one message of 
them extra ordinary large?

Jun 23 12:53:21 lxmhs74 dovecot: imap(USER): Fatal:
pool_system_realloc(268435456): Out of memory

this number likely mean 256MB, is one of your memory limits that large? 
You can see all limits with dovecot -a (note the "-a" instead of
"-n").
Memory limits are vsz_limit, IMHO.

I had to increase some vsz_limits, because one particular large message 
caused an out of memory during LMTP.

- -- 
Steffen Kaiser
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.11 (GNU/Linux)

iQEVAwUBU6g76nz1H7kL/d9rAQJeqggApw27K6NvoVJNs8zH/MeqY8sRYzooOziQ
fJ6pIJS2I86ChaG/DjJkmlds17GSdBaM55FS94yrC+arBZMh/jVTe4KXcyzQMyzq
GtPQzWsW3LJdFGTF7RMai74bKU/ca+uIlNCtS2rznsH6p6BnJJWlE9Nml6vPEfQg
CbvED7gs+L+dclwTuKjew/6XINBaVda7k5Ow2QO+Hn7nWbnldx7QBr7sbjWPIyHy
SU6VO2tUPir+bjs16yd7uEUsTzYbpK33UUKOPBX5Dw3PWzYTh8oUpCuUW0LbSjIP
Og2x+PZ1U+0Mz5yPB7sQIegXhuon0K7bOTuNUWuErmRBItFBMTsIUg==s88s
-----END PGP SIGNATURE-----

Steffen Kaiser

2014-Jun-23 14:38 UTC

head link

OOM in Dovecot 2.2.13 imap

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

On Mon, 23 Jun 2014, Bernhard Schmidt wrote:>
> we run Dovecot 2.2.13 on Debian Wheezy with a couple thousand mailboxes.
> We have two users that repeatedly trigger an OOM condition with IMAP.
Do those users have mailboxes extra ordinary large or is one message of 
them extra ordinary large?

Jun 23 12:53:21 lxmhs74 dovecot: imap(USER): Fatal:
pool_system_realloc(268435456): Out of memory

this number likely mean 256MB, is one of your memory limits that large? 
You can see all limits with dovecot -a (note the "-a" instead of
"-n").
Memory limits are vsz_limit, IMHO.

I had to increase some vsz_limits, because one particular large message 
caused an out of memory during LMTP.

- -- 
Steffen Kaiser
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.11 (GNU/Linux)

iQEVAwUBU6g76nz1H7kL/d9rAQJeqggApw27K6NvoVJNs8zH/MeqY8sRYzooOziQ
fJ6pIJS2I86ChaG/DjJkmlds17GSdBaM55FS94yrC+arBZMh/jVTe4KXcyzQMyzq
GtPQzWsW3LJdFGTF7RMai74bKU/ca+uIlNCtS2rznsH6p6BnJJWlE9Nml6vPEfQg
CbvED7gs+L+dclwTuKjew/6XINBaVda7k5Ow2QO+Hn7nWbnldx7QBr7sbjWPIyHy
SU6VO2tUPir+bjs16yd7uEUsTzYbpK33UUKOPBX5Dw3PWzYTh8oUpCuUW0LbSjIP
Og2x+PZ1U+0Mz5yPB7sQIegXhuon0K7bOTuNUWuErmRBItFBMTsIUg==s88s
-----END PGP SIGNATURE-----

Bernhard Schmidt

2014-Jun-23 19:06 UTC

head link

OOM in Dovecot 2.2.13 imap

On 23.06.2014 16:38, Steffen Kaiser wrote:
> On Mon, 23 Jun 2014, Bernhard Schmidt wrote:
>>
>> we run Dovecot 2.2.13 on Debian Wheezy with a couple thousand
mailboxes.
>> We have two users that repeatedly trigger an OOM condition with IMAP.
>
> Do those users have mailboxes extra ordinary large or is one message of
> them extra ordinary large?
No, not particularly. 8000 Mails (2GB total), the largest mail is
20MB.>
> Jun 23 12:53:21 lxmhs74 dovecot: imap(USER): Fatal:
> pool_system_realloc(268435456): Out of memory
>
> this number likely mean 256MB, is one of your memory limits that large?
> You can see all limits with dovecot -a (note the "-a" instead of
"-n").
> Memory limits are vsz_limit, IMHO.
No memory limits outside of dovecot. In dovecot there are the default 
settings

default_vsz_limit = 256 M
service imap {
   [...]
   vsz_limit = 18446744073709551615 B
}

Since the largest IMAP processes I can observe are at around 70MB VIRT 
(43MB RSS) I suspect vsz_limit is doing what it is supposed to do (limit 
memory consumption of a run-away process) and something went wrong in 
that mailbox. Thus the backtrace, hoping for someone to confirm.

Regards,
Bernhard

Timo Sirainen

2014-Jul-03 18:28 UTC

head link

OOM in Dovecot 2.2.13 imap

On 23.6.2014, at 15.18, Bernhard Schmidt <berni at birkenwald.de> wrote:
> we run Dovecot 2.2.13 on Debian Wheezy with a couple thousand mailboxes.
> We have two users that repeatedly trigger an OOM condition with IMAP.
> 
> Jun 23 12:53:21 lxmhs74 dovecot: imap(USER): Fatal:
pool_system_realloc(268435456): Out of memory
..> #6  0x00007f11766e6cda in o_stream_grow_buffer (fstream=fstream at
entry=0x7f11789f41c0, bytes=<optimized out>) at ostream-file.c:440
>        size = 268435456
>        new_size = <optimized out>
>        end_size = <optimized out>
..> #11 0x00007f1175692849 in o_stream_zlib_send_outbuf
(zstream=0x7f11789f9340) at ostream-zlib.c:94
>        ret = <optimized out>
>        size = 12113
> #12 0x00007f1175692982 in o_stream_zlib_send_flush (zstream=zstream at
entry=0x7f11789f9340, final=final at entry=true) at ostream-zlib.c:189
This is most likely because of the IMAP COMPRESS extension, which causes the
output stream buffer to get really large. So the easiest fix would be to just
disable imap_zlib plugin and it'll probably work. But this should get fixed
properly.. I just can't figure out how this can happen. What was the IMAP
client doing that caused it? Could you run a few more gdb commands:
> #17 0x00007f1176e8d269 in client_output (client=0x7f11789f4470) at
imap-client.c:1019
Assuming client_output is again in frame 17, run:

f 17
p *client.command_queue
p *client.command_queue.next

Reasonably Related Threads

Search for more reasonably related threads

dovecot - Jun 2014 - OOM in Dovecot 2.2.13 imap

OOM in Dovecot 2.2.13 imap

Re: OOM in Dovecot 2.2.13 imap

OOM in Dovecot 2.2.13 imap

OOM in Dovecot 2.2.13 imap

OOM in Dovecot 2.2.13 imap

Reasonably Related Threads