[Dovecot] SIGBART/SIGSEGV while SELECTing virtual folder

20 Oct 2008

      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.

[Dovecot] SIGBART/SIGSEGV while SELECTing virtual folder

Lars Noschinski