[Dovecot] SIGBART/SIGSEGV while SELECTing virtual folder
Hello!
I just installed Dovecot's latest nightly build (20081020) and tried the virtual folder features. I started with a really simple "all" folder:
| # virtual/all | * | all
But selecting this folder causes dovecot to panic (in most cases).
While trying to debug this, I got slightly different results and I am not really sure yet if this is just non-deterministic, depends on some cached dovecot data or if there is some difference between the debug build or my rudimentary, unpatched debian package (which lacks the debug symbols).
The results below are from a build with --prefix set to a clean, temporary directory. Similar problems occured also with the alpha2 release, which caused me to try the latest nightly build.
% ./sbin/dovecot --exec-mail ext /usr/bin/gdb ./libexec/dovecot/imap GNU gdb 6.8-debian Copyright (C) 2008 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 "i486-linux-gnu"... (gdb) r Starting program: /tmp/dd/libexec/dovecot/imap
- PREAUTH [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE SORT THREAD=REFERENCES MULTIAPPEND UNSELECT IDLE CHILDREN NAMESPACE UIDPLUS LIST-EXTE NDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH SEARCHRES WITHIN CONTEXT=SEARCH] Logg ed in as lars . SELECT virtual/all
Program received signal SIGSEGV, Segmentation fault. mailbox_search_result_free (_result=0x8efc0d0) at mailbox-search-result.c:65 65 results = array_get(&result->box->search_results, &count); (gdb) bt full #0 mailbox_search_result_free (_result=0x8efc0d0) at mailbox-search-result.c:65 result = (struct mail_search_result *) 0x0 i = <value optimized out> __PRETTY_FUNCTION__ = "mailbox_search_result_free" #1 0xb7f4e12e in virtual_storage_mailbox_close (box=0x8efbeb0) at virtual-storage.c:311 i = 0 ret = 0 #2 0x080a9299 in mail_thread_mailbox_close (box=0x8efbeb0) at index-thread.c:638 tbox = (struct mail_thread_mailbox *) 0x9517c68 ret = <value optimized out> __PRETTY_FUNCTION__ = "mail_thread_mailbox_close" #3 0x0806486a in cmd_select_finish (ctx=0x8ef3778, ret=0) at cmd-select.c:190 No locals. #4 0x08064a89 in cmd_select_full (cmd=0x8ef3730, readonly=false) at cmd-select.c:381 client = (struct client *) 0x8ef34b0 box = (struct mailbox *) 0xbfb78258 ctx = (struct imap_select_context *) 0x8ef3778 args = (const struct imap_arg *) 0x8ef87b0 mailbox = 0x8ef8838 "all" ret = 0 __PRETTY_FUNCTION__ = "cmd_select_full" #5 0x080653d9 in cmd_select (cmd=0x8ef3730) at cmd-select.c:387 No locals. #6 0x0806755c in client_command_input (cmd=0x8ef3730) at client.c:592 client = (struct client *) 0x8ef34b0 command = <value optimized out> __PRETTY_FUNCTION__ = "client_command_input" #7 0x080675f9 in client_command_input (cmd=0x8ef3730) at client.c:641 client = (struct client *) 0x8ef34b0 command = <value optimized out> __PRETTY_FUNCTION__ = "client_command_input" #8 0x08067bfd in client_handle_input (client=0x8ef34b0) at client.c:682 _data_stack_cur_id = 3 ret = <value optimized out> remove_io = <value optimized out> handled_commands = false #9 0x080680b3 in client_input (client=0x8ef34b0) at client.c:737 cmd = <value optimized out> output = (struct ostream *) 0x8ef365c bytes = <value optimized out> __PRETTY_FUNCTION__ = "client_input" #10 0x080f3210 in io_loop_handler_run (ioloop=0x8eefab8) at ioloop-epoll.c:203 ctx = (struct ioloop_handler_context *) 0x8eefbb0 event = (const struct epoll_event *) 0x8eefbf0 list = (struct io_list *) 0x8ef36d8 io = (struct io_file *) 0x8ef36b8 tv = {tv_sec = 1799, tv_usec = 999384} t_id = 2 msecs = <value optimized out> ret = 1 i = 0 j = 0 call = <value optimized out> #11 0x080f26a0 in io_loop_run (ioloop=0x8eefab8) at ioloop.c:320 No locals. #12 0x0806f54d in main (argc=149943736, argv=0xbfb78484, envp=0xbfb7848c) at main.c:309 No locals.
On another folder with the same dovecot-virtual file, I get another backtrace:
% ./sbin/dovecot --exec-mail ext /usr/bin/gdb ./libexec/dovecot/imap GNU gdb 6.8-debian Copyright (C) 2008 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 "i486-linux-gnu"... (gdb) r Starting program: /tmp/dd/libexec/dovecot/imap
- PREAUTH [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE SORT THREAD=REFERENCES MULTIAPPEND UNSELECT IDLE CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH SEARCHRES WITHIN CONTEXT=SEARCH] Logged in as lars . SELECT "virtual/test"
Program received signal SIGABRT, Aborted. 0xb7e83556 in raise () from /lib/libc.so.6 (gdb) bt #0 0xb7e83556 in raise () from /lib/libc.so.6 #1 0xb7e84d78 in abort () from /lib/libc.so.6 #2 0x080ead25 in default_fatal_finish (type=<value optimized out>, status=0) at failures.c:150 #3 0x080eade4 in i_syslog_fatal_handler (type=LOG_TYPE_PANIC, status=0, fmt=0x80ffdec "file %s: line %d (%s): assertion failed: (%s)", args=0xbfdce064 "\203�020\b\t\001") at failures.c:308 #4 0x080ea729 in i_panic ( format=0x80ffdec "file %s: line %d (%s): assertion failed: (%s)") at failures.c:197 #5 0x080c86b8 in view_lookup_seq_range (view=0x9956648, first_uid=1, last_uid=0, first_seq_r=0xbfdce294, last_seq_r=0xbfdce290) at mail-index-view.c:265 #6 0x080c815c in mail_index_lookup_seq_range (view=0x9956648, first_uid=1, last_uid=0, first_seq_r=0xbfdce294, last_seq_r=0xbfdce290) at mail-index-view.c:530 #7 0xb7fa64d6 in virtual_sync_backend_boxes (ctx=0x9e2e3e0) at virtual-sync.c:561 #8 0xb7fa738f in virtual_storage_sync_init (box=0x9811eb0, flags=65) at virtual-sync.c:1194 #9 0x080b0240 in mailbox_sync (box=0x578d, flags=65, status_items=239, status_r=0xbfdce438) at mail-storage.c:523 #10 0x08064c70 in cmd_select_full (cmd=0x9809730, readonly=false) at cmd-select.c:273 #11 0x080653d9 in cmd_select (cmd=0x9809730) at cmd-select.c:387 #12 0x0806755c in client_command_input (cmd=0x9809730) at client.c:592 #13 0x080675f9 in client_command_input (cmd=0x9809730) at client.c:641 #14 0x08067bfd in client_handle_input (client=0x98094b0) at client.c:682 #15 0x080680b3 in client_input (client=0x98094b0) at client.c:737 #16 0x080f3210 in io_loop_handler_run (ioloop=0x9805ab8) at ioloop-epoll.c:203 #17 0x080f26a0 in io_loop_run (ioloop=0x9805ab8) at ioloop.c:320 #18 0x0806f54d in main (argc=Cannot access memory at address 0x578d ) at main.c:309
with log message
-Oct 20 15:29:22 vertikal EXT(lars): : Panic: file mail-index-view.c: line 265 (view_lookup_seq_range): assertion failed: (first_uid <= last_uid) Oct 20 15:29:22 vertikal EXT(lars): : Raw backtrace: /tmp/dd/libexec/dovecot/imap [0x80ead11] -> /tmp/dd/libexec/dovecot/imap(i_syslog_fatal_handler+0x34) [0x80eade4] -> /tmp/dd/libexec/dovecot/imap [0x80ea729] -> /tmp/dd/libexec/dovecot/imap [0x80c86b8] -> /tmp/dd/libexec/dovecot/imap(mail_index_lookup_seq_range+0x2c) [0x80c815c] -> /tmp/dd/lib/dovecot/imap/lib20_virtual_plugin.so [0xb7fa64d6] -> /tmp/dd/lib/dovecot/imap/lib20_virtual_plugin.so(virtual_storage_sync_init+0x53f) [0xb7fa738f] -> /tmp/dd/libexec/dovecot/imap(mailbox_sync+0x30) [0x80b0240] -> /tmp/dd/libexec/dovecot/imap(cmd_select_full+0x3d0) [0x8064c70] -> /tmp/dd/libexec/dovecot/imap(cmd_select+0x19) [0x80653d9] -> /tmp/dd/libexec/dovecot/imap [0x806755c] -> /tmp/dd/libexec/dovecot/imap [0x80675f9] -> /tmp/dd/libexec/dovecot/imap(client_handle_input+0x1d) [0x8067bfd] -> /tmp/dd/libexec/dovecot/imap(client_input+0x63) [0x80680b3] -> /tmp/dd/libexec/dovecot/imap(io_loop_handler_run+0xe0) [0x80f3210] -> /tmp/dd/libexec/dovecot/imap(io_loop_run+0x20)
Given that result, I tried adding yet another virtual folder with the same configuration - and it succeeded. Once. A second SELECT gave me yet another backtrace:
% ./sbin/dovecot --exec-mail ext /usr/bin/gdb ./libexec/dovecot/imap GNU gdb 6.8-debian Copyright (C) 2008 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 "i486-linux-gnu"... (gdb) r Starting program: /tmp/dd/libexec/dovecot/imap
- PREAUTH [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE SORT THREAD=REFERENCES MULTIAPPEND UNSELECT IDLE CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH SEARCHRES WITHIN CONTEXT=SEARCH] Logged in as lars . SELECT virtual/test2
- FLAGS (\Answered \Flagged \Deleted \Seen \Draft Old)
- OK [PERMANENTFLAGS (\Answered \Flagged \Deleted \Seen \Draft Old \*)] Flags permitted.
- 73863 EXISTS
- 0 RECENT
- OK [UNSEEN 10841] First unseen.
- OK [UIDVALIDITY 1224509528] UIDs valid
- OK [UIDNEXT 73864] Predicted next UID
- OK [HIGHESTMODSEQ 1] . OK [READ-WRITE] Select completed. . SELECT virtual/test2
Program received signal SIGABRT, Aborted. 0xb7e0f556 in raise () from /lib/libc.so.6 (gdb) bt full #0 0xb7e0f556 in raise () from /lib/libc.so.6 No symbol table info available. #1 0xb7e10d78 in abort () from /lib/libc.so.6 No symbol table info available. #2 0x080ead25 in default_fatal_finish (type=<value optimized out>, status=0) at failures.c:150 backtrace = 0x8b27838 "/tmp/dd/libexec/dovecot/imap [0x80ead11] -> /tmp/dd/libexec/dovecot/imap(i_syslog_fatal_handler+0x34) [0x80eade4] -> /tmp/dd/libexec/dovecot/imap [0x80ea729] -> /tmp/dd/libexec/dovecot/imap [0x80c86b8"... #3 0x080eade4 in i_syslog_fatal_handler (type=LOG_TYPE_PANIC, status=0, fmt=0x80ffdec "file %s: line %d (%s): assertion failed: (%s)", args=0xbfc57ef4 "\203�020\b\t\001") at failures.c:308 No locals. #4 0x080ea729 in i_panic ( format=0x80ffdec "file %s: line %d (%s): assertion failed: (%s)") at failures.c:197 No locals. #5 0x080c86b8 in view_lookup_seq_range (view=0x8eb77e0, first_uid=1, last_uid=0, first_seq_r=0xbfc58124, last_seq_r=0xbfc58120) at mail-index-view.c:265 __PRETTY_FUNCTION__ = "view_lookup_seq_range" #6 0x080c815c in mail_index_lookup_seq_range (view=0x8eb77e0, first_uid=1, last_uid=0, first_seq_r=0xbfc58124, last_seq_r=0xbfc58120) at mail-index-view.c:530 No locals. #7 0xb7f324d6 in virtual_sync_backend_boxes (ctx=0x90f8eb8) at virtual-sync.c:561 i = 10 #8 0xb7f3338f in virtual_storage_sync_init (box=0x8eba5d0, flags=65) at virtual-sync.c:1194 ret = <value optimized out> #9 0x080b0240 in mailbox_sync (box=0x57a2, flags=65, status_items=239, status_r=0xbfc582c8) at mail-storage.c:523 ctx = (struct mailbox_sync_context *) 0x0 #10 0x08064c70 in cmd_select_full (cmd=0x8b32730, readonly=false) at cmd-select.c:273 client = (struct client *) 0x8b324b0 box = (struct mailbox *) 0x0 ctx = (struct imap_select_context *) 0x8b32778 args = (const struct imap_arg *) 0x8b377b0 mailbox = 0x8b37838 "test2" ret = <value optimized out> __PRETTY_FUNCTION__ = "cmd_select_full" #11 0x080653d9 in cmd_select (cmd=0x8b32730) at cmd-select.c:387 No locals. #12 0x0806755c in client_command_input (cmd=0x8b32730) at client.c:592 client = (struct client *) 0x8b324b0 command = <value optimized out> __PRETTY_FUNCTION__ = "client_command_input" #13 0x080675f9 in client_command_input (cmd=0x8b32730) at client.c:641 client = (struct client *) 0x8b324b0 command = <value optimized out> __PRETTY_FUNCTION__ = "client_command_input" #14 0x08067bfd in client_handle_input (client=0x8b324b0) at client.c:682 _data_stack_cur_id = 3 ret = <value optimized out> remove_io = <value optimized out> handled_commands = false #15 0x080680b3 in client_input (client=0x8b324b0) at client.c:737 cmd = <value optimized out> output = (struct ostream *) 0x8b3265c bytes = <value optimized out> __PRETTY_FUNCTION__ = "client_input" #16 0x080f3210 in io_loop_handler_run (ioloop=0x8b2eab8) at ioloop-epoll.c:203 ctx = (struct ioloop_handler_context *) 0x8b2ebb0 event = (const struct epoll_event *) 0x8b2ebf0 list = (struct io_list *) 0x8b326d8 io = (struct io_file *) 0x8b326b8 tv = {tv_sec = 1799, tv_usec = 995613} t_id = 2 msecs = <value optimized out> ret = 1 i = 0 j = 0 call = <value optimized out> #17 0x080f26a0 in io_loop_run (ioloop=0x8b2eab8) at ioloop.c:320 No locals. #18 0x0806f54d in main (argc=Cannot access memory at address 0x57a2 ) at main.c:309 No locals.
Oct 20 15:33:31 vertikal EXT(lars): : Panic: file mail-index-view.c: line 265 (view_lookup_seq_range): assertion failed: (first_uid <= last_uid) Oct 20 15:33:31 vertikal EXT(lars): : Raw backtrace: /tmp/dd/libexec/dovecot/imap [0x80ead11] -> /tmp/dd/libexec/dovecot/imap(i_syslog_fatal_handler+0x34) [0x80eade4] -> /tmp/dd/libexec/dovecot/imap [0x80ea729] -> /tmp/dd/libexec/dovecot/imap [0x80c86b8] -> /tmp/dd/libexec/dovecot/imap(mail_index_lookup_seq_range+0x2c) [0x80c815c] -> /tmp/dd/lib/dovecot/imap/lib20_virtual_plugin.so [0xb7f324d6] -> /tmp/dd/lib/dovecot/imap/lib20_virtual_plugin.so(virtual_storage_sync_init+0x53f) [0xb7f3338f] -> /tmp/dd/libexec/dovecot/imap(mailbox_sync+0x30) [0x80b0240] -> /tmp/dd/libexec/dovecot/imap(cmd_select_full+0x3d0) [0x8064c70] -> /tmp/dd/libexec/dovecot/imap(cmd_select+0x19) [0x80653d9] -> /tmp/dd/libexec/dovecot/imap [0x806755c] -> /tmp/dd/libexec/dovecot/imap [0x80675f9] -> /tmp/dd/libexec/dovecot/imap(client_handle_input+0x1d) [0x8067bfd] -> /tmp/dd/libexec/dovecot/imap(client_input+0x63) [0x80680b3] -> /tmp/dd/libexec/dovecot/imap(io_loop_handler_run+0xe0) [0x80f3210] -> /tmp/dd/libexec/dovecot/imap(io_loop_run+0x20)
Configuration was:
% ./sbin/dovecot -n # 1.2.alpha2: /tmp/dd/etc/dovecot.conf listen: 127.0.0.1 ssl_disable: yes login_dir: /tmp/dd/var/run/dovecot/login login_executable: /tmp/dd/libexec/dovecot/imap-login mail_plugins: fts fts_squat virtual zlib namespace: type: private separator: / location: maildir:~/Mailbox/Maildir inbox: yes list: yes subscriptions: yes namespace: type: private separator: / prefix: mbox/ location: mbox:~/Mailbox/mbox/ list: yes subscriptions: yes namespace: type: private separator: / prefix: virtual/ location: virtual:~/Mailbox/virtual list: yes subscriptions: yes auth default: passdb: driver: pam userdb: driver: passwd
System is Linux/i386. I tried narrowing down the problem to a specific mail folder, but did not succeed, it seems I need to give a number of folders for this problem to occur. The SIGABRT kind of crash occured a lot more often.
On an unrelated note, given the above configuration file, using a dovecot-virtual file like
| mbox/* | all
causes dovecot to complain:
Oct 20 13:56:59 vertikal EXT(lars): : Connection closed bytes=22/350 Oct 20 13:57:03 vertikal EXT(lars): : /home/lars/Mailbox/virtual/test/dovecot-virtual: No mailboxes defined
Greetings, Lars.
On Mon, 2008-10-20 at 15:37 +0200, Lars Noschinski wrote:
(gdb) bt full #0 mailbox_search_result_free (_result=0x8efc0d0) at mailbox-search-result.c:65 result = (struct mail_search_result *) 0x0 i = <value optimized out> __PRETTY_FUNCTION__ = "mailbox_search_result_free" #1 0xb7f4e12e in virtual_storage_mailbox_close (box=0x8efbeb0) at virtual-storage.c:311 i = 0 ret = 0
I couldn't reproduce this, but this should fix it anyway: http://hg.dovecot.org/dovecot-1.2/rev/0738739a8152
#5 0x080c86b8 in view_lookup_seq_range (view=0x9956648, first_uid=1, last_uid=0, first_seq_r=0xbfdce294, last_seq_r=0xbfdce290) at mail-index-view.c:265 #6 0x080c815c in mail_index_lookup_seq_range (view=0x9956648, first_uid=1, last_uid=0, first_seq_r=0xbfdce294, last_seq_r=0xbfdce290) at mail-index-view.c:530 #7 0xb7fa64d6 in virtual_sync_backend_boxes (ctx=0x9e2e3e0) at virtual-sync.c:561
Fixed: ttp://hg.dovecot.org/dovecot-1.2/rev/ba6ec21af651
#5 0x080c86b8 in view_lookup_seq_range (view=0x8eb77e0, first_uid=1, last_uid=0, first_seq_r=0xbfc58124, last_seq_r=0xbfc58120) at mail-index-view.c:265 __PRETTY_FUNCTION__ = "view_lookup_seq_range" #6 0x080c815c in mail_index_lookup_seq_range (view=0x8eb77e0, first_uid=1, last_uid=0, first_seq_r=0xbfc58124, last_seq_r=0xbfc58120) at mail-index-view.c:530 No locals. #7 0xb7f324d6 in virtual_sync_backend_boxes (ctx=0x90f8eb8) at virtual-sync.c:561 i = 10
Same as above.
On an unrelated note, given the above configuration file, using a dovecot-virtual file like
| mbox/* | all
causes dovecot to complain:
Oct 20 13:56:59 vertikal EXT(lars): : Connection closed bytes=22/350 Oct 20 13:57:03 vertikal EXT(lars): : /home/lars/Mailbox/virtual/test/dovecot-virtual: No mailboxes defined
Hello Timo,
thanks for your swift response!
- Timo Sirainen <tss@iki.fi> [08-10-25 20:22]:
I couldn't reproduce this, but this should fix it anyway: http://hg.dovecot.org/dovecot-1.2/rev/0738739a8152 [...] Fixed: ttp://hg.dovecot.org/dovecot-1.2/rev/ba6ec21af651
Thanks! I was just looking at the repository, while you were committing these fixes ;) But these fixes uncovered another bug. I can SELECT now, but FETCH fails:
% ./sbin/dovecot --exec-mail ext /usr/bin/gdb ./libexec/dovecot/imap GNU gdb 6.8-debian Copyright (C) 2008 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 "i486-linux-gnu"... (gdb) run Starting program: /tmp/dd/libexec/dovecot/imap
- PREAUTH [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE SORT THREAD=REFERENCES MULTIAPPEND UNSELECT IDLE CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH SEARCHRES WITHIN CONTEXT=SEARCH] Logged in as lars . SELECT virtual/all
- FLAGS (\Answered \Flagged \Deleted \Seen \Draft Old)
- OK [PERMANENTFLAGS (\Answered \Flagged \Deleted \Seen \Draft Old \*)] Flags permitted.
- 74142 EXISTS
- 0 RECENT
- OK [UNSEEN 10841] First unseen.
- OK [UIDVALIDITY 1224958382] UIDs valid
- OK [UIDNEXT 74143] Predicted next UID
- OK [HIGHESTMODSEQ 1] . OK [READ-WRITE] Select completed. a0060 FETCH 1:74142 (UID FLAGS INTERNALDATE RFC822.SIZE BODY.PEEK[HEADER.FIELDS (DATE FROM SUBJECT TO CC MESSAGE-ID REFERENCES CONTENT-TYPE CONTENT-DESCRIPTION IN-REPLY-TO REPLY-TO LINES LIST-POST X-LABEL)])
Program received signal SIGABRT, Aborted. 0xb7ed8556 in raise () from /lib/libc.so.6 (gdb) bt full #0 0xb7ed8556 in raise () from /lib/libc.so.6 No symbol table info available. #1 0xb7ed9d78 in abort () from /lib/libc.so.6 No symbol table info available. #2 0x080eade5 in default_fatal_finish (type=<value optimized out>, status=0) at failures.c:150 backtrace = 0x99356c0 "/tmp/dd/libexec/dovecot/imap [0x80eadd1] -> /tmp/dd/libexec/dovecot/imap(i_syslog_fatal_handler+0x34) [0x80eaea4] -> /tmp/dd/libexec/dovecot/imap [0x80ea7e9] -> /tmp/dd/libexec/dovecot/imap [0x80d5e93"... #3 0x080eaea4 in i_syslog_fatal_handler (type=LOG_TYPE_PANIC, status=0, fmt=0x80fff0c "file %s: line %d (%s): assertion failed: (%s)", args=0xbfa23ef4 "g�020\bP") at failures.c:308 No locals. #4 0x080ea7e9 in i_panic (format=0x80fff0c "file %s: line %d (%s): assertion failed: (%s)") at failures.c:197 No locals. #5 0x080d5e93 in mail_cache_decision_state_update (view=0x9bc5ff0, seq=9, field=12) at mail-cache-decisions.c:80 cache = (struct mail_cache *) 0x9c5f750 hdr = <value optimized out> uid = <value optimized out> __PRETTY_FUNCTION__ = "mail_cache_decision_state_update" #6 0x080b6f47 in mail_cache_lookup_headers (view=0x9bc5ff0, dest=0xa024320, seq=9, field_idxs=0x9fee430, fields_count=14) at mail-cache-lookup.c:479 _data_stack_cur_id = 5 ret = <value optimized out> #7 0x080a1bd1 in index_mail_get_header_stream (_mail=0x9f85ff0, _headers=0x9fee418, stream_r=0x99417cc) at index-mail-headers.c:740 input = (struct istream *) 0x1 dest = (string_t *) 0xa024320 #8 0xb7ff9a71 in virtual_mail_get_header_stream (mail=0xa029540, headers=0x9fee418, stream_r=0x99417cc) at virtual-mail.c:209 No locals. #9 0x0806c6f1 in fetch_body_header_fields (ctx=0x9941778, mail=0x6, body=0x9941a98) at imap-fetch-body.c:451 size = {physical_size = 578317383981219944, virtual_size = 167833648, lines = 89} old_offset = <value optimized out> #10 0x08069c55 in imap_fetch_more (ctx=0x9941778) at imap-fetch.c:479 ret = <value optimized out> __PRETTY_FUNCTION__ = "imap_fetch_more" #11 0x080611b3 in cmd_fetch (cmd=0x9941730) at cmd-fetch.c:218 client = (struct client *) 0x99414b0 ctx = (struct imap_fetch_context *) 0x9941778 args = (const struct imap_arg *) 0x99467b0 search_args = (struct mail_search_args *) 0xa04e7f8 messageset = <value optimized out> ret = <value optimized out> #12 0x0806758c in client_command_input (cmd=0x9941730) at client.c:592 client = (struct client *) 0x99414b0 command = <value optimized out> __PRETTY_FUNCTION__ = "client_command_input" #13 0x08067629 in client_command_input (cmd=0x9941730) at client.c:641 client = (struct client *) 0x99414b0 command = <value optimized out> __PRETTY_FUNCTION__ = "client_command_input" #14 0x08067c2d in client_handle_input (client=0x99414b0) at client.c:682 _data_stack_cur_id = 3 ret = <value optimized out> remove_io = <value optimized out> handled_commands = false #15 0x080680e3 in client_input (client=0x99414b0) at client.c:737 cmd = <value optimized out> output = (struct ostream *) 0x994165c bytes = <value optimized out> __PRETTY_FUNCTION__ = "client_input" #16 0x080f32d0 in io_loop_handler_run (ioloop=0x993dab8) at ioloop-epoll.c:203 ctx = (struct ioloop_handler_context *) 0x993dbb0 event = (const struct epoll_event *) 0x993dbf0 list = (struct io_list *) 0x99416d8 io = (struct io_file *) 0x99416b8 tv = {tv_sec = 1799, tv_usec = 995813} t_id = 2 msecs = <value optimized out> ret = 1 i = 0 j = 0 call = <value optimized out> #17 0x080f2760 in io_loop_run (ioloop=0x993dab8) at ioloop.c:320 No locals. #18 0x0806f58d in main (argc=Cannot access memory at address 0x2f25 ) at main.c:309 No locals.
Oct 25 20:19:40 vertikal EXT(lars): : Panic: file mail-cache-decisions.c: line 80 (mail_cache_decision_state_update): assertion failed: (field < cache->fields_count) Oct 25 20:19:40 vertikal EXT(lars): : Raw backtrace: /tmp/dd/libexec/dovecot/imap [0x80eadd1] -> /tmp/dd/libexec/dovecot/imap(i_syslog_fatal_handler+0x34) [0x80eaea4] -> /tmp/dd/libexec/dovecot/imap [0x80ea7e9] -> /tmp/dd/libexec/dovecot/imap [0x80d5e93] -> /tmp/dd/libexec/dovecot/imap(mail_cache_lookup_headers+0x57) [0x80b6f47] -> /tmp/dd/libexec/dovecot/imap(index_mail_get_header_stream+0x61) [0x80a1bd1] -> /tmp/dd/lib/dovecot/imap/lib20_virtual_plugin.so [0xb7ff9a71] -> /tmp/dd/libexec/dovecot/imap [0x806c6f1] -> /tmp/dd/libexec/dovecot/imap(imap_fetch_more+0x145) [0x8069c55] -> /tmp/dd/libexec/dovecot/imap(cmd_fetch+0x343) [0x80611b3] -> /tmp/dd/libexec/dovecot/imap [0x806758c] -> /tmp/dd/libexec/dovecot/imap [0x8067629] -> /tmp/dd/libexec/dovecot/imap(client_handle_input+0x1d) [0x8067c2d] -> /tmp/dd/libexec/dovecot/imap(client_input+0x63) [0x80680e3] -> /tmp/dd/libexec/dovecot/imap(io_loop_handler_run+0xe0) [0x80f32d0] -> /tmp/dd/libexec/dovecot/imap(io_loop_run+0x20) [0x80f2760] -> /tmp/dd/libexec/dovecot/
On an unrelated note, given the above configuration file, using a dovecot-virtual file like
| mbox/* | all
causes dovecot to complain:
Oct 20 13:56:59 vertikal EXT(lars): : Connection closed bytes=22/350 Oct 20 13:57:03 vertikal EXT(lars): : /home/lars/Mailbox/virtual/test/dovecot-virtual: No mailboxes defined
Thanks. This works now, with a minor glitch. The directory backing the "mbox" namespace looks like this:
Archiv/list1
Archiv/list2
foo1
foo2As "Archiv" is a directory, it is not selectable (of course). Using the above dovecot-virtual file, I get "NO Mailbox isn't selectable: Archiv" if I try to select the virtual mbox.
This message does not occur, if use "*" instead of "mbox/*" as mailbox pattern.
BTW: I really like dovecot's easy-to-reach debugging facilities.
- Lars.
On Sat, 2008-10-25 at 20:38 +0200, Lars Noschinski wrote:
Thanks! I was just looking at the repository, while you were committing these fixes ;) But these fixes uncovered another bug. I can SELECT now, but FETCH fails:
Fixed.
Thanks. This works now, with a minor glitch. The directory backing the "mbox" namespace looks like this:
Archiv/list1 Archiv/list2 foo1 foo2As "Archiv" is a directory, it is not selectable (of course). Using the above dovecot-virtual file, I get "NO Mailbox isn't selectable: Archiv" if I try to select the virtual mbox.
Fixed.
This message does not occur, if use "*" instead of "mbox/*" as mailbox pattern.
Yes, because "*" matches only your maildirs and you don't have non-selectable maildirs. I added a note about this one-namespace-only-per-wildcard to http://wiki.dovecot.org/Plugins/Virtual
Hello!
- Timo Sirainen <tss@iki.fi> [08-10-26 11:37]:
On Sat, 2008-10-25 at 20:38 +0200, Lars Noschinski wrote:
Thanks! I was just looking at the repository, while you were committing these fixes ;) But these fixes uncovered another bug. I can SELECT now, but FETCH fails:
Fixed.
Thanks again. Now we get to another assertion:
Oct 26 11:40:54 vertikal EXT(lars): : Panic: file index-mail-headers.c: line 733 (index_mail_get_header_stream): assertion failed: (_headers->box == _mail->box) Oct 26 11:40:54 vertikal EXT(lars): : Raw backtrace: /tmp/dd1/libexec/dovecot/imap [0x80eae61] -> /tmp/dd1/libexec/dovecot/imap(i_syslog_fatal_handler+0x34) [0x80eaf34] -> /tmp/dd1/libexec/dovecot/imap [0x80ea879] -> /tmp/dd1/libexec/dovecot/imap(index_mail_get_header_stream+0x107) [0x80a1cc7] -> /tmp/dd1/lib/dovecot/imap/lib20_virtual_plugin.so [0xb7fbdca3] -> /tmp/dd1/libexec/dovecot/imap [0x806c6f1] -> /tmp/dd1/libexec/dovecot/imap(imap_fetch_more+0x145) [0x8069c55] -> /tmp/dd1/libexec/dovecot/imap(cmd_fetch+0x343) [0x80611b3] -> /tmp/dd1/libexec/dovecot/imap [0x806758c] -> /tmp/dd1/libexec/dovecot/imap [0x8067629] -> /tmp/dd1/libexec/dovecot/imap(client_handle_input+0x1d) [0x8067c2d] -> /tmp/dd1/libexec/dovecot/imap(client_input+0x63) [0x80680e3] -> /tmp/dd1/libexec/dovecot/imap(io_loop_handler_run+0xe0) [0x80f3360] -> /tmp/dd1/libexec/dovecot/imap(io_loop_run+0x20) [0x80f27f0] -> /tmp/dd1/libexec/dovecot/imap(main+0x59d) [0x806f58d] -> /lib/libc.so.6(__libc_start_main+0xe5) [0xb7e88455] -> /tmp/dd1/libexec/
% ./sbin/dovecot --exec-mail ext /usr/bin/gdb ./libexec/dovecot/imap GNU gdb 6.8-debian Copyright (C) 2008 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 "i486-linux-gnu"... (gdb) run Starting program: /tmp/dd1/libexec/dovecot/imap
- PREAUTH [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE SORT THREAD=REFERENCES MULTIAPPEND UNSELECT IDLE CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH SEARCHRES WITHIN CONTEXT=SEARCH] Logged in as lars . SELECT virtual/all
- FLAGS (\Answered \Flagged \Deleted \Seen \Draft Old)
- OK [PERMANENTFLAGS (\Answered \Flagged \Deleted \Seen \Draft Old \*)] Flags permitted.
- 74171 EXISTS
- 0 RECENT
- OK [UNSEEN 10841] First unseen.
- OK [UIDVALIDITY 1225017599] UIDs valid
- OK [UIDNEXT 74172] Predicted next UID
- OK [HIGHESTMODSEQ 1] . OK [READ-WRITE] Select completed. a0060 FETCH 1:74142 (UID FLAGS INTERNALDATE RFC822.SIZE BODY.PEEK[HEADER.FIELDS (DATE FROM SUBJECT TO CC MESSAGE-ID REFERENCES CONTENT-TYPE CONTENT-DESCRIPTION IN-REPLY-TO REPLY-TO LINES LIST-POST X-LABEL)])
Program received signal SIGABRT, Aborted. 0xb7e9c556 in raise () from /lib/libc.so.6 (gdb) bt full #0 0xb7e9c556 in raise () from /lib/libc.so.6 No symbol table info available. #1 0xb7e9dd78 in abort () from /lib/libc.so.6 No symbol table info available. #2 0x080eae75 in default_fatal_finish (type=<value optimized out>, status=0) at failures.c:150 backtrace = 0x92006c0 "/tmp/dd1/libexec/dovecot/imap [0x80eae61] -> /tmp/dd1/libexec/dovecot/imap(i_syslog_fatal_handler+0x34) [0x80eaf34] -> /tmp/dd1/libexec/dovecot/imap [0x80ea879] -> /tmp/dd1/libexec/dovecot/imap(index_"... #3 0x080eaf34 in i_syslog_fatal_handler (type=LOG_TYPE_PANIC, status=0, fmt=0x80fff8c "file %s: line %d (%s): assertion failed: (%s)", args=0xbfce5a84 "9\200\020\b�\002") at failures.c:308 No locals. #4 0x080ea879 in i_panic (format=0x80fff8c "file %s: line %d (%s): assertion failed: (%s)") at failures.c:197 No locals. #5 0x080a1cc7 in index_mail_get_header_stream (_mail=0x9d8b450, _headers=0x9885050, stream_r=0x920c7cc) at index-mail-headers.c:733 input = (struct istream *) 0x0 dest = <value optimized out> __PRETTY_FUNCTION__ = "index_mail_get_header_stream" #6 0xb7fbdca3 in virtual_mail_get_header_stream (mail=0x9b5c038, headers=0x9885050, stream_r=0x920c7cc) at virtual-mail.c:252 backend_headers = (struct mailbox_header_lookup_ctx *) 0x99823e0 ret = <value optimized out> #7 0x0806c6f1 in fetch_body_header_fields (ctx=0x920c778, mail=0x6, body=0x920ca98) at imap-fetch-body.c:451 size = {physical_size = 578317383984110376, virtual_size = 155418768, lines = 89} old_offset = <value optimized out> #8 0x08069c55 in imap_fetch_more (ctx=0x920c778) at imap-fetch.c:479 ret = <value optimized out> __PRETTY_FUNCTION__ = "imap_fetch_more" #9 0x080611b3 in cmd_fetch (cmd=0x920c730) at cmd-fetch.c:218 client = (struct client *) 0x920c4b0 ctx = (struct imap_fetch_context *) 0x920c778 args = (const struct imap_arg *) 0x92117b0 search_args = (struct mail_search_args *) 0x9dd2a30 messageset = <value optimized out> ret = <value optimized out> #10 0x0806758c in client_command_input (cmd=0x920c730) at client.c:592 client = (struct client *) 0x920c4b0 command = <value optimized out> __PRETTY_FUNCTION__ = "client_command_input" #11 0x08067629 in client_command_input (cmd=0x920c730) at client.c:641 client = (struct client *) 0x920c4b0 command = <value optimized out> __PRETTY_FUNCTION__ = "client_command_input" #12 0x08067c2d in client_handle_input (client=0x920c4b0) at client.c:682 _data_stack_cur_id = 3 ret = <value optimized out> remove_io = <value optimized out> handled_commands = false #13 0x080680e3 in client_input (client=0x920c4b0) at client.c:737 cmd = <value optimized out> output = (struct ostream *) 0x920c65c bytes = <value optimized out> __PRETTY_FUNCTION__ = "client_input" #14 0x080f3360 in io_loop_handler_run (ioloop=0x9208ab8) at ioloop-epoll.c:203 ctx = (struct ioloop_handler_context *) 0x9208bb0 event = (const struct epoll_event *) 0x9208bf0 list = (struct io_list *) 0x920c6d8 io = (struct io_file *) 0x920c6b8 tv = {tv_sec = 1799, tv_usec = 999297} t_id = 2 msecs = <value optimized out> ret = 1 i = 0 j = 0 call = <value optimized out> #15 0x080f27f0 in io_loop_run (ioloop=0x9208ab8) at ioloop.c:320 No locals. #16 0x0806f58d in main (argc=Cannot access memory at address 0x2598 ) at main.c:309 No locals. (gdb)
This message does not occur, if use "*" instead of "mbox/*" as mailbox pattern.
Yes, because "*" matches only your maildirs and you don't have non-selectable maildirs. I added a note about this one-namespace-only-per-wildcard to http://wiki.dovecot.org/Plugins/Virtual
Ah, ok. I already suspected something like that.
- Lars.
On Sun, 2008-10-26 at 11:49 +0100, Lars Noschinski wrote:
#6 0xb7fbdca3 in virtual_mail_get_header_stream (mail=0x9b5c038, headers=0x9885050, stream_r=0x920c7cc) at virtual-mail.c:252 backend_headers = (struct mailbox_header_lookup_ctx *) 0x99823e0 ret = <value optimized out>
Whops, I almost fixed this the last time but left one important part out. Fixed now. :)
- Timo Sirainen <tss@iki.fi> [08-10-26 15:28]:
On Sun, 2008-10-26 at 11:49 +0100, Lars Noschinski wrote:
#6 0xb7fbdca3 in virtual_mail_get_header_stream (mail=0x9b5c038, headers=0x9885050, stream_r=0x920c7cc) at virtual-mail.c:252 backend_headers = (struct mailbox_header_lookup_ctx *) 0x99823e0 ret = <value optimized out>
Whops, I almost fixed this the last time but left one important part out. Fixed now. :)
Yeah, looks good now. Thank you very much!
- Lars.
- Lars Noschinski <lars@public.noschinski.de> [08-10-26 15:31]:
- Timo Sirainen <tss@iki.fi> [08-10-26 15:28]:
On Sun, 2008-10-26 at 11:49 +0100, Lars Noschinski wrote:
#6 0xb7fbdca3 in virtual_mail_get_header_stream (mail=0x9b5c038, headers=0x9885050, stream_r=0x920c7cc) at virtual-mail.c:252 backend_headers = (struct mailbox_header_lookup_ctx *) 0x99823e0 ret = <value optimized out>
Whops, I almost fixed this the last time but left one important part out. Fixed now. :)
Yeah, looks good now. Thank you very much!
And another one to go (using latest hg tip, changeset 8360:7c615ac48711)
% ./sbin/dovecot --exec-mail ext /usr/bin/gdb ./libexec/dovecot/imap GNU gdb 6.8-debian Copyright (C) 2008 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 "i486-linux-gnu"... (gdb) run Starting program: /tmp/dd/libexec/dovecot/imap
- PREAUTH [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE SORT THREAD=REFERENCES MULTIAPPEND UNSELECT IDLE CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH SEARCHRES WITHIN CONTEXT=SEARCH] Logged in as lars . SELECT virtual/alle
Program received signal SIGABRT, Aborted. 0xb7dbd556 in raise () from /lib/libc.so.6 (gdb) bt full #0 0xb7dbd556 in raise () from /lib/libc.so.6 No symbol table info available. #1 0xb7dbed78 in abort () from /lib/libc.so.6 No symbol table info available. #2 0x080eaf15 in default_fatal_finish (type=<value optimized out>, status=0) at failures.c:150 backtrace = 0xa120f60 "/tmp/dd/libexec/dovecot/imap [0x80eaf01] -> /tmp/dd/libexec/dovecot/imap(i_syslog_fatal_handler+0x34) [0x80eafd4] -> /tmp/dd/libexec/dovecot/imap [0x80ea919] -> /tmp/dd/lib/dovecot/imap/lib20_virtual_"... #3 0x080eafd4 in i_syslog_fatal_handler (type=LOG_TYPE_PANIC, status=0, fmt=0xb7ee38af "UID lost unexpectedly", args=0xbfe09004 "\001") at failures.c:308 No locals. #4 0x080ea919 in i_panic (format=0xb7ee38af "UID lost unexpectedly") at failures.c:197 No locals. #5 0xb7ee075e in virtual_sync_external_flags (ctx=0x9f130a8, bbox=0x977ea20, vseq=35152, real_uid=1) at virtual-sync.c:66 flags = <value optimized out> kw_names = <value optimized out> keywords = <value optimized out> #6 0xb7ee230a in virtual_sync_backend_boxes (ctx=0x9f130a8) at virtual-sync.c:977 i = 83 #7 0xb7ee28cf in virtual_storage_sync_init (box=0x977e5e0, flags=65) at virtual-sync.c:1199 ret = <value optimized out> #8 0x080b03b0 in mailbox_sync (box=0x17a8, flags=65, status_items=239, status_r=0xbfe093c8) at mail-storage.c:523 ctx = (struct mailbox_sync_context *) 0x0 #9 0x08064ca8 in cmd_select_full (cmd=0x9775e60, readonly=false) at cmd-select.c:273 client = (struct client *) 0x9775be0 box = (struct mailbox *) 0xbfe09438 ctx = (struct imap_select_context *) 0x9775ea8 args = (const struct imap_arg *) 0x977aee0 mailbox = 0x977af68 "alle" ret = <value optimized out> __PRETTY_FUNCTION__ = "cmd_select_full"
Oct 30 20:09:18 vertikal EXT(lars): : Panic: UID lost unexpectedly Oct 30 20:09:18 vertikal EXT(lars): : Raw backtrace: /tmp/dd/libexec/dovecot/imap [0x80eaf01] -> /tmp/dd/libexec/dovecot/imap(i_syslog_fatal_handler+0x34) [0x80eafd4] -> /tmp/dd/libexec/dovecot/imap [0x80ea919] -> /tmp/dd/lib/dovecot/imap/lib20_virtual_plugin.so [0xb7ee075e] -> /tmp/dd/lib/dovecot/imap/lib20_virtual_plugin.so [0xb7ee230a] -> /tmp/dd/lib/dovecot/imap/lib20_virtual_plugin.so(virtual_storage_sync_init+0x53f) [0xb7ee28cf] -> /tmp/dd/libexec/dovecot/imap(mailbox_sync+0x30) [0x80b03b0] -> /tmp/dd/libexec/dovecot/imap(cmd_select_full+0x3d8) [0x8064ca8] -> /tmp/dd/libexec/dovecot/imap(cmd_select+0x19) [0x8065409] -> /tmp/dd/libexec/dovecot/imap [0x806758c] -> /tmp/dd/libexec/dovecot/imap [0x8067629] -> /tmp/dd/libexec/dovecot/imap(client_handle_input+0x1d) [0x8067c2d] -> /tmp/dd/libexec/dovecot/imap(client_input+0x63) [0x80680e3] -> /tmp/dd/libexec/dovecot/imap(io_loop_handler_run+0xe0) [0x80f3400] -> /tmp/dd/libexec/dovecot/imap(io_loop_run+0x20) [0x80f2890] -> /tmp/dd/libexec/dovecot/imap(main+0x59d)
- Lars Noschinski <lars@public.noschinski.de> [08-10-30 20:13]:
And another one to go (using latest hg tip, changeset 8360:7c615ac48711)
Forgot the dovecot-virtual file:
- mbox/* all
though it also occurs using only "*". And dovecot -n output:
# 1.2.alpha3: /tmp/dd/etc/dovecot.conf # OS: Linux 2.6.26-rc9-00114-gf2260c5-dirty i686 Debian lenny/sid listen: 127.0.0.1 ssl_disable: yes login_dir: /tmp/dd/var/run/dovecot/login login_executable: /tmp/dd/libexec/dovecot/imap-login mail_plugins: fts fts_squat virtual zlib namespace: type: private separator: / location: maildir:~/Mailbox/Maildir:LAYOUT=fs inbox: yes list: yes subscriptions: yes namespace: type: private separator: / prefix: mbox/ location: mbox:~/Mailbox/mbox/ list: yes subscriptions: yes namespace: type: private separator: / prefix: spam/ location: mbox:~/Mailbox/spam/ list: yes subscriptions: yes namespace: type: private separator: / prefix: virtual/ location: virtual:~/Mailbox/virtual list: yes subscriptions: yes auth default: passdb: driver: pam userdb: driver: passwd
Greetings, Lars.
- Lars Noschinski <lars@public.noschinski.de> [08-10-30 20:29]:
- Lars Noschinski <lars@public.noschinski.de> [08-10-30 20:13]:
And another one to go (using latest hg tip, changeset 8360:7c615ac48711)
Forgot the dovecot-virtual file:
- mbox/* all
though it also occurs using only "*". And dovecot -n output:
While trying to produce a smaller testcase, I changed the dovecot-virtual file to
mbox/* all
and the problem went away. It did not reoccur after reverting the change. After this, I also could not reproduce the problem on a copy of the Mailbox, which I produced using cp -rl. Probably I should not have used hardlinks there.
So this sounds like a chaching-related problem to me? Hm, I remember I renamed the virtual folder yesterday (in the filesystem, using mv).
participants (2)
-
Lars Noschinski
-
Timo Sirainen