I've managed to re-compile the alpine packages inside the container, creating the debug symbols and disabling compile time optimizations, as they also disturbed the backtrace. The following output looks much more meaningful. But unfortunately there are still some symbols missing for lucene-core. Let me know if this is enough to work with. (It doesn't seem to be musl after all?) Reading symbols from /usr/libexec/dovecot/indexer-worker...Reading symbols from /usr/lib/debug//usr/libexec/dovecot/indexer-worker.debug...done. done. [New LWP 30417] warning: Can't read pathname for load map: No error information. Core was generated by `dovecot/indexer-worker'. Program terminated with signal SIGSEGV, Segmentation fault. #0  0x00007f1653f12c31 in ?? () from /usr/lib/libclucene-core.so.1 (gdb) bt full #0  0x00007f1653f12c31 in ?? () from /usr/lib/libclucene-core.so.1 No symbol table info available. #1  0x00007f1653edeba2 in lucene::index::KeepOnlyLastCommitDeletionPolicy::onCommit(std::vectorlucene::index::IndexCommitPoint* >&) ()    from /usr/lib/libclucene-core.so.1 No symbol table info available. #2  0x00007f1653f15312 in ?? () from /usr/lib/libclucene-core.so.1 No symbol table info available. #3  0x00007f1653f325e3 in lucene::index::IndexWriter::doFlush(bool) () from /usr/lib/libclucene-core.so.1 No symbol table info available. #4  0x00007f1653f32f9c in lucene::index::IndexWriter::flush(bool, bool) () from /usr/lib/libclucene-core.so.1 No symbol table info available. #5  0x00007f1653f33052 in lucene::index::IndexWriter::closeInternal(bool) () from /usr/lib/libclucene-core.so.1 No symbol table info available. #6  0x00007f1653f337c4 in lucene::index::IndexWriter::close(bool) () from /usr/lib/libclucene-core.so.1 No symbol table info available. #7  0x00007f16541fc8c6 in lucene_index_build_deinit (index=0x55945fe7a860) at lucene-wrapper.cc:646         ret = 0 #8  0x00007f16541f9ba4 in fts_backend_lucene_update_deinit (_ctx=0x55945fe910a0) at fts-backend-lucene.c:259         ctx = 0x55945fe910a0         backend = 0x55945fe7a760         ret = 0         __func__ = "fts_backend_lucene_update_deinit" #9  0x00007f1654649baa in fts_backend_update_deinit (_ctx=0x55945fe7a480) at fts-api.c:144         ctx = 0x55945fe910a0         backend = 0x55945fe7a760         ret = 0 #10 0x00007f1654655d83 in fts_transaction_end (t=0x55945fe88820, error_r=0x7fff1b28d1b8) at fts-storage.c:613         ft = 0x55945fe84400         flist = 0x55945fe7a3a0         ret = 0         __func__ = "fts_transaction_end" #11 0x00007f16546562e8 in fts_transaction_commit (t=0x55945fe88820, changes_r=0x7fff1b28d2c0) at fts-storage.c:696         ft = 0x55945fe84400 --Type <RET> for more, q to quit, c to continue without paging--c         fbox = 0x55945fe7f798         box = 0x55945fe7efa8         autoindex = false         ret = 0         error = 0x7f1654813665 "H\213E\350\353\067\213E\344\211\302H\213E\330H\211\326H\211\307\350\301\367\377\377H\211E\360\213E\344\203\350\001\211\302H\213M\350H\213E\360H\211\316H\211\307\350\302\357\354\377H\213E\360H\213M\370dH3\f%(" #12 0x00007f165469b83e in quota_mailbox_transaction_commit (ctx=0x55945fe88820, changes_r=0x7fff1b28d2c0) at quota-storage.c:174         qbox = 0x55945fe7f600         qt = 0x55945fe8f160         __func__ = "quota_mailbox_transaction_commit" #13 0x00007f16548fefad in mailbox_transaction_commit_get_changes (_t=0x7fff1b28d348, changes_r=0x7fff1b28d2c0) at mail-storage.c:2215         _data_stack_cur_id = 4         t = 0x55945fe88820         box = 0x55945fe7efa8         save_count = 0         ret = 21908         __func__ = "mailbox_transaction_commit_get_changes" #14 0x00007f16548feefc in mailbox_transaction_commit (t=0x7fff1b28d348) at mail-storage.c:2197         changes = {pool = 0x0, uid_validity = 1418718114, saved_uids = {arr = {buffer = 0x7f16548e5d9e <__x86_return_thunk+5>, element_size = 140733649048408}, v = 0x7f16548e5d9e <__x86_return_thunk+5>, v_modifiable = 0x7f16548e5d9e <__x86_return_thunk+5>}, ignored_modseq_changes = 455660384, changes_mask = (unknown: 0), no_read_perm = false}         ret = 21908 #15 0x000055945e4abdcb in index_mailbox_precache (conn=0x55945fe57440, box=0x55945fe7efa8) at master-connection.c:126         storage = 0x55945fe77f28         username = 0x55945fe73ee0 "admin@usrpro.io"         box_vname = 0x55945fe7f310 "Sent"         errstr = 0x7f165469cb53 "\213E\344H\203\304([]\351\320f\377\377UH\211\345H\203\354\060H\211}\330dH\213\004%("         error = MAIL_ERROR_TEMP         status = {messages = 10, recent = 0, unseen = 0, uidvalidity = 1545140227, uidnext = 11, first_unseen_seq = 0, first_recent_uid = 3, last_cached_seq = 1, highest_modseq = 0, highest_pvt_modseq = 0, keywords = 0x0, permanent_flags = 0, flags = 0, permanent_keywords = false, allow_new_keywords = false, nonpermanent_modseqs = false, no_modseq_tracking = false, have_guids = true, have_save_guids = true, have_only_guid128 = false}         trans = 0x0         search_args = 0x0         ctx = 0x0         mail = 0x0         metadata = {guid = '\000' , virtual_size = 0, physical_size = 0, first_save_date = 0, cache_fields = 0x0, precache_fields = (MAIL_FETCH_STREAM_HEADER | MAIL_FETCH_STREAM_BODY | MAIL_FETCH_RECEIVED_DATE | MAIL_FETCH_SAVE_DATE | MAIL_FETCH_PHYSICAL_SIZE | MAIL_FETCH_VIRTUAL_SIZE | MAIL_FETCH_UIDL_BACKEND | MAIL_FETCH_GUID | MAIL_FETCH_POP3_ORDER), backend_ns_prefix = 0x0, backend_ns_type = (unknown: 0)}         seq = 2         first_uid = 2         last_uid = 10         percentage_str = "\026\177\000"         counter = 9         max = 9         percentage = 32534         percentage_sent = 0         ret = 0         uids = 0x55945fe48938 " (UIDs 2..10)" #16 0x000055945e4ac1c1 in index_mailbox (conn=0x55945fe57440, user=0x55945fe73dc8, mailbox=0x55945fe46058 "Sent", max_recent_msgs=0, what=0x55945fe46070 "i") at master-connection.c:205         ns = 0x55945fe77da0         box = 0x55945fe7efa8         status = {messages = 1608873868, recent = 0, unseen = 1581972288, uidvalidity = 21908, uidnext = 455660880, first_unseen_seq = 32767, first_recent_uid = 1608810272, last_cached_seq = 21908, highest_modseq = 139733882519610, highest_pvt_modseq = 94095725476155, keywords = 0x7fff1b28d540, permanent_flags = 0, flags = 0, permanent_keywords = false, allow_new_keywords = false, nonpermanent_modseqs = false, no_modseq_tracking = true, have_guids = true, have_save_guids = false, have_only_guid128 = true}         path = 0x55945fe47f38 "/mail/admin@usrpro.io/.Sent"         errstr = 0x7f16546e403a <__x86_return_thunk+5> "\363\220\017\256\350\353\371H\215d$\b\303\350\a"         error = 32534         sync_flags = MAILBOX_SYNC_FLAG_FULL_READ         ret = 0 #17 0x000055945e4ac3d8 in master_connection_input_line (conn=0x55945fe57440, line=0x55945fe5778c "admin@usrpro.io\tSent\t2HvXT2h9epPAqMsG\t0\ti") at master-connection.c:247         args = 0x55945fe46078         input = {parent_event = 0x0, module = 0x55945e4ad2ec "mail", service = 0x55945e4ad2f1 "indexer-worker", username = 0x55945fe46048 "admin@usrpro.io", session_id = 0x0, session_id_prefix = 0x55945fe4605d "2HvXT2h9epPAqMsG", session_create_time = 0, local_ip = {family = 0, u = {ip6 = {__in6_union = {__s6_addr = '\000' , __s6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __s6_addr32 = {0, 0, 0, 0}}}, ip4 = {s_addr = 0}}}, remote_ip = {family = 0, u = {ip6 = {__in6_union = {__s6_addr = '\000' , __s6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __s6_addr32 = {0, 0, 0, 0}}}, ip4 = {s_addr = 0}}}, local_port = 0, remote_port = 0, userdb_fields = 0x0, flags_override_add = (unknown: 0), flags_override_remove = (unknown: 0), no_userdb_lookup = false, debug = false, conn_secured = false, conn_ssl_secured = false}         service_user = 0x55945fe59958         user = 0x55945fe73dc8         str = 0x7f16547f6231 "\220\311\351\375\335\356\377UH\211\345H\203\354 H\211}\370H\211u\360H\211U\350H\211M\340H\203",         error = 0x0         max_recent_msgs = 0         ret = 32767 #18 0x000055945e4ac58f in master_connection_input (conn=0x55945fe57440) at master-connection.c:287         _data_stack_cur_id = 3         line = 0x55945fe5778c "admin@usrpro.io\tSent\t2HvXT2h9epPAqMsG\t0\ti"         ret = 32534 #19 0x00007f16547e73c8 in io_loop_call_io (io=0x55945fe57480) at ioloop.c:698         ioloop = 0x55945e4afca0         t_id = 2         __func__ = "io_loop_call_io" #20 0x00007f16547ea409 in io_loop_handler_run_internal (ioloop=0x55945e4afca0) at ioloop-epoll.c:221         ctx = 0x7f1654b0dda0         events = 0x55945fe548c0         event = 0x55945fe548c0         list = 0x55945fe57500         io = 0x55945fe57480         tv = {tv_sec = 2147483, tv_usec = 0}         events_count = 5         msecs = -1         ret = 1         i = 0         j = 0         call = true         __func__ = "io_loop_handler_run_internal" #21 0x00007f16547e7657 in io_loop_handler_run (ioloop=0x55945e4afca0) at ioloop.c:750         __func__ = "io_loop_handler_run" #22 0x00007f16547e752e in io_loop_run (ioloop=0x55945e4afca0) at ioloop.c:723         __func__ = "io_loop_run" #23 0x00007f165471b3d5 in master_service_run (service=0x55945e4afb40, callback=0x55945e4ab5ed ) at master-service.c:775 No locals. #24 0x000055945e4ab7ce in main (argc=1, argv=0x55945e4af8e0) at indexer-worker.c:78         service_flags = (MASTER_SERVICE_FLAG_KEEP_CONFIG_OPEN | MASTER_SERVICE_FLAG_SEND_STATS)         storage_service_flags = (MAIL_STORAGE_SERVICE_FLAG_USERDB_LOOKUP | MAIL_STORAGE_SERVICE_FLAG_TEMP_PRIV_DROP | MAIL_STORAGE_SERVICE_FLAG_NO_IDLE_TIMEOUT)         c = -1 On 12/19/18 8:15 PM, Tim Mohlmann via dovecot wrote: <Deleted due to message size limit>

Hi, I now this is kinda impolite to ask, but I would like some feedback on this issue. I'm representing the Mailu user group here, plus the fact that my own production server is affected and starts to crash due to file corruption as a result of the indexer-worker segfaults. Last night my server became unavailable with logs like: Error: imap(tim@usrpro.com)<131><2RGyoYd9Jq/AqMsO>: Corrupted transaction log file /mail/tim@usrpro.com/dovecot.index.log seq 6: record size too small (type=0x2272560, offset=26340, size=0) (sync_offset=26592) Deleting the corrupted files brought it back, but I don't really like the prospect of cleaning corrupted files during christmas. ;) I would like to know: do you consider this a real dovecot bug? Or is this something as a result of the way  Alpine configures the package? Should I cross post the report to Alpine? Or is it worth changing the image to Debian instead? Or maybe you don't consider the trace good enough to work on? Also that I would like to know. Many thanks in advance! Tim On 12/20/18 9:49 AM, Tim Mohlmann via dovecot wrote:

I'm really sorry, but it was a long day yesterday. I forgot to mention that I used alpine:edge (based on the alpine master branch) image to set up the build environment. So there were some version changes.

dovecot --version: 2.3.3 (dcead646b)

apk info musl:

musl-1.1.20-r2 description: the musl c library (libc) implementation

Configuration was unchanged wrt to my first mail. Maybe it's helpful to share the build flags?

export CFLAGS="-O0" export CXXFLAGS="$CFLAGS"

export CPPFLAGS="$CFLAGS"

export LDFLAGS="-Wl,--as-needed"

In the APKBUILD file can be found here: https://git.alpinelinux.org/cgit/aports/tree/main/dovecot/APKBUILD and I've modified the following:

options="libtool !strip"

subpackages="

     ....

     $pkgname-dbg

"

And if it is of any interest, I've done a `docker commit` on the container and pushed the resulting image as muhlemmer/dovecot:debug. https://cloud.docker.com/repository/docker/muhlemmer/dovecot/tags. Don't know if its of much use by itself, without the Mailu ecosystem around. Just in case.

Cheers!

On 12/20/18 2:04 AM, Tim Mohlmann via dovecot wrote:

...

I've managed to re-compile the alpine packages inside the container, creating the debug symbols and disabling compile time optimizations, as they also disturbed the backtrace. The following output looks much more meaningful. But unfortunately there are still some symbols missing for lucene-core. Let me know if this is enough to work with. (It doesn't seem to be musl after all?)

Reading symbols from /usr/libexec/dovecot/indexer-worker...Reading symbols from /usr/lib/debug//usr/libexec/dovecot/indexer-worker.debug...done. done. [New LWP 30417]

warning: Can't read pathname for load map: No error information. Core was generated by `dovecot/indexer-worker'. Program terminated with signal SIGSEGV, Segmentation fault. #0  0x00007f1653f12c31 in ?? () from /usr/lib/libclucene-core.so.1 (gdb) bt full #0  0x00007f1653f12c31 in ?? () from /usr/lib/libclucene-core.so.1 No symbol table info available. #1  0x00007f1653edeba2 in lucene::index::KeepOnlyLastCommitDeletionPolicy::onCommit(std::vectorlucene::index::IndexCommitPoint* >&) ()    from /usr/lib/libclucene-core.so.1 No symbol table info available. #2  0x00007f1653f15312 in ?? () from /usr/lib/libclucene-core.so.1 No symbol table info available. #3  0x00007f1653f325e3 in lucene::index::IndexWriter::doFlush(bool) () from /usr/lib/libclucene-core.so.1 No symbol table info available. #4  0x00007f1653f32f9c in lucene::index::IndexWriter::flush(bool, bool) () from /usr/lib/libclucene-core.so.1 No symbol table info available. #5  0x00007f1653f33052 in lucene::index::IndexWriter::closeInternal(bool) () from /usr/lib/libclucene-core.so.1 No symbol table info available. #6  0x00007f1653f337c4 in lucene::index::IndexWriter::close(bool) () from /usr/lib/libclucene-core.so.1 No symbol table info available. #7  0x00007f16541fc8c6 in lucene_index_build_deinit (index=0x55945fe7a860) at lucene-wrapper.cc:646         ret = 0 #8  0x00007f16541f9ba4 in fts_backend_lucene_update_deinit (_ctx=0x55945fe910a0) at fts-backend-lucene.c:259         ctx = 0x55945fe910a0         backend = 0x55945fe7a760         ret = 0         __func__ = "fts_backend_lucene_update_deinit" #9  0x00007f1654649baa in fts_backend_update_deinit (_ctx=0x55945fe7a480) at fts-api.c:144         ctx = 0x55945fe910a0         backend = 0x55945fe7a760         ret = 0 #10 0x00007f1654655d83 in fts_transaction_end (t=0x55945fe88820, error_r=0x7fff1b28d1b8) at fts-storage.c:613         ft = 0x55945fe84400         flist = 0x55945fe7a3a0         ret = 0         __func__ = "fts_transaction_end" #11 0x00007f16546562e8 in fts_transaction_commit (t=0x55945fe88820, changes_r=0x7fff1b28d2c0) at fts-storage.c:696         ft = 0x55945fe84400 --Type <RET> for more, q to quit, c to continue without paging--c         fbox = 0x55945fe7f798         box = 0x55945fe7efa8         autoindex = false         ret = 0         error = 0x7f1654813665 "H\213E\350\353\067\213E\344\211\302H\213E\330H\211\326H\211\307\350\301\367\377\377H\211E\360\213E\344\203\350\001\211\302H\213M\350H\213E\360H\211\316H\211\307\350\302\357\354\377H\213E\360H\213M\370dH3\f%(" #12 0x00007f165469b83e in quota_mailbox_transaction_commit (ctx=0x55945fe88820, changes_r=0x7fff1b28d2c0) at quota-storage.c:174         qbox = 0x55945fe7f600         qt = 0x55945fe8f160         __func__ = "quota_mailbox_transaction_commit" #13 0x00007f16548fefad in mailbox_transaction_commit_get_changes (_t=0x7fff1b28d348, changes_r=0x7fff1b28d2c0) at mail-storage.c:2215         _data_stack_cur_id = 4         t = 0x55945fe88820         box = 0x55945fe7efa8         save_count = 0         ret = 21908         __func__ = "mailbox_transaction_commit_get_changes" #14 0x00007f16548feefc in mailbox_transaction_commit (t=0x7fff1b28d348) at mail-storage.c:2197         changes = {pool = 0x0, uid_validity = 1418718114, saved_uids = {arr = {buffer = 0x7f16548e5d9e <__x86_return_thunk+5>, element_size = 140733649048408}, v = 0x7f16548e5d9e <__x86_return_thunk+5>, v_modifiable = 0x7f16548e5d9e <__x86_return_thunk+5>}, ignored_modseq_changes = 455660384, changes_mask = (unknown: 0), no_read_perm = false}         ret = 21908 #15 0x000055945e4abdcb in index_mailbox_precache (conn=0x55945fe57440, box=0x55945fe7efa8) at master-connection.c:126         storage = 0x55945fe77f28         username = 0x55945fe73ee0 "admin@usrpro.io"         box_vname = 0x55945fe7f310 "Sent"         errstr = 0x7f165469cb53 "\213E\344H\203\304([]\351\320f\377\377UH\211\345H\203\354\060H\211}\330dH\213\004%("         error = MAIL_ERROR_TEMP         status = {messages = 10, recent = 0, unseen = 0, uidvalidity = 1545140227, uidnext = 11, first_unseen_seq = 0, first_recent_uid = 3, last_cached_seq = 1, highest_modseq = 0, highest_pvt_modseq = 0, keywords = 0x0, permanent_flags = 0, flags = 0, permanent_keywords = false, allow_new_keywords = false, nonpermanent_modseqs = false, no_modseq_tracking = false, have_guids = true, have_save_guids = true, have_only_guid128 = false}         trans = 0x0         search_args = 0x0         ctx = 0x0         mail = 0x0         metadata = {guid = '\000' , virtual_size = 0, physical_size = 0, first_save_date = 0, cache_fields = 0x0, precache_fields = (MAIL_FETCH_STREAM_HEADER | MAIL_FETCH_STREAM_BODY | MAIL_FETCH_RECEIVED_DATE | MAIL_FETCH_SAVE_DATE | MAIL_FETCH_PHYSICAL_SIZE | MAIL_FETCH_VIRTUAL_SIZE | MAIL_FETCH_UIDL_BACKEND | MAIL_FETCH_GUID | MAIL_FETCH_POP3_ORDER), backend_ns_prefix = 0x0, backend_ns_type = (unknown: 0)}         seq = 2         first_uid = 2         last_uid = 10         percentage_str = "\026\177\000"         counter = 9         max = 9         percentage = 32534         percentage_sent = 0         ret = 0         uids = 0x55945fe48938 " (UIDs 2..10)" #16 0x000055945e4ac1c1 in index_mailbox (conn=0x55945fe57440, user=0x55945fe73dc8, mailbox=0x55945fe46058 "Sent", max_recent_msgs=0, what=0x55945fe46070 "i") at master-connection.c:205         ns = 0x55945fe77da0         box = 0x55945fe7efa8         status = {messages = 1608873868, recent = 0, unseen = 1581972288, uidvalidity = 21908, uidnext = 455660880, first_unseen_seq = 32767, first_recent_uid = 1608810272, last_cached_seq = 21908, highest_modseq = 139733882519610, highest_pvt_modseq = 94095725476155, keywords = 0x7fff1b28d540, permanent_flags = 0, flags = 0, permanent_keywords = false, allow_new_keywords = false, nonpermanent_modseqs = false, no_modseq_tracking = true, have_guids = true, have_save_guids = false, have_only_guid128 = true}         path = 0x55945fe47f38 "/mail/admin@usrpro.io/.Sent"         errstr = 0x7f16546e403a <__x86_return_thunk+5> "\363\220\017\256\350\353\371H\215d$\b\303\350\a"         error = 32534         sync_flags = MAILBOX_SYNC_FLAG_FULL_READ         ret = 0 #17 0x000055945e4ac3d8 in master_connection_input_line (conn=0x55945fe57440, line=0x55945fe5778c "admin@usrpro.io\tSent\t2HvXT2h9epPAqMsG\t0\ti") at master-connection.c:247         args = 0x55945fe46078         input = {parent_event = 0x0, module = 0x55945e4ad2ec "mail", service = 0x55945e4ad2f1 "indexer-worker", username = 0x55945fe46048 "admin@usrpro.io", session_id = 0x0, session_id_prefix = 0x55945fe4605d "2HvXT2h9epPAqMsG", session_create_time = 0, local_ip = {family = 0, u = {ip6 = {__in6_union = {__s6_addr = '\000' , __s6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __s6_addr32 = {0, 0, 0, 0}}}, ip4 = {s_addr = 0}}}, remote_ip = {family = 0, u = {ip6 = {__in6_union = {__s6_addr = '\000' , __s6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __s6_addr32 = {0, 0, 0, 0}}}, ip4 = {s_addr = 0}}}, local_port = 0, remote_port = 0, userdb_fields = 0x0, flags_override_add = (unknown: 0), flags_override_remove = (unknown: 0), no_userdb_lookup = false, debug = false, conn_secured = false, conn_ssl_secured = false}         service_user = 0x55945fe59958         user = 0x55945fe73dc8         str = 0x7f16547f6231 "\220\311\351\375\335\356\377UH\211\345H\203\354 H\211}\370H\211u\360H\211U\350H\211M\340H\203",         error = 0x0         max_recent_msgs = 0         ret = 32767 #18 0x000055945e4ac58f in master_connection_input (conn=0x55945fe57440) at master-connection.c:287         _data_stack_cur_id = 3         line = 0x55945fe5778c "admin@usrpro.io\tSent\t2HvXT2h9epPAqMsG\t0\ti"         ret = 32534 #19 0x00007f16547e73c8 in io_loop_call_io (io=0x55945fe57480) at ioloop.c:698         ioloop = 0x55945e4afca0         t_id = 2         __func__ = "io_loop_call_io" #20 0x00007f16547ea409 in io_loop_handler_run_internal (ioloop=0x55945e4afca0) at ioloop-epoll.c:221         ctx = 0x7f1654b0dda0         events = 0x55945fe548c0         event = 0x55945fe548c0         list = 0x55945fe57500         io = 0x55945fe57480         tv = {tv_sec = 2147483, tv_usec = 0}         events_count = 5         msecs = -1         ret = 1         i = 0         j = 0         call = true         __func__ = "io_loop_handler_run_internal" #21 0x00007f16547e7657 in io_loop_handler_run (ioloop=0x55945e4afca0) at ioloop.c:750         __func__ = "io_loop_handler_run" #22 0x00007f16547e752e in io_loop_run (ioloop=0x55945e4afca0) at ioloop.c:723         __func__ = "io_loop_run" #23 0x00007f165471b3d5 in master_service_run (service=0x55945e4afb40, callback=0x55945e4ab5ed ) at master-service.c:775 No locals. #24 0x000055945e4ab7ce in main (argc=1, argv=0x55945e4af8e0) at indexer-worker.c:78         service_flags = (MASTER_SERVICE_FLAG_KEEP_CONFIG_OPEN | MASTER_SERVICE_FLAG_SEND_STATS)         storage_service_flags = (MAIL_STORAGE_SERVICE_FLAG_USERDB_LOOKUP | MAIL_STORAGE_SERVICE_FLAG_TEMP_PRIV_DROP | MAIL_STORAGE_SERVICE_FLAG_NO_IDLE_TIMEOUT)         c = -1

On 12/19/18 8:15 PM, Tim Mohlmann via dovecot wrote:

<Deleted due to message size limit>

Ok, thanks a lot for the reply. I'll keep digging then :) On 12/21/18 4:19 PM, Aki Tuomi wrote:

On 21.12.2018 15.01, Tim Mohlmann via dovecot wrote:

...

Hi, I now this is kinda impolite to ask, but I would like some feedback on this issue. I'm representing the Mailu user group here, plus the fact that my own production server is affected and starts to crash due to file corruption as a result of the indexer-worker segfaults. Last night my server became unavailable with logs like:

Error: imap(tim@usrpro.com)<131><2RGyoYd9Jq/AqMsO>: Corrupted transaction log file /mail/tim@usrpro.com/dovecot.index.log seq 6: record size too small (type=0x2272560, offset=26340, size=0) (sync_offset=26592)

Deleting the corrupted files brought it back, but I don't really like the prospect of cleaning corrupted files during christmas. ;)

I would like to know: do you consider this a real dovecot bug? Or is this something as a result of the way  Alpine configures the package? Should I cross post the report to Alpine? Or is it worth changing the image to Debian instead?

Or maybe you don't consider the trace good enough to work on? Also that I would like to know.

Many thanks in advance!

Tim

On 12/20/18 9:49 AM, Tim Mohlmann via dovecot wrote:

...

I'm really sorry, but it was a long day yesterday. I forgot to mention that I used alpine:edge (based on the alpine master branch) image to set up the build environment. So there were some version changes.

dovecot --version: 2.3.3 (dcead646b)

apk info musl:

musl-1.1.20-r2 description: the musl c library (libc) implementation

Configuration was unchanged wrt to my first mail. Maybe it's helpful to share the build flags?

export CFLAGS="-O0" export CXXFLAGS="$CFLAGS"

export CPPFLAGS="$CFLAGS"

export LDFLAGS="-Wl,--as-needed"

In the APKBUILD file can be found here: https://git.alpinelinux.org/cgit/aports/tree/main/dovecot/APKBUILD and I've modified the following:

options="libtool !strip"

subpackages="

     ....

     $pkgname-dbg

"

And if it is of any interest, I've done a `docker commit` on the container and pushed the resulting image as muhlemmer/dovecot:debug. https://cloud.docker.com/repository/docker/muhlemmer/dovecot/tags. Don't know if its of much use by itself, without the Mailu ecosystem around. Just in case.

Cheers!

On 12/20/18 2:04 AM, Tim Mohlmann via dovecot wrote:

...

I've managed to re-compile the alpine packages inside the container, creating the debug symbols and disabling compile time optimizations, as they also disturbed the backtrace. The following output looks much more meaningful. But unfortunately there are still some symbols missing for lucene-core. Let me know if this is enough to work with. (It doesn't seem to be musl after all?)

Reading symbols from /usr/libexec/dovecot/indexer-worker...Reading symbols from /usr/lib/debug//usr/libexec/dovecot/indexer-worker.debug...done. done. [New LWP 30417]

warning: Can't read pathname for load map: No error information. Core was generated by `dovecot/indexer-worker'. Program terminated with signal SIGSEGV, Segmentation fault. #0  0x00007f1653f12c31 in ?? () from /usr/lib/libclucene-core.so.1 (gdb) bt full #0  0x00007f1653f12c31 in ?? () from /usr/lib/libclucene-core.so.1 No symbol table info available. #1  0x00007f1653edeba2 in lucene::index::KeepOnlyLastCommitDeletionPolicy::onCommit(std::vectorlucene::index::IndexCommitPoint* >&) ()    from /usr/lib/libclucene-core.so.1 No symbol table info available. #2  0x00007f1653f15312 in ?? () from /usr/lib/libclucene-core.so.1 No symbol table info available. #3  0x00007f1653f325e3 in lucene::index::IndexWriter::doFlush(bool) () from /usr/lib/libclucene-core.so.1 No symbol table info available. #4  0x00007f1653f32f9c in lucene::index::IndexWriter::flush(bool, bool) () from /usr/lib/libclucene-core.so.1 No symbol table info available. #5  0x00007f1653f33052 in lucene::index::IndexWriter::closeInternal(bool) () from /usr/lib/libclucene-core.so.1 No symbol table info available. #6  0x00007f1653f337c4 in lucene::index::IndexWriter::close(bool) () from /usr/lib/libclucene-core.so.1 No symbol table info available. #7  0x00007f16541fc8c6 in lucene_index_build_deinit (index=0x55945fe7a860) at lucene-wrapper.cc:646         ret = 0 #8  0x00007f16541f9ba4 in fts_backend_lucene_update_deinit (_ctx=0x55945fe910a0) at fts-backend-lucene.c:259         ctx = 0x55945fe910a0         backend = 0x55945fe7a760         ret = 0         __func__ = "fts_backend_lucene_update_deinit" #9  0x00007f1654649baa in fts_backend_update_deinit (_ctx=0x55945fe7a480) at fts-api.c:144         ctx = 0x55945fe910a0         backend = 0x55945fe7a760         ret = 0 #10 0x00007f1654655d83 in fts_transaction_end (t=0x55945fe88820, error_r=0x7fff1b28d1b8) at fts-storage.c:613         ft = 0x55945fe84400         flist = 0x55945fe7a3a0         ret = 0         __func__ = "fts_transaction_end" #11 0x00007f16546562e8 in fts_transaction_commit (t=0x55945fe88820, changes_r=0x7fff1b28d2c0) at fts-storage.c:696         ft = 0x55945fe84400 --Type <RET> for more, q to quit, c to continue without paging--c         fbox = 0x55945fe7f798         box = 0x55945fe7efa8         autoindex = false         ret = 0         error = 0x7f1654813665 "H\213E\350\353\067\213E\344\211\302H\213E\330H\211\326H\211\307\350\301\367\377\377H\211E\360\213E\344\203\350\001\211\302H\213M\350H\213E\360H\211\316H\211\307\350\302\357\354\377H\213E\360H\213M\370dH3\f%(" #12 0x00007f165469b83e in quota_mailbox_transaction_commit (ctx=0x55945fe88820, changes_r=0x7fff1b28d2c0) at quota-storage.c:174         qbox = 0x55945fe7f600         qt = 0x55945fe8f160         __func__ = "quota_mailbox_transaction_commit" #13 0x00007f16548fefad in mailbox_transaction_commit_get_changes (_t=0x7fff1b28d348, changes_r=0x7fff1b28d2c0) at mail-storage.c:2215         _data_stack_cur_id = 4         t = 0x55945fe88820         box = 0x55945fe7efa8         save_count = 0         ret = 21908         __func__ = "mailbox_transaction_commit_get_changes" #14 0x00007f16548feefc in mailbox_transaction_commit (t=0x7fff1b28d348) at mail-storage.c:2197         changes = {pool = 0x0, uid_validity = 1418718114, saved_uids = {arr = {buffer = 0x7f16548e5d9e <__x86_return_thunk+5>, element_size = 140733649048408}, v = 0x7f16548e5d9e <__x86_return_thunk+5>, v_modifiable = 0x7f16548e5d9e <__x86_return_thunk+5>}, ignored_modseq_changes = 455660384, changes_mask = (unknown: 0), no_read_perm = false}         ret = 21908 #15 0x000055945e4abdcb in index_mailbox_precache (conn=0x55945fe57440, box=0x55945fe7efa8) at master-connection.c:126         storage = 0x55945fe77f28         username = 0x55945fe73ee0 "admin@usrpro.io"         box_vname = 0x55945fe7f310 "Sent"         errstr = 0x7f165469cb53 "\213E\344H\203\304([]\351\320f\377\377UH\211\345H\203\354\060H\211}\330dH\213\004%("         error = MAIL_ERROR_TEMP         status = {messages = 10, recent = 0, unseen = 0, uidvalidity = 1545140227, uidnext = 11, first_unseen_seq = 0, first_recent_uid = 3, last_cached_seq = 1, highest_modseq = 0, highest_pvt_modseq = 0, keywords = 0x0, permanent_flags = 0, flags = 0, permanent_keywords = false, allow_new_keywords = false, nonpermanent_modseqs = false, no_modseq_tracking = false, have_guids = true, have_save_guids = true, have_only_guid128 = false}         trans = 0x0         search_args = 0x0         ctx = 0x0         mail = 0x0         metadata = {guid = '\000' , virtual_size = 0, physical_size = 0, first_save_date = 0, cache_fields = 0x0, precache_fields = (MAIL_FETCH_STREAM_HEADER | MAIL_FETCH_STREAM_BODY | MAIL_FETCH_RECEIVED_DATE | MAIL_FETCH_SAVE_DATE | MAIL_FETCH_PHYSICAL_SIZE | MAIL_FETCH_VIRTUAL_SIZE | MAIL_FETCH_UIDL_BACKEND | MAIL_FETCH_GUID | MAIL_FETCH_POP3_ORDER), backend_ns_prefix = 0x0, backend_ns_type = (unknown: 0)}         seq = 2         first_uid = 2         last_uid = 10         percentage_str = "\026\177\000"         counter = 9         max = 9         percentage = 32534         percentage_sent = 0         ret = 0         uids = 0x55945fe48938 " (UIDs 2..10)" #16 0x000055945e4ac1c1 in index_mailbox (conn=0x55945fe57440, user=0x55945fe73dc8, mailbox=0x55945fe46058 "Sent", max_recent_msgs=0, what=0x55945fe46070 "i") at master-connection.c:205         ns = 0x55945fe77da0         box = 0x55945fe7efa8         status = {messages = 1608873868, recent = 0, unseen = 1581972288, uidvalidity = 21908, uidnext = 455660880, first_unseen_seq = 32767, first_recent_uid = 1608810272, last_cached_seq = 21908, highest_modseq = 139733882519610, highest_pvt_modseq = 94095725476155, keywords = 0x7fff1b28d540, permanent_flags = 0, flags = 0, permanent_keywords = false, allow_new_keywords = false, nonpermanent_modseqs = false, no_modseq_tracking = true, have_guids = true, have_save_guids = false, have_only_guid128 = true}         path = 0x55945fe47f38 "/mail/admin@usrpro.io/.Sent"         errstr = 0x7f16546e403a <__x86_return_thunk+5> "\363\220\017\256\350\353\371H\215d$\b\303\350\a"         error = 32534         sync_flags = MAILBOX_SYNC_FLAG_FULL_READ         ret = 0 #17 0x000055945e4ac3d8 in master_connection_input_line (conn=0x55945fe57440, line=0x55945fe5778c "admin@usrpro.io\tSent\t2HvXT2h9epPAqMsG\t0\ti") at master-connection.c:247         args = 0x55945fe46078         input = {parent_event = 0x0, module = 0x55945e4ad2ec "mail", service = 0x55945e4ad2f1 "indexer-worker", username = 0x55945fe46048 "admin@usrpro.io", session_id = 0x0, session_id_prefix = 0x55945fe4605d "2HvXT2h9epPAqMsG", session_create_time = 0, local_ip = {family = 0, u = {ip6 = {__in6_union = {__s6_addr = '\000' , __s6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __s6_addr32 = {0, 0, 0, 0}}}, ip4 = {s_addr = 0}}}, remote_ip = {family = 0, u = {ip6 = {__in6_union = {__s6_addr = '\000' , __s6_addr16 = {0, 0, 0, 0, 0, 0, 0, 0}, __s6_addr32 = {0, 0, 0, 0}}}, ip4 = {s_addr = 0}}}, local_port = 0, remote_port = 0, userdb_fields = 0x0, flags_override_add = (unknown: 0), flags_override_remove = (unknown: 0), no_userdb_lookup = false, debug = false, conn_secured = false, conn_ssl_secured = false}         service_user = 0x55945fe59958         user = 0x55945fe73dc8         str = 0x7f16547f6231 "\220\311\351\375\335\356\377UH\211\345H\203\354 H\211}\370H\211u\360H\211U\350H\211M\340H\203",         error = 0x0         max_recent_msgs = 0         ret = 32767 #18 0x000055945e4ac58f in master_connection_input (conn=0x55945fe57440) at master-connection.c:287         _data_stack_cur_id = 3         line = 0x55945fe5778c "admin@usrpro.io\tSent\t2HvXT2h9epPAqMsG\t0\ti"         ret = 32534 #19 0x00007f16547e73c8 in io_loop_call_io (io=0x55945fe57480) at ioloop.c:698         ioloop = 0x55945e4afca0         t_id = 2         __func__ = "io_loop_call_io" #20 0x00007f16547ea409 in io_loop_handler_run_internal (ioloop=0x55945e4afca0) at ioloop-epoll.c:221         ctx = 0x7f1654b0dda0         events = 0x55945fe548c0         event = 0x55945fe548c0         list = 0x55945fe57500         io = 0x55945fe57480         tv = {tv_sec = 2147483, tv_usec = 0}         events_count = 5         msecs = -1         ret = 1         i = 0         j = 0         call = true         __func__ = "io_loop_handler_run_internal" #21 0x00007f16547e7657 in io_loop_handler_run (ioloop=0x55945e4afca0) at ioloop.c:750         __func__ = "io_loop_handler_run" #22 0x00007f16547e752e in io_loop_run (ioloop=0x55945e4afca0) at ioloop.c:723         __func__ = "io_loop_run" #23 0x00007f165471b3d5 in master_service_run (service=0x55945e4afb40, callback=0x55945e4ab5ed ) at master-service.c:775 No locals. #24 0x000055945e4ab7ce in main (argc=1, argv=0x55945e4af8e0) at indexer-worker.c:78         service_flags = (MASTER_SERVICE_FLAG_KEEP_CONFIG_OPEN | MASTER_SERVICE_FLAG_SEND_STATS)         storage_service_flags = (MAIL_STORAGE_SERVICE_FLAG_USERDB_LOOKUP | MAIL_STORAGE_SERVICE_FLAG_TEMP_PRIV_DROP | MAIL_STORAGE_SERVICE_FLAG_NO_IDLE_TIMEOUT)         c = -1

On 12/19/18 8:15 PM, Tim Mohlmann via dovecot wrote:

<Deleted due to message size limit>

This unfortunately looks a lot like lucene problem.

Aki

do you use both fts-solr and tika by chance?

On Fri, Jan 11, 2019 at 11:19 AM Fírvida aafirvida@gmail.com wrote:

Hello have you manage to solve your issue. I have a Mailu/Dovecot server in production which is giving me the same error. Any help would be appreciated.

-- Sent from: http://dovecot.2317879.n4.nabble.com/

-- Larry Rosenman http://www.lerctr.org/~ler Phone: +1 214-642-9640 (c) E-Mail: larryrtx@gmail.com US Mail: 5708 Sabbia Dr, Round Rock, TX 78665-2106

Ok, thanks for the info.

Hadn't read the whole thread.

On Sat, Jan 12, 2019 at 1:30 PM Stephan Bosch stephan@rename-it.nl wrote:

Op 11/01/2019 om 21:07 schreef Larry Rosenman:

...

do you use both fts-solr and tika by chance?

I doubt it. The original post is about Lucene and it fails in the Lucene code. The FTS Solr + Tika problem is caused in Dovecot lib-http.

Regards,

Stephan.

...

On Fri, Jan 11, 2019 at 11:19 AM Fírvida mailto:aafirvida@gmail.com> wrote:

Hello have you manage to solve your issue. I have a Mailu/Dovecot
server in
production which is giving me the same error. Any help would be
appreciated.



--
Sent from: http://dovecot.2317879.n4.nabble.com/

-- Larry Rosenman http://www.lerctr.org/~ler Phone: +1 214-642-9640 (c) E-Mail: larryrtx@gmail.com mailto:larryrtx@gmail.com US Mail: 5708 Sabbia Dr, Round Rock, TX 78665-2106

-- Larry Rosenman http://www.lerctr.org/~ler Phone: +1 214-642-9640 (c) E-Mail: larryrtx@gmail.com US Mail: 5708 Sabbia Dr, Round Rock, TX 78665-2106