On 2017-05-01 19:34, Aki Tuomi wrote:

...

On May 1, 2017 at 8:26 PM Aki Tuomi <aki.tuomi@dovecot.fi> wrote:

...

On May 1, 2017 at 8:21 PM Tom Sommer <mail@tomsommer.dk> wrote:

I just upgraded our Director to 2.2.29.1 from 2.2.26, and now my dmesg and /var/log/messages are getting flooded by these errors:

lmtp[45758]: segfault at 21 ip 00007fb412d3ad11 sp 00007ffe83ad2df0 error 4 in libdovecot.so.0.0.0[7fb412c95000+11c000]

Any ideas?

-- Tom

Try get a core dump and run it thru gdb.

Aki

Also, dovecot should log some kind of trace and message into syslog or whatever log_path points to.

Only this:

May 02 09:00:34 lmtp(17467): Fatal: master: service(lmtp): child 17467 killed with signal 11 (core dumps disabled)

.. and lots of them.

On 2017-05-01 19:26, Aki Tuomi wrote:

...

On May 1, 2017 at 8:21 PM Tom Sommer <mail@tomsommer.dk> wrote:

I just upgraded our Director to 2.2.29.1 from 2.2.26, and now my dmesg and /var/log/messages are getting flooded by these errors:

lmtp[45758]: segfault at 21 ip 00007fb412d3ad11 sp 00007ffe83ad2df0 error 4 in libdovecot.so.0.0.0[7fb412c95000+11c000]

Any ideas?

-- Tom

Try get a core dump and run it thru gdb.

[root@director1 dovecot]# gdb /usr/libexec/dovecot/lmtp core.19749 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/lmtp...done. [New Thread 19749] Reading symbols from /usr/lib/dovecot/libdovecot-lda.so.0...done. Loaded symbols for /usr/lib/dovecot/libdovecot-lda.so.0 Reading symbols from /usr/lib/dovecot/libdovecot-storage.so.0...done. Loaded symbols for /usr/lib/dovecot/libdovecot-storage.so.0 Reading symbols from /usr/lib/dovecot/libdovecot.so.0...done. Loaded symbols for /usr/lib/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/lib/dovecot/libssl_iostream_openssl.so...done. Loaded symbols for /usr/lib/dovecot/libssl_iostream_openssl.so Reading symbols from /usr/lib64/libssl.so.10...(no debugging symbols found)...done. Loaded symbols for /usr/lib64/libssl.so.10 Reading symbols from /usr/lib64/libcrypto.so.10...(no debugging symbols found)...done. Loaded symbols for /usr/lib64/libcrypto.so.10 Reading symbols from /lib64/libgssapi_krb5.so.2...(no debugging symbols found)...done. Loaded symbols for /lib64/libgssapi_krb5.so.2 Reading symbols from /lib64/libkrb5.so.3...(no debugging symbols found)...done. Loaded symbols for /lib64/libkrb5.so.3 Reading symbols from /lib64/libcom_err.so.2...(no debugging symbols found)...done. Loaded symbols for /lib64/libcom_err.so.2 Reading symbols from /lib64/libk5crypto.so.3...(no debugging symbols found)...done. Loaded symbols for /lib64/libk5crypto.so.3 Reading symbols from /lib64/libz.so.1...(no debugging symbols found)...done. Loaded symbols for /lib64/libz.so.1 Reading symbols from /lib64/libkrb5support.so.0...(no debugging symbols found)...done. Loaded symbols for /lib64/libkrb5support.so.0 Reading symbols from /lib64/libkeyutils.so.1...(no debugging symbols found)...done. Loaded symbols for /lib64/libkeyutils.so.1 Reading symbols from /lib64/libresolv.so.2...(no debugging symbols found)...done. Loaded symbols for /lib64/libresolv.so.2 Reading symbols from /lib64/libselinux.so.1...(no debugging symbols found)...done. Loaded symbols for /lib64/libselinux.so.1 Core was generated by `dovecot/lmtp'. Program terminated with signal 11, Segmentation fault. #0 i_stream_seek (stream=0x21, v_offset=0) at istream.c:298 298 if (v_offset >= stream->v_offset && Missing separate debuginfos, use: debuginfo-install glibc-2.12-1.209.el6_9.1.x86_64 keyutils-libs-1.4-5.el6.x86_64 krb5-libs-1.10.3-65.el6.x86_64 libcom_err-1.41.12-23.el6.x86_64 libselinux-2.0.94-7.el6.x86_64 openssl-1.0.1e-57.el6.x86_64 zlib-1.2.3-29.el6.x86_64

On 2017-05-02 09:35, Aki Tuomi wrote:

On 2017-05-02 10:20, Tom Sommer wrote:

...

On 2017-05-01 19:26, Aki Tuomi wrote:

...

...

On May 1, 2017 at 8:21 PM Tom Sommer <mail@tomsommer.dk> wrote:

I just upgraded our Director to 2.2.29.1 from 2.2.26, and now my dmesg and /var/log/messages are getting flooded by these errors:

lmtp[45758]: segfault at 21 ip 00007fb412d3ad11 sp 00007ffe83ad2df0 error 4 in libdovecot.so.0.0.0[7fb412c95000+11c000]

Any ideas?

-- Tom

Try get a core dump and run it thru gdb.

[root@director1 dovecot]# gdb /usr/libexec/dovecot/lmtp core.19749 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/lmtp...done. [New Thread 19749] Reading symbols from /usr/lib/dovecot/libdovecot-lda.so.0...done. Loaded symbols for /usr/lib/dovecot/libdovecot-lda.so.0 Reading symbols from /usr/lib/dovecot/libdovecot-storage.so.0...done. Loaded symbols for /usr/lib/dovecot/libdovecot-storage.so.0 Reading symbols from /usr/lib/dovecot/libdovecot.so.0...done. Loaded symbols for /usr/lib/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/lib/dovecot/libssl_iostream_openssl.so...done. Loaded symbols for /usr/lib/dovecot/libssl_iostream_openssl.so Reading symbols from /usr/lib64/libssl.so.10...(no debugging symbols found)...done. Loaded symbols for /usr/lib64/libssl.so.10 Reading symbols from /usr/lib64/libcrypto.so.10...(no debugging symbols found)...done. Loaded symbols for /usr/lib64/libcrypto.so.10 Reading symbols from /lib64/libgssapi_krb5.so.2...(no debugging symbols found)...done. Loaded symbols for /lib64/libgssapi_krb5.so.2 Reading symbols from /lib64/libkrb5.so.3...(no debugging symbols found)...done. Loaded symbols for /lib64/libkrb5.so.3 Reading symbols from /lib64/libcom_err.so.2...(no debugging symbols found)...done. Loaded symbols for /lib64/libcom_err.so.2 Reading symbols from /lib64/libk5crypto.so.3...(no debugging symbols found)...done. Loaded symbols for /lib64/libk5crypto.so.3 Reading symbols from /lib64/libz.so.1...(no debugging symbols found)...done. Loaded symbols for /lib64/libz.so.1 Reading symbols from /lib64/libkrb5support.so.0...(no debugging symbols found)...done. Loaded symbols for /lib64/libkrb5support.so.0 Reading symbols from /lib64/libkeyutils.so.1...(no debugging symbols found)...done. Loaded symbols for /lib64/libkeyutils.so.1 Reading symbols from /lib64/libresolv.so.2...(no debugging symbols found)...done. Loaded symbols for /lib64/libresolv.so.2 Reading symbols from /lib64/libselinux.so.1...(no debugging symbols found)...done. Loaded symbols for /lib64/libselinux.so.1 Core was generated by `dovecot/lmtp'. Program terminated with signal 11, Segmentation fault. #0 i_stream_seek (stream=0x21, v_offset=0) at istream.c:298 298 if (v_offset >= stream->v_offset && Missing separate debuginfos, use: debuginfo-install glibc-2.12-1.209.el6_9.1.x86_64 keyutils-libs-1.4-5.el6.x86_64 krb5-libs-1.10.3-65.el6.x86_64 libcom_err-1.41.12-23.el6.x86_64 libselinux-2.0.94-7.el6.x86_64 openssl-1.0.1e-57.el6.x86_64 zlib-1.2.3-29.el6.x86_64 Can you run bt full please?

(gdb) bt full #0 i_stream_seek (stream=0x21, v_offset=0) at istream.c:298 _stream = <value optimized out> #1 0x00007fe98391ff32 in i_stream_concat_read_next (stream=0x1efe6c0) at istream-concat.c:77 prev_input = 0x1ef1560 data = 0x0 data_size = <value optimized out> size = <value optimized out> #2 i_stream_concat_read (stream=0x1efe6c0) at istream-concat.c:175 cstream = 0x1efe6c0 data = 0x0 size = <value optimized out> data_size = 0 cur_data_pos = <value optimized out> new_pos = <value optimized out> new_bytes_count = <value optimized out> ret = <value optimized out> last_stream = <value optimized out> __FUNCTION__ = "i_stream_concat_read" #3 0x00007fe98391d1f5 in i_stream_read (stream=0x1efe730) at istream.c:174 _stream = 0x1efe6c0 old_size = 0 ret = <value optimized out> __FUNCTION__ = "i_stream_read" #4 0x00007fe983924156 in i_stream_sized_parent_read (stream=0x1efb2d0, pos_r=0x7ffc6a3e2d28) at istream-sized.c:54 ret = <value optimized out> #5 0x00007fe9839243db in i_stream_sized_read (stream=0x1efb2d0) at istream-sized.c:84 sstream = 0x1efb2d0 data = {v_offset = 32486208, new_bytes = 140722090946024, wanted_size = 0, eof = 132} error = <value optimized out> left = <value optimized out> ret = <value optimized out> pos = 0 __FUNCTION__ = "i_stream_sized_read" #6 0x00007fe98391d1f5 in i_stream_read (stream=0x1efb340) at istream.c:174 _stream = 0x1efb2d0 old_size = 0 ret = <value optimized out> __FUNCTION__ = "i_stream_read" #7 0x00007fe98391d5d2 in i_stream_read_data (stream=0x1efb340, data_r=0x7ffc6a3e2df0, size_r=0x7ffc6a3e2de8, threshold=0) at istream.c:569 ret = <value optimized out> read_more = false __FUNCTION__ = "i_stream_read_data" #8 0x00007fe9838e6ca4 in lmtp_client_send_data (client=0x1eefb78) at lmtp-client.c:333 data = 0x0 add = 0 '\000' i = <value optimized out> size = 0 sent_bytes = false ret = <value optimized out> #9 0x00007fe9838e7045 in lmtp_client_output (client=0x1eefb78) at lmtp-client.c:662 ret = 1 #10 0x00007fe983934769 in stream_send_io (fstream=0x1eee9a0) at ostream-file.c:473 ostream = 0x1eeea30 ret = <value optimized out> #11 0x00007fe983925df1 in io_loop_call_io (io=0x1eee0a0) at ioloop.c:599 ioloop = 0x1e909b0 t_id = 2 __FUNCTION__ = "io_loop_call_io" #12 0x00007fe9839279bf in io_loop_handler_run_internal (ioloop=<value optimized out>) at ioloop-epoll.c:223 ctx = 0x1e96620 events = <value optimized out> event = 0x1e97490 ---Type <return> to continue, or q <return> to quit--- list = 0x1ef17b0 io = <value optimized out> tv = {tv_sec = 124, tv_usec = 850269} events_count = <value optimized out> msecs = <value optimized out> ret = 1 i = <value optimized out> call = <value optimized out> __FUNCTION__ = "io_loop_handler_run_internal" #13 0x00007fe983925eac in io_loop_handler_run (ioloop=0x1e909b0) at ioloop.c:648 No locals. #14 0x00007fe983926058 in io_loop_run (ioloop=0x1e909b0) at ioloop.c:623 __FUNCTION__ = "io_loop_run" #15 0x00007fe9838aff93 in master_service_run (service=0x1e90850, callback=<value optimized out>) at master-service.c:641 No locals. #16 0x0000000000404f5f in main (argc=1, argv=0x1e905f0) at main.c:127 set_roots = {0x60bd40, 0x40a700, 0x0} service_flags = <value optimized out> storage_service_flags = 675 c = <value optimized out>

On 2 May 2017, at 10.41, Tom Sommer <mail@tomsommer.dk> wrote:

(gdb) bt full #0 i_stream_seek (stream=0x21, v_offset=0) at istream.c:298 _stream = <value optimized out> #1 0x00007fe98391ff32 in i_stream_concat_read_next (stream=0x1efe6c0) at istream-concat.c:77 prev_input = 0x1ef1560 data = 0x0 data_size = <value optimized out> size = <value optimized out> #2 i_stream_concat_read (stream=0x1efe6c0) at istream-concat.c:175

This isn't very obvious.. There hasn't been any changes to istream-concat code in 2.2.29 and I can't really think of any other changes either that could be causing these crashes. Do these crashes happen to all mail deliveries or only some (any idea of percentage)? Maybe only for deliveries that have multiple recipients (in different backends)? We'll try to reproduce, but I'd think someone else would have already noticed/complained if it was that badly broken..

What's your doveconf -n? Also can you try running via valgrind to see what it logs before the crash? :

service lmtp { executable = /usr/bin/valgrind --vgdb=no -q /usr/libexec/dovecot/lmtp # or whatever the lmtp path really is }

On 2017-05-18 09:36, Teemu Huovila wrote:

Hello Tom

On 02.05.2017 11:19, Timo Sirainen wrote:

...

On 2 May 2017, at 10.41, Tom Sommer <mail@tomsommer.dk> wrote:

...

(gdb) bt full #0 i_stream_seek (stream=0x21, v_offset=0) at istream.c:298 _stream = <value optimized out> #1 0x00007fe98391ff32 in i_stream_concat_read_next (stream=0x1efe6c0) at istream-concat.c:77 prev_input = 0x1ef1560 data = 0x0 data_size = <value optimized out> size = <value optimized out> #2 i_stream_concat_read (stream=0x1efe6c0) at istream-concat.c:175

This isn't very obvious.. There hasn't been any changes to istream-concat code in 2.2.29 and I can't really think of any other changes either that could be causing these crashes. Do these crashes happen to all mail deliveries or only some (any idea of percentage)? Maybe only for deliveries that have multiple recipients (in different backends)? We'll try to reproduce, but I'd think someone else would have already noticed/complained if it was that badly broken..

What's your doveconf -n? Also can you try running via valgrind to see what it logs before the crash? :

service lmtp { executable = /usr/bin/valgrind --vgdb=no -q /usr/libexec/dovecot/lmtp # or whatever the lmtp path really is }

As this is not easily reproducible with a common lmtp proxying configuration, we would be interested in the doveconf -n output from all involved nodes (proxy, director, backend).

Did you have a chance to try the valgrind wrapper adviced by Timo?

Timo already fixed this?

https://github.com/dovecot/core/commit/167dbb662c2ddedeb7b34383c18bdcf0537c0...

Tom

On 18.05.2017 10:55, Tom Sommer wrote:

On 2017-05-18 09:36, Teemu Huovila wrote:

...

Hello Tom

On 02.05.2017 11:19, Timo Sirainen wrote:

...

On 2 May 2017, at 10.41, Tom Sommer <mail@tomsommer.dk> wrote:

...

(gdb) bt full #0 i_stream_seek (stream=0x21, v_offset=0) at istream.c:298 _stream = <value optimized out> #1 0x00007fe98391ff32 in i_stream_concat_read_next (stream=0x1efe6c0) at istream-concat.c:77 prev_input = 0x1ef1560 data = 0x0 data_size = <value optimized out> size = <value optimized out> #2 i_stream_concat_read (stream=0x1efe6c0) at istream-concat.c:175

This isn't very obvious.. There hasn't been any changes to istream-concat code in 2.2.29 and I can't really think of any other changes either that could be causing these crashes. Do these crashes happen to all mail deliveries or only some (any idea of percentage)? Maybe only for deliveries that have multiple recipients (in different backends)? We'll try to reproduce, but I'd think someone else would have already noticed/complained if it was that badly broken..

What's your doveconf -n? Also can you try running via valgrind to see what it logs before the crash? :

service lmtp { executable = /usr/bin/valgrind --vgdb=no -q /usr/libexec/dovecot/lmtp # or whatever the lmtp path really is }

As this is not easily reproducible with a common lmtp proxying configuration, we would be interested in the doveconf -n output from all involved nodes (proxy, director, backend).

Did you have a chance to try the valgrind wrapper adviced by Timo?

Timo already fixed this? I think?

https://github.com/dovecot/core/commit/167dbb662c2ddedeb7b34383c18bdcf0537c0... The commit in question fixes an asser failure. The issue you reported is an invalid memory access. The commit was not intended to fix your report. Has the crash stopped happening in your environment?

br, Teemu

---

Tom

On 18.05.2017 11:56, Tom Sommer wrote:

---

Tom

On 2017-05-18 10:05, Teemu Huovila wrote:

...

On 18.05.2017 10:55, Tom Sommer wrote:

...

On 2017-05-18 09:36, Teemu Huovila wrote:

...

Hello Tom

On 02.05.2017 11:19, Timo Sirainen wrote:

...

On 2 May 2017, at 10.41, Tom Sommer <mail@tomsommer.dk> wrote:

...

(gdb) bt full #0 i_stream_seek (stream=0x21, v_offset=0) at istream.c:298 _stream = <value optimized out> #1 0x00007fe98391ff32 in i_stream_concat_read_next (stream=0x1efe6c0) at istream-concat.c:77 prev_input = 0x1ef1560 data = 0x0 data_size = <value optimized out> size = <value optimized out> #2 i_stream_concat_read (stream=0x1efe6c0) at istream-concat.c:175

This isn't very obvious.. There hasn't been any changes to istream-concat code in 2.2.29 and I can't really think of any other changes either that could be causing these crashes. Do these crashes happen to all mail deliveries or only some (any idea of percentage)? Maybe only for deliveries that have multiple recipients (in different backends)? We'll try to reproduce, but I'd think someone else would have already noticed/complained if it was that badly broken..

What's your doveconf -n? Also can you try running via valgrind to see what it logs before the crash? :

service lmtp { executable = /usr/bin/valgrind --vgdb=no -q /usr/libexec/dovecot/lmtp # or whatever the lmtp path really is }

As this is not easily reproducible with a common lmtp proxying configuration, we would be interested in the doveconf -n output from all involved nodes (proxy, director, backend).

Did you have a chance to try the valgrind wrapper adviced by Timo?

Timo already fixed this? I think?

https://github.com/dovecot/core/commit/167dbb662c2ddedeb7b34383c18bdcf0537c0... The commit in question fixes an asser failure. The issue you reported is an invalid memory access. The commit was not intended to fix your report. Has the crash stopped happening in your environment?

Well, I downgraded to 2.2.26 and haven't looked at 2.2.29 since. So I guess it's not fixed.

I'll give it another look with valgrind.

Please, also send the doveconf -n output for proxy, director and backend.

br, Teemu

// Tom

On 2017-05-19 08:41, Timo Sirainen wrote:

On 2 May 2017, at 11.19, Timo Sirainen <tss@iki.fi> wrote:

On 2 May 2017, at 10.41, Tom Sommer <mail@tomsommer.dk> wrote:

(gdb) bt full #0 i_stream_seek (stream=0x21, v_offset=0) at istream.c:298 _stream = <value optimized out> #1 0x00007fe98391ff32 in i_stream_concat_read_next (stream=0x1efe6c0) at istream-concat.c:77 prev_input = 0x1ef1560 data = 0x0 data_size = <value optimized out> size = <value optimized out> #2 i_stream_concat_read (stream=0x1efe6c0) at istream-concat.c:175 This isn't very obvious.. There hasn't been any changes to istream-concat code in 2.2.29 and I can't really think of any other changes either that could be causing these crashes. Do these crashes happen to all mail deliveries or only some (any idea of percentage)? Maybe only for deliveries that have multiple recipients (in different backends)? We'll try to reproduce, but I'd think someone else would have already noticed/complained if it was that badly broken..

What's your doveconf -n? Also can you try running via valgrind to see what it logs before the crash? :

service lmtp { executable = /usr/bin/valgrind --vgdb=no -q /usr/libexec/dovecot/lmtp # or whatever the lmtp path really is }

I don't really know why this started happening with you now, but it should be fixed by https://github.com/dovecot/core/commit/16b5dc27e7db42849510403d37e3629aba14d...

Somehow I always end up being hit by the weirdest bugs :)

Thank you for the fix.

Any chance of a 2.2.30 with this included? :)