Dovecot Imap-Proxy: openssl_iostream_handle_error

Urban Loesch bind at enas.net
Wed Mar 11 10:30:01 EET 2020


Hi,

I'm running Dovecot 2.3.9-2 as an IMAP/POP3 Proxy in front of several Dovecotbackends. No Director, only static routing to the backends of each user.
The proxies are also working as "SSL offload engines". SystemOS: Debian Stretch (9.11) on LXC Virtualization

Sometimes I get the following errors in mail.err log:

...
Mar 10 16:47:24 imap1 dovecot: imap-login: Panic: file iostream-openssl.c: line 599 (openssl_iostream_handle_error): assertion failed: (errno != 0)
Mar 10 16:47:24 imap1 dovecot: imap-login: Fatal: master: service(imap-login): child 30431 killed with signal 6 (core dumped)
Mar 10 16:47:38 imap1 dovecot: imap-login: Panic: file iostream-openssl.c: line 599 (openssl_iostream_handle_error): assertion failed: (errno != 0)
Mar 10 16:47:38 imap1 dovecot: imap-login: Fatal: master: service(imap-login): child 30471 killed with signal 6 (core dumped)
...

Full backtrace of the coredump:
...
# gdb /usr/lib/dovecot/imap-login core.imap-login.30471

GNU gdb (Debian 7.12-6) 7.12.0.20161007-git
Copyright (C) 2016 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-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /usr/lib/dovecot/imap-login...Reading symbols from /usr/lib/debug/.build-id/3c/24fcde9d366e5cfd7615cc42e013a060d092e5.debug...done.
done.
[New LWP 30471]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `dovecot/imap-login'.
Program terminated with signal SIGABRT, Aborted.
#0  __GI_raise (sig=sig at entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51

warning: Source file is more recent than executable.
51	}
(gdb) bt full
#0  __GI_raise (sig=sig at entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
         set = {__val = {0, 140427116827682, 140427117098374, 2147483649, 140427116658101, 0, 140427119440144, 140427116658101, 140427116658080, 
140427104016227, 140427119689728, 0, 140427104016288, 140427119440144, 18446744073709551615,
             0}}
         pid = <optimized out>
         tid = <optimized out>
#1  0x00007fb7bc5ba42a in __GI_abort () at abort.c:89
         save_stage = 2
         act = {__sigaction_handler = {sa_handler = 0x7fff75b21b30, sa_sigaction = 0x7fff75b21b30}, sa_mask = {__val = {0, 140427119702945, 
94861876544520, 140427119702945, 140427120378435, 140735167994944, 94861876544520,
               140427119702945, 6008397283549395712, 140427119702945, 94861876544520, 140735167994832, 140427101843879, 3, 5, 140427119702945}}, 
sa_flags = -1130359394, sa_restorer = 0x0}
         sigs = {__val = {32, 0 <repeats 15 times>}}
#2  0x00007fb7bca0c464 in default_fatal_finish (status=0, type=LOG_TYPE_PANIC) at failures.c:459
         backtrace = 0x5646c0a5ae4c ""
         recursed = 0
         recursed = 0
#3  fatal_handler_real (ctx=<optimized out>, format=<optimized out>, args=<optimized out>) at failures.c:471
         status = 0
#4  0x00007fb7bca0c551 in i_internal_fatal_handler (ctx=<optimized out>, format=<optimized out>, args=<optimized out>) at failures.c:848
No locals.
#5  0x00007fb7bc9622e3 in i_panic (format=format at entry=0x7fb7bb85ae70 "file %s: line %d (%s): assertion failed: (%s)") at failures.c:523
         ctx = {type = LOG_TYPE_PANIC, exit_status = 0, timestamp = 0x0, timestamp_usecs = 0, log_prefix = 0x0, log_prefix_type_pos = 0}
         args = {{gp_offset = 40, fp_offset = 48, overflow_arg_area = 0x7fff75b21d20, reg_save_area = 0x7fff75b21c60}}
#6  0x00007fb7bb858708 in openssl_iostream_handle_error (ssl_io=ssl_io at entry=0x5646c0a22aa0, ret=-1, 
type=type at entry=OPENSSL_IOSTREAM_SYNC_TYPE_HANDSHAKE, func_name=func_name at entry=0x7fb7bb85b1a7 "SSL_accept()") at iostream-openssl.c:599
         errstr = 0x0
         err = 5
         __func__ = "openssl_iostream_handle_error"
#7  0x00007fb7bb8588ea in openssl_iostream_handshake (ssl_io=0x5646c0a22aa0) at iostream-openssl.c:669
         reason = 0x53621d7edb623b00 <error: Cannot access memory at address 0x53621d7edb623b00>
         error = 0x0
         ret = <optimized out>
         __func__ = "openssl_iostream_handshake"
#8  0x00007fb7bb8583da in openssl_iostream_more (ssl_io=ssl_io at entry=0x5646c0a22aa0, type=type at entry=OPENSSL_IOSTREAM_SYNC_TYPE_HANDSHAKE) at 
iostream-openssl.c:546
         ret = <optimized out>
#9  0x00007fb7bb85a30f in i_stream_ssl_read_real (stream=stream at entry=0x5646c0a5b530) at istream-openssl.c:46
         sstream = 0x5646c0a5b530
         ssl_io = 0x5646c0a22aa0
         buffer = 
"\234y\345h\226#a\256*\v\216\024\215\250S\227\362\300\003\231\212\027\361\340\353vfv\206_\375\340\362\300\003\231\212\027\361\340\353vfv\206_\375\340kEt`6\005\235\273\205\365\211\366\bU\374\212kEt`6\005\235\273\205\365\211\366\bU\374\212ڿ\024\221\025\350\351\347\060\005\236}\377\250\266\340ڿ\024\221\025\350\351\347\060\005\236}\377\250\266\340\037p\275x8\334Iu~\215\257\255\322\310W\253\037p\275x8\334Iu~\215\257\255\322\310W\253\264\036N\350\375\f!\310\"\250\033\236%\214\223\242\264\036N\350\375\f!\310\"\250\033\236%\214\223\242\371\v\204\371\v\002\036u\355\324/\301FV\000\000\260\037\262u\377\177\000\000\224\261"...
         orig_max_buffer_size = 1026
         size = 10904244446682811178
         ret = <optimized out>
         total_ret = <optimized out>
         __func__ = "i_stream_ssl_read_real"
#10 0x00007fb7bb85a53e in i_stream_ssl_read (stream=0x5646c0a5b530) at istream-openssl.c:102
         sstream = 0x5646c0a5b530
         ret = <optimized out>
#11 0x00007fb7bca1a305 in i_stream_read_memarea (stream=stream at entry=0x5646c0a5b5b0) at istream.c:313
         old_size = 0
         ret = <optimized out>
         __func__ = "i_stream_read_memarea"
#12 0x00007fb7bca1a525 in i_stream_read (stream=0x5646c0a5b5b0) at istream.c:271
         _stream = 0x5646c0a5b530
         ret = <optimized out>
#13 0x00007fb7bccd2880 in client_read (client=0x5646c0a59940) at client-common.c:1079
No locals.
#14 0x00005646beb83ae3 in imap_client_input (client=<optimized out>) at imap-login-client.c:349
         imap_client = 0x5646c0a59940
#15 0x00007fb7bca260c5 in io_loop_call_io (io=0x5646c0a22c80) at ioloop.c:718
         ioloop = 0x5646c074ce10
         t_id = 2
         __func__ = "io_loop_call_io"
#16 0x00007fb7bca27afb in io_loop_handler_run_internal (ioloop=ioloop at entry=0x5646c074ce10) at ioloop-epoll.c:222
---Type <return> to continue, or q <return> to quit---
         ctx = 0x5646c074eaa0
         io = <optimized out>
         tv = {tv_sec = 0, tv_usec = 982536}
         events_count = <optimized out>
         msecs = <optimized out>
         ret = <optimized out>
         i = 0
         j = <optimized out>
         call = <optimized out>
         __func__ = "io_loop_handler_run_internal"
#17 0x00007fb7bca261d9 in io_loop_handler_run (ioloop=<optimized out>) at ioloop.c:770
No locals.
#18 0x00007fb7bca26408 in io_loop_run (ioloop=0x5646c074ce10) at ioloop.c:743
         __func__ = "io_loop_run"
#19 0x00007fb7bc993423 in master_service_run (service=0x5646c074cca0, callback=callback at entry=0x7fb7bccd7d10 <client_connected>) at master-service.c:809
No locals.
#20 0x00007fb7bccd8541 in login_binary_run (binary=<optimized out>, argc=<optimized out>, argv=<optimized out>) at main.c:560
         set_pool = 0x5646c0752d10
         login_socket = 0x7fb7bccdbfc9 "login"
         c = <optimized out>
#21 0x00007fb7bc5a62e1 in __libc_start_main (main=0x5646beb832f0 <main>, argc=1, argv=0x7fff75b241c8, init=<optimized out>, fini=<optimized out>, 
rtld_fini=<optimized out>, stack_end=0x7fff75b241b8) at ../csu/libc-start.c:291
         result = <optimized out>
         unwind_buf = {cancel_jmp_buf = {{jmp_buf = {0, -6899649731693310855, 94861847442192, 140735168004544, 0, 0, -915335683310285703, 
-874401070412002183}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x7fff75b241d8,
               0x7fb7bd106170}, data = {prev = 0x0, cleanup = 0x0, canceltype = 1974616536}}}
         not_first_call = <optimized out>
#22 0x00005646beb8333a in _start ()
No symbol table info available.
...

....
(gdb) bt
#0  __GI_raise (sig=sig at entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
#1  0x00007fb7bc5ba42a in __GI_abort () at abort.c:89
#2  0x00007fb7bca0c464 in default_fatal_finish (status=0, type=LOG_TYPE_PANIC) at failures.c:459
#3  fatal_handler_real (ctx=<optimized out>, format=<optimized out>, args=<optimized out>) at failures.c:471
#4  0x00007fb7bca0c551 in i_internal_fatal_handler (ctx=<optimized out>, format=<optimized out>, args=<optimized out>) at failures.c:848
#5  0x00007fb7bc9622e3 in i_panic (format=format at entry=0x7fb7bb85ae70 "file %s: line %d (%s): assertion failed: (%s)") at failures.c:523
#6  0x00007fb7bb858708 in openssl_iostream_handle_error (ssl_io=ssl_io at entry=0x5646c0a22aa0, ret=-1, 
type=type at entry=OPENSSL_IOSTREAM_SYNC_TYPE_HANDSHAKE, func_name=func_name at entry=0x7fb7bb85b1a7 "SSL_accept()") at iostream-openssl.c:599
#7  0x00007fb7bb8588ea in openssl_iostream_handshake (ssl_io=0x5646c0a22aa0) at iostream-openssl.c:669
#8  0x00007fb7bb8583da in openssl_iostream_more (ssl_io=ssl_io at entry=0x5646c0a22aa0, type=type at entry=OPENSSL_IOSTREAM_SYNC_TYPE_HANDSHAKE) at 
iostream-openssl.c:546
#9  0x00007fb7bb85a30f in i_stream_ssl_read_real (stream=stream at entry=0x5646c0a5b530) at istream-openssl.c:46
#10 0x00007fb7bb85a53e in i_stream_ssl_read (stream=0x5646c0a5b530) at istream-openssl.c:102
#11 0x00007fb7bca1a305 in i_stream_read_memarea (stream=stream at entry=0x5646c0a5b5b0) at istream.c:313
#12 0x00007fb7bca1a525 in i_stream_read (stream=0x5646c0a5b5b0) at istream.c:271
#13 0x00007fb7bccd2880 in client_read (client=0x5646c0a59940) at client-common.c:1079
#14 0x00005646beb83ae3 in imap_client_input (client=<optimized out>) at imap-login-client.c:349
#15 0x00007fb7bca260c5 in io_loop_call_io (io=0x5646c0a22c80) at ioloop.c:718
#16 0x00007fb7bca27afb in io_loop_handler_run_internal (ioloop=ioloop at entry=0x5646c074ce10) at ioloop-epoll.c:222
#17 0x00007fb7bca261d9 in io_loop_handler_run (ioloop=<optimized out>) at ioloop.c:770
#18 0x00007fb7bca26408 in io_loop_run (ioloop=0x5646c074ce10) at ioloop.c:743
#19 0x00007fb7bc993423 in master_service_run (service=0x5646c074cca0, callback=callback at entry=0x7fb7bccd7d10 <client_connected>) at master-service.c:809
#20 0x00007fb7bccd8541 in login_binary_run (binary=<optimized out>, argc=<optimized out>, argv=<optimized out>) at main.c:560
#21 0x00007fb7bc5a62e1 in __libc_start_main (main=0x5646beb832f0 <main>, argc=1, argv=0x7fff75b241c8, init=<optimized out>, fini=<optimized out>, 
rtld_fini=<optimized out>, stack_end=0x7fff75b241b8) at ../csu/libc-start.c:291
#22 0x00005646beb8333a in _start ()
.....


I hope this is correct, fact that I'm not very experienced with coreudmps and the debug-process of it.

Many thanks
Urban Loesch


More information about the dovecot mailing list