dovecot - Jan 2018 - Panic: data stack: Out of memory when allocating bytes

On Tue, Jan 23, 2018 at 14:03:27 -0500, Josef 'Jeff' Sipek
wrote:
> On Tue, Jan 23, 2018 at 18:21:38 +0100, Thomas Robers wrote:
> > Hello,
> > 
> > I'm using Dovecot 2.3 and sometimes i get this:
> > 
> > --- snip ---
> > Jan 23 14:23:13 mail dovecot: imap(bob at
tutech.de)<4880><PDqibHFjMvrAqG1n>:
> > Panic: data stack: Out of memory when allocating 134217768 bytes
> 
> Interesting... imap is trying to allocate 128MB and failing.  A couple of
> questions:
> 
> 0. Does this user have any unusually large emails?
> 1. Do you have any idea what the imap process was doing at the time of the
>    allocation failure?
> 2. You snipped all the important parts of the back trace. :)  It *starts*
on
>    the line:
> 	#0  0x00007f73f1386495 in raise () from /lib64/libc.so.6
In case you haven't used gdb before...  after starting up gdb, run "bt
full"
at the gdb prompt.  That'll print out a very detailed backtrace.  (You might
want to sanity check it to make sure there aren't any user passwords in it
before posting it here...)

Jeff.
>    Having the backtrace should help answer question number 1.
> 3. How big is this process when it dies?
> 4. Do you have any sort of ulimit/rlimit set on dovecot in whatever startup
>    script you use?
> 5. Do you use cgroups to limit memory usage?
> 6. Did you disable memory overcommit on the system?
> 
> Jeff.
> 
> > Jan 23 14:23:13 mail dovecot: imap(bob at
tutech.de)<4880><PDqibHFjMvrAqG1n>:
> > Fatal: master: service(imap): child 4880 killed with signal 6 (core
dumped)
> > --- snip ---
> > 
> > The gdb backtrace is:
> > 
> > --- snip ---
> > GNU gdb (GDB) Red Hat Enterprise Linux (7.2-92.el6)
> > Copyright (C) 2010 Free Software Foundation, Inc.
> > License GPLv3+: GNU GPL version 3 or later
> > <http://gnu.org/licenses/gpl.html>
> > This is free software: you are free to change and redistribute it.
> > There is NO WARRANTY, to the extent permitted by law.  Type "show
copying"
> > and "show warranty" for details.
> > This GDB was configured as "x86_64-redhat-linux-gnu".
> > For bug reporting instructions, please see:
> > <http://www.gnu.org/software/gdb/bugs/>...
> > Reading symbols from /usr/libexec/dovecot/imap...(no debugging symbols
> > found)...done.
> > Attaching to program: /usr/libexec/dovecot/imap, process 4880
> > ptrace: Kein passender Prozess gefunden.
> > [New Thread 4880]
> > Reading symbols from /usr/lib64/dovecot/libdovecot-storage.so.0...(no
> > debugging symbols found)...done.
> > Loaded symbols for /usr/lib64/dovecot/libdovecot-storage.so.0
> > Reading symbols from /usr/lib64/dovecot/libdovecot.so.0...(no
debugging
> > symbols found)...done.
> > Loaded symbols for /usr/lib64/dovecot/libdovecot.so.0
> > Reading symbols from /lib64/libc.so.6...(no debugging symbols
found)...done.
> > Loaded symbols for /lib64/libc.so.6
> > Reading symbols from /lib64/librt.so.1...(no debugging symbols
> > found)...done.
> > Loaded symbols for /lib64/librt.so.1
> > Reading symbols from /lib64/libdl.so.2...(no debugging symbols
> > found)...done.
> > Loaded symbols for /lib64/libdl.so.2
> > Reading symbols from /lib64/ld-linux-x86-64.so.2...(no debugging
symbols
> > found)...done.
> > Loaded symbols for /lib64/ld-linux-x86-64.so.2
> > Reading symbols from /lib64/libpthread.so.0...(no debugging symbols
> > found)...done.
> > [Thread debugging using libthread_db enabled]
> > Loaded symbols for /lib64/libpthread.so.0
> > Reading symbols from /usr/lib64/dovecot/lib01_acl_plugin.so...(no
debugging
> > symbols found)...done.
> > Loaded symbols for /usr/lib64/dovecot/lib01_acl_plugin.so
> > Reading symbols from /usr/lib64/dovecot/lib02_imap_acl_plugin.so...(no
> > debugging symbols found)...done.
> > Loaded symbols for /usr/lib64/dovecot/lib02_imap_acl_plugin.so
> > Reading symbols from /usr/lib64/dovecot/lib15_notify_plugin.so...(no
> > debugging symbols found)...done.
> > Loaded symbols for /usr/lib64/dovecot/lib15_notify_plugin.so
> > Reading symbols from /usr/lib64/dovecot/lib20_mail_log_plugin.so...(no
> > debugging symbols found)...done.
> > Loaded symbols for /usr/lib64/dovecot/lib20_mail_log_plugin.so
> > Reading symbols from /usr/lib64/dovecot/lib20_zlib_plugin.so...(no
debugging
> > symbols found)...done.
> > Loaded symbols for /usr/lib64/dovecot/lib20_zlib_plugin.so
> > Reading symbols from /lib64/libz.so.1...(no debugging symbols
found)...done.
> > Loaded symbols for /lib64/libz.so.1
> > Reading symbols from /lib64/libbz2.so.1...(no debugging symbols
> > found)...done.
> > Loaded symbols for /lib64/libbz2.so.1
> > Reading symbols from
/usr/lib64/dovecot/lib30_imap_zlib_plugin.so...(no
> > debugging symbols found)...done.
> > Loaded symbols for /usr/lib64/dovecot/lib30_imap_zlib_plugin.so
> > Core was generated by `dovecot/imap'.
> > Program terminated with signal 6, Aborted.
> > #0  0x00007f73f1386495 in raise () from /lib64/libc.so.6
> > --- snip ---
> > 
> > I searched for that error message but only found some entries
regarding
> > older dovecot versions and setting "mail_process_size" but i
couldn't
> > find anything regarding Dovecot Version 2.3. Maybe it's something
that is
> > fixed already but if so i can't find it. Or is this a
configuration issue or
> > a bug?
> > 
> > Here my Dovecot configuration:
> > 
> > --- snip ---
> > # 2.3.0 (c8b89eb): /etc/dovecot/dovecot.conf
> > # Pigeonhole version 0.5.0.1 (d33dca20)
> > # OS: Linux 2.6.32-696.3.1.el6.x86_64 x86_64 CentOS release 6.9
(Final) ext4
> > auth_debug = yes
> > auth_debug_passwords = yes
> > auth_master_user_separator = *
> > auth_mechanisms = plain login
> > auth_verbose = yes
> > disable_plaintext_auth = no
> > doveadm_password =  # hidden, use -P to show it
> > doveadm_port = 12345
> > imap_max_line_length = 2 M
> > mail_debug = yes
> > mail_location = maildir:/export/home/imap/%Lu/Maildir
> > mail_plugins = acl zlib mail_log notify
> > mailbox_idle_check_interval = 10 secs
> > managesieve_notify_capability = mailto
> > managesieve_sieve_capability = fileinto reject envelope
encoded-character
> > vacation subaddress comparator-i;ascii-numeric relational regex
imap4flags
> > copy include variables body enotify environment mailbox date index
ihave
> > duplicate mime foreverypart extracttext
> > namespace {
> >   hidden = no
> >   ignore_on_failure = no
> >   inbox = no
> >   list = children
> >   location = maildir:%%h/Maildir:INDEXPVT=%h/shared/%%u
> >   prefix = shared/%%u/
> >   separator = /
> >   subscriptions = yes
> >   type = shared
> > }
> > namespace inbox {
> >   hidden = no
> >   inbox = yes
> >   list = yes
> >   location > >   mailbox Drafts {
> >     special_use = \Drafts
> >   }
> >   mailbox Junk {
> >     special_use = \Junk
> >   }
> >   mailbox Sent {
> >     special_use = \Sent
> >   }
> >   mailbox "Sent Messages" {
> >     special_use = \Sent
> >   }
> >   mailbox Trash {
> >     special_use = \Trash
> >   }
> >   prefix = INBOX/
> >   separator = /
> >   type = private
> > }
> > passdb {
> >   args = /etc/dovecot/master-users
> >   driver = passwd-file
> >   master = yes
> > }
> > passdb {
> >   args = /etc/dovecot/dovecot-ldap.conf.ext
> >   driver = ldap
> > }
> > plugin {
> >   acl = vfile:/etc/dovecot/global-acls:cache_secs=300
> >   acl_shared_dict = file:/export/home/shared-db/shared-mailboxes
> >   mail_log_events = append delete undelete expunge copy mailbox_delete
> > mailbox_rename flag_change
> >   mail_log_fields = uid box msgid size from flags
> >   mail_replica = tcp:mail2.tutech.de
> >   sieve = ~/.dovecot.sieve
> >   sieve_dir = ~/sieve
> >   sieve_global = /var/lib/dovecot/sieve/global/
> >   sieve_user_log = ~/.dovecot.sieve.log
> >   zlib_save = gz
> >   zlib_save_level = 6
> > }
> > protocols = imap pop3 lmtp sieve sieve
> > service aggregator {
> >   fifo_listener replication-notify-fifo {
> >     mode = 0666
> >     user = vmail
> >   }
> >   unix_listener replication-notify {
> >     mode = 0666
> >     user = vmail
> >   }
> > }
> > service auth {
> >   unix_listener /var/spool/postfix/private/auth {
> >     mode = 0666
> >   }
> >   unix_listener auth-userdb {
> >     group = vmail
> >     mode = 0660
> >     user = vmail
> >   }
> > }
> > service config {
> >   unix_listener config {
> >     user = vmail
> >   }
> > }
> > service doveadm {
> >   inet_listener {
> >     port = 12345
> >   }
> >   user = vmail
> > }
> > service imap-login {
> >   inet_listener imaps {
> >     port = 993
> >     ssl = yes
> >   }
> >   process_limit = 500
> >   process_min_avail = 20
> > }
> > service imap {
> >   executable = imap
> > }
> > service lmtp {
> >   inet_listener lmtp {
> >     address = 127.0.0.1
> >     port = 24
> >   }
> > }
> > service managesieve-login {
> >   inet_listener sieve {
> >     port = 4190
> >   }
> >   inet_listener sieve_deprecated {
> >     port = 2000
> >   }
> > }
> > service pop3-login {
> >   inet_listener pop3s {
> >     port = 995
> >     ssl = yes
> >   }
> > }
> > service pop3 {
> >   executable = pop3
> > }
> > service replicator {
> >   unix_listener replicator-doveadm {
> >     mode = 0666
> >   }
> > }
> > ssl = required
> > ssl_cert = </etc/pki/dovecot/certs/mail.tutech.de.crt_chain
> > ssl_cipher_list = ALL:!LOW:!SSLv2:!EXP:!aNULL:!EXPORT
> > ssl_dh =  # hidden, use -P to show it
> > ssl_key =  # hidden, use -P to show it
> > syslog_facility = local6
> > userdb {
> >   args = /etc/dovecot/dovecot-ldap-userdb.conf.ext
> >   driver = ldap
> > }
> > protocol lmtp {
> >   mail_plugins = acl zlib mail_log notify sieve
> > }
> > protocol imap {
> >   mail_max_userip_connections = 100
> >   mail_plugins = acl zlib mail_log notify imap_zlib imap_acl
> >   rawlog_dir = /tmp/rawlog/%u
> > }
> > --- snip ---
> > 
> > 
> > Thanks for the help!
> > 
> > Kind regards
> > Thomas
> > 
> 
> -- 
> Bad pun of the week: The formula 1 control computer suffered from a race
> condition
-- 
C is quirky, flawed, and an enormous success.
		- Dennis M. Ritchie.

Hi,

Am 23.01.2018 um 20:07 schrieb Josef 'Jeff'
Sipek:
> On Tue, Jan 23, 2018 at 14:03:27 -0500, Josef 'Jeff' Sipek wrote:
>> On Tue, Jan 23, 2018 at 18:21:38 +0100, Thomas Robers wrote:
>>> Hello,
>>>
>>> I'm using Dovecot 2.3 and sometimes i get this:
>>>
>>> --- snip ---
>>> Jan 23 14:23:13 mail dovecot: imap(bob at
tutech.de)<4880><PDqibHFjMvrAqG1n>:
>>> Panic: data stack: Out of memory when allocating 134217768 bytes
>>
>> Interesting... imap is trying to allocate 128MB and failing.  A couple
of
>> questions:
>>
>> 0. Does this user have any unusually large emails?
No, not usually but there are some mails which are larger than 15mb.
But that's not the normal size. Most e-mail are between some kb up to
5mb.

>> 1. Do you have any idea what the imap process was doing at the time of
the
>>     allocation failure?
Yes perhaps. We use shared mailboxes and at the time of failure the
imap process is reading acl files in a shared mailbox (and subfolder).
This shared mailbox has about 2800 subfolder and the acl files are read
in about 10sec and and during this reading the imap process dies with
the already mentioned error. It seems it has something to do with the
shared mailbox, because since yesterday morning 5 core dumps have been
created, 4 of them by one user accessing the shared mailbox and 1
by the user who is the owner of the shared mailbox. No other mailboxes
are affected until now.
>> 2. You snipped all the important parts of the back trace. :)  It
*starts* on
>>     the line:
>> 	#0  0x00007f73f1386495 in raise () from /lib64/libc.so.6
> 
> In case you haven't used gdb before...  after starting up gdb, run
"bt full"
> at the gdb prompt.  That'll print out a very detailed backtrace.  (You
might
> want to sanity check it to make sure there aren't any user passwords in
it
> before posting it here...)
Yes, sorry I'm not very familiar in using gdb, but here is the full
backtrace:

--- snip ---
(gdb) bt full
#0  0x00007f73f1386495 in raise () from /lib64/libc.so.6
No symbol table info available.
#1  0x00007f73f1387c75 in abort () from /lib64/libc.so.6
No symbol table info available.
#2  0x00007f73f17ab822 in ?? () from /usr/lib64/dovecot/libdovecot.so.0
No symbol table info available.
#3  0x00007f73f17abc18 in ?? () from /usr/lib64/dovecot/libdovecot.so.0
No symbol table info available.
#4  0x00007f73f17abdeb in t_malloc0 () from 
/usr/lib64/dovecot/libdovecot.so.0
No symbol table info available.
#5  0x00007f73f17a95dd in ?? () from /usr/lib64/dovecot/libdovecot.so.0
No symbol table info available.
#6  0x00007f73f17a967b in buffer_create_dynamic () from 
/usr/lib64/dovecot/libdovecot.so.0
No symbol table info available.
#7  0x00007f73f17a803b in backtrace_get () from 
/usr/lib64/dovecot/libdovecot.so.0
No symbol table info available.
#8  0x00007f73f17af1da in ?? () from /usr/lib64/dovecot/libdovecot.so.0
No symbol table info available.
#9  0x00007f73f17af766 in ?? () from /usr/lib64/dovecot/libdovecot.so.0
No symbol table info available.
#10 0x00007f73f1723e11 in i_panic () from /usr/lib64/dovecot/libdovecot.so.0
No symbol table info available.
#11 0x00007f73f17ab83a in ?? () from /usr/lib64/dovecot/libdovecot.so.0
No symbol table info available.
#12 0x00007f73f17abc18 in ?? () from /usr/lib64/dovecot/libdovecot.so.0
No symbol table info available.
#13 0x00007f73f17abd3b in t_buffer_get () from 
/usr/lib64/dovecot/libdovecot.so.0
No symbol table info available.
#14 0x00007f73f17e1d60 in vstrconcat () from 
/usr/lib64/dovecot/libdovecot.so.0
No symbol table info available.
#15 0x00007f73f17b7d03 in i_strconcat () from 
/usr/lib64/dovecot/libdovecot.so.0
No symbol table info available.
#16 0x00007f73f0b1fa39 in ?? () from /usr/lib64/dovecot/lib01_acl_plugin.so
No symbol table info available.
#17 0x00007f73f0b20740 in ?? () from /usr/lib64/dovecot/lib01_acl_plugin.so
No symbol table info available.
#18 0x00007f73f0b20b7d in acl_backend_vfile_acllist_rebuild () from 
/usr/lib64/dovecot/lib01_acl_plugin.so
No symbol table info available.
#19 0x00007f73f0b21569 in acl_backend_vfile_object_update () from 
/usr/lib64/dovecot/lib01_acl_plugin.so
No symbol table info available.
#20 0x00007f73f0b24bd8 in ?? () from /usr/lib64/dovecot/lib01_acl_plugin.so
No symbol table info available.
#21 0x00007f73f1aa1973 in mailbox_create () from 
/usr/lib64/dovecot/libdovecot-storage.so.0
No symbol table info available.
#22 0x00007f73f1fd1654 in cmd_create ()
No symbol table info available.
#23 0x00007f73f1fde585 in command_exec ()
No symbol table info available.
#24 0x00007f73f1fdb7b0 in ?? ()
No symbol table info available.
#25 0x00007f73f1fdb848 in ?? ()
No symbol table info available.
#26 0x00007f73f1fdbc35 in client_handle_input ()
No symbol table info available.
#27 0x00007f73f1fdc17e in client_input ()
No symbol table info available.
#28 0x00007f73f17c5ec5 in io_loop_call_io () from 
/usr/lib64/dovecot/libdovecot.so.0
No symbol table info available.
#29 0x00007f73f17c7dcf in io_loop_handler_run_internal () from 
/usr/lib64/dovecot/libdovecot.so.0
No symbol table info available.
#30 0x00007f73f17c5fb5 in io_loop_handler_run () from 
/usr/lib64/dovecot/libdovecot.so.0
No symbol table info available.
#31 0x00007f73f17c61d8 in io_loop_run () from 
/usr/lib64/dovecot/libdovecot.so.0
No symbol table info available.
#32 0x00007f73f1745ab3 in master_service_run () from 
/usr/lib64/dovecot/libdovecot.so.0
No symbol table info available.
#33 0x00007f73f1feacee in main ()
No symbol table info available.
-- snip ---
>>     Having the backtrace should help answer question number 1.
>> 3. How big is this process when it dies?
I don't know which imap process dies beforehand so how do i get this 
information?
>> 4. Do you have any sort of ulimit/rlimit set on dovecot in whatever
startup
>>     script you use?
The startup script sets no ulimits and ulimit -a shows this

--- snip ---
ulimit -a
core file size          (blocks, -c) unlimited
data seg size           (kbytes, -d) unlimited
scheduling priority             (-e) 0
file size               (blocks, -f) unlimited
pending signals                 (-i) 31380
max locked memory       (kbytes, -l) 64
max memory size         (kbytes, -m) unlimited
open files                      (-n) 8192
pipe size            (512 bytes, -p) 8
POSIX message queues     (bytes, -q) 819200
real-time priority              (-r) 0
stack size              (kbytes, -s) 10240
cpu time               (seconds, -t) unlimited
max user processes              (-u) 31380
virtual memory          (kbytes, -v) unlimited
file locks                      (-x) unlimited
--- snip ---

>> 5. Do you use cgroups to limit memory usage?
No.
>> 6. Did you disable memory overcommit on the system?
No, i didn't disable it.

-- snip ---
cat /proc/sys/vm/overcommit_memory
0
--- snip ---

>> Jeff.
Thomas.

On Wed, Jan 24, 2018 at 18:55:47 +0100, Thomas Robers
wrote:
> Am 23.01.2018 um 20:07 schrieb Josef 'Jeff' Sipek:
> > On Tue, Jan 23, 2018 at 14:03:27 -0500, Josef 'Jeff' Sipek
wrote:
> > > On Tue, Jan 23, 2018 at 18:21:38 +0100, Thomas Robers wrote:
...
> > > 1. Do you have any idea what the imap process was doing at the
time of the
> > >     allocation failure?
> 
> Yes perhaps. We use shared mailboxes and at the time of failure the
> imap process is reading acl files in a shared mailbox (and subfolder).
> This shared mailbox has about 2800 subfolder and the acl files are read
> in about 10sec and and during this reading the imap process dies with
> the already mentioned error. It seems it has something to do with the
> shared mailbox, because since yesterday morning 5 core dumps have been
> created, 4 of them by one user accessing the shared mailbox and 1
> by the user who is the owner of the shared mailbox. No other mailboxes
> are affected until now.
Based on the stack trace, the client was creating a new mailbox, which
caused an acl list rebuild, which ended up triggering this oddly sized
allocation.
> > > 2. You snipped all the important parts of the back trace. :)  It
*starts* on
> > >     the line:
> > > 	#0  0x00007f73f1386495 in raise () from /lib64/libc.so.6
> > 
> > In case you haven't used gdb before...  after starting up gdb, run
"bt full"
> > at the gdb prompt.  That'll print out a very detailed backtrace. 
(You might
> > want to sanity check it to make sure there aren't any user
passwords in it
> > before posting it here...)
> 
> Yes, sorry I'm not very familiar in using gdb, but here is the full
> backtrace:
It looks like the binaries are stripped.  There should be a "debug"
package
you can install with symbol information.  Then, the backtrace should be much
more helpful.
> > >     Having the backtrace should help answer question number 1.
> > > 3. How big is this process when it dies?
> 
> I don't know which imap process dies beforehand so how do i get this
> information?
The size of the core file will give you an general idea.  gdb can also print
out lots of info via "maintenance info sections", but I don't
think that'll
help figuring out why things blow up.

Jeff.

-- 
Keyboard not found!
Press F1 to enter Setup