dovecot - Feb 2008 - (message_parse_header_next): assertion failed:, +(IS_LWSP(line->value[0])) 1.1beta14

I noticed these happen when one of my users searches his Trash folder 
which he doesn't empty.
He uses thunderbird and it is reproducable.

Feb  5 22:47:39 boomhauer dovecot: IMAP(username): file 
message-header-parser.c: line 350 (message_parse_header_next): assertion 
failed:
+(IS_LWSP(line->value[0]))
Feb  5 22:47:41 boomhauer dovecot: child 8022 (imap) killed with signal 6
Feb  5 22:48:21 boomhauer dovecot: IMAP(username): file 
message-header-parser.c: line 350 (message_parse_header_next): assertion 
failed:
+(IS_LWSP(line->value[0]))
Feb  5 22:48:24 boomhauer dovecot: child 8121 (imap) killed with signal 6
Feb  5 22:49:13 boomhauer dovecot: IMAP(username): file 
message-header-parser.c: line 350 (message_parse_header_next): assertion 
failed:
+(IS_LWSP(line->value[0]))
Feb  5 22:49:15 boomhauer dovecot: child 8171 (imap) killed with signal 6

I hope this is enough of a backtrace, let me know if not:

GNU gdb 6.1.1 [FreeBSD]
Copyright 2004 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain 
conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB.  Type "show warranty" for
details.
This GDB was configured as "amd64-marcel-freebsd"...
Core was generated by `imap'.
Program terminated with signal 6, Aborted.
Reading symbols from /usr/local/lib/libiconv.so.3...done.
Loaded symbols for /usr/local/lib/libiconv.so.3
Reading symbols from /lib/libc.so.6...done.
Loaded symbols for /lib/libc.so.6
Reading symbols from /usr/local/lib/dovecot/imap/lib01_acl_plugin.so...done.
Loaded symbols for /usr/local/lib/dovecot/imap/lib01_acl_plugin.so
Reading symbols from /usr/local/lib/dovecot/imap/lib20_fts_plugin.so...done.
Loaded symbols for /usr/local/lib/dovecot/imap/lib20_fts_plugin.so
Reading symbols from 
/usr/local/lib/dovecot/imap/lib21_fts_squat_plugin.so...done.
Loaded symbols for /usr/local/lib/dovecot/imap/lib21_fts_squat_plugin.so
Reading symbols from /libexec/ld-elf.so.1...done.
Loaded symbols for /libexec/ld-elf.so.1
#0  0x00000000109d54ac in __res_pquery () from /lib/libc.so.6
(gdb) bt
#0  0x00000000109d54ac in __res_pquery () from /lib/libc.so.6
#1  0x00000000004a8e1b in i_panic (format=0x4d60e0 "Tue") at
failures.c:191
#2  0x00000000004a0149 in message_parse_header_next (ctx=0x18c3f00, 
hdr_r=0x7fffffffdff0) at message-header-parser.c:341
#3  0x00000000004a11e9 in parse_content_type (ctx=0x600180, hdr=0x0) at 
message-parser.c:441
#4  0x00000000004a1bb6 in message_parser_init_from_parts 
(parts=0x450f848, input=0x7fffffffe0c0, hdr_flags=32767, flags=16769184)
    at message-parser.c:718
#5  0x0000000010c2355d in fts_mailbox_search_next_nonblock () from 
/usr/local/lib/dovecot/imap/lib20_fts_plugin.so
#6  0x000000000046b353 in mailbox_search_deinit (_ctx=0xc42200) at 
mail-storage.c:624
#7  0x0000000000418f2f in imap_search_deinit (cmd=0x60c300, 
ctx=0x61d048) at cmd-search.c:64
#8  0x000000000041916e in cmd_search_more (cmd=0x4b2216) at cmd-search.c:119
#9  0x00000000004b25ef in io_loop_handle_timeouts_real (ioloop=0x5ff240) 
at ioloop.c:257
#10 0x00000000004b263d in io_loop_handle_timeouts_real (ioloop=0x5ff240) 
at ioloop.c:267
#11 0x00000000004b351e in io_loop_handler_run (ioloop=0x5ff240) at 
ioloop-kqueue.c:123
#12 0x00000000004b2690 in io_loop_handle_timeouts_real (ioloop=0x5ff240) 
at ioloop.c:280
#13 0x00000000004265de in main_deinit () at main.c:269
#14 0x000000000041418e in _start (ap=0x0, cleanup=0x7fffffffe6ad) at 
/usr/src/lib/csu/amd64/crt1.c:69
#15 0x00007fffffffe6ca in ?? ()
#16 0x00007fffffffe6dd in ?? ()
#17 0x00007fffffffe6f8 in ?? ()
#18 0x00007fffffffe709 in ?? ()
#19 0x00007fffffffe71a in ?? ()
#20 0x00007fffffffe733 in ?? ()
#21 0x00007fffffffe747 in ?? ()

# 1.1.beta14: /usr/local/etc/dovecot.conf
ssl_cert_file: /usr/local/etc/apache2/ssl/mail.pem
ssl_key_file: /usr/local/etc/apache2/ssl/mail.pem
login_dir: /var/run/dovecot/login
login_executable: /usr/local/libexec/dovecot/imap-login
mail_max_userip_connections: 25
verbose_proctitle: yes
first_valid_uid: 1000
first_valid_gid: 1000
mail_extra_groups: postlocal
mail_location: 
maildir:%h/Maildir:CONTROL=%h/Maildir/dovecot/private/control:INDEX=%h/Maildir/dovecot/private/indexes
mmap_disable: yes
mail_nfs_storage: yes
mail_nfs_index: yes
mail_drop_priv_before_exec: yes
mail_plugins: acl fts fts_squat
mail_log_max_lines_per_sec: 0
imap_client_workarounds: delay-newmail netscape-eoh tb-extra-mailbox-sep
namespace:
  type: private
  separator: /
  inbox: yes
  list: yes
  subscriptions: yes
namespace:
  type: private
  separator: /
  prefix: mail/
  hidden: yes
  subscriptions: yes
namespace:
  type: private
  separator: /
  prefix: Mail/
  hidden: yes
  subscriptions: yes
namespace:
  type: public
  separator: /
  prefix: #shared/decs/
  location: 
maildir:/egr/mail/shared/decs:CONTROL=%h/Maildir/dovecot/public/control/decs:INDEX=%h/Maildir/dovecot/public/indexes/decs
  list: yes
  subscriptions: yes
auth default:
  passdb:
    driver: pam
  userdb:
    driver: passwd
    args: system_user  socket:
    type: listen
    client:
      path: /var/spool/postfix/private/auth
      mode: 384
      user: postfix
      group: postfix
plugin:
  acl: vfile:/usr/local/etc/dovecot-acls:cache_secs=10
  fts: squat

Adam McDougall wrote:
> I noticed these happen when one of my users searches his Trash folder 
> which he doesn't empty.
> He uses thunderbird and it is reproducable.
>
> Feb 5 22:47:39 boomhauer dovecot: IMAP(username): file 
> message-header-parser.c: line 350 (message_parse_header_next): 
> assertion failed:
> +(IS_LWSP(line->value[0]))
> Feb 5 22:47:41 boomhauer dovecot: child 8022 (imap) killed with signal 6
> Feb 5 22:48:21 boomhauer dovecot: IMAP(username): file 
> message-header-parser.c: line 350 (message_parse_header_next): 
> assertion failed:
> +(IS_LWSP(line->value[0]))
> Feb 5 22:48:24 boomhauer dovecot: child 8121 (imap) killed with signal 6
> Feb 5 22:49:13 boomhauer dovecot: IMAP(username): file 
> message-header-parser.c: line 350 (message_parse_header_next): 
> assertion failed:
> +(IS_LWSP(line->value[0]))
> Feb 5 22:49:15 boomhauer dovecot: child 8171 (imap) killed with signal 6
>
> I hope this is enough of a backtrace, let me know if not:
>
> GNU gdb 6.1.1 [FreeBSD]
> Copyright 2004 Free Software Foundation, Inc.
> GDB is free software, covered by the GNU General Public License, and 
> you are
> welcome to change it and/or distribute copies of it under certain 
> conditions.
> Type "show copying" to see the conditions.
> There is absolutely no warranty for GDB. Type "show warranty" for
> details.
> This GDB was configured as "amd64-marcel-freebsd"...
> Core was generated by `imap'.
> Program terminated with signal 6, Aborted.
> Reading symbols from /usr/local/lib/libiconv.so.3...done.
> Loaded symbols for /usr/local/lib/libiconv.so.3
> Reading symbols from /lib/libc.so.6...done.
> Loaded symbols for /lib/libc.so.6
> Reading symbols from 
> /usr/local/lib/dovecot/imap/lib01_acl_plugin.so...done.
> Loaded symbols for /usr/local/lib/dovecot/imap/lib01_acl_plugin.so
> Reading symbols from 
> /usr/local/lib/dovecot/imap/lib20_fts_plugin.so...done.
> Loaded symbols for /usr/local/lib/dovecot/imap/lib20_fts_plugin.so
> Reading symbols from 
> /usr/local/lib/dovecot/imap/lib21_fts_squat_plugin.so...done.
> Loaded symbols for /usr/local/lib/dovecot/imap/lib21_fts_squat_plugin.so
> Reading symbols from /libexec/ld-elf.so.1...done.
> Loaded symbols for /libexec/ld-elf.so.1
> #0 0x00000000109d54ac in __res_pquery () from /lib/libc.so.6
>
Sorry, maybe bt full would be more helpful:
#0 0x00000000109d54ac in __res_pquery () from /lib/libc.so.6
No symbol table info available.
#1 0x00000000004a8e1b in i_panic (format=0x4d60e0 "Tue") at
failures.c:191
args = {{gp_offset = 40, fp_offset = 48, overflow_arg_area = 
0x7fffffffdf30, reg_save_area = 0x7fffffffde70}}
#2 0x00000000004a0149 in message_parse_header_next (ctx=0x18c3f00, 
hdr_r=0x7fffffffdff0) at message-header-parser.c:341
line = (struct message_header_line *) 0x18c3f00
msg = (const unsigned char *) 0x4511000 ""
i = 46
size = 46
startpos = 0
colon_pos = 0
parse_size = 361
ret = 1
continued = true
continues = false
last_no_newline = true
last_crlf = false
no_newline = false
crlf_newline = false
__PRETTY_FUNCTION__ = "message_parse_header_next"
#3 0x00000000004a11e9 in parse_content_type (ctx=0x600180, hdr=0x0) at 
message-parser.c:441
parser = {data = 0x7fffffffe000 "?????\177", end = 0x1004a773d
<Address
0x1004a773d out of bounds>, last_comment = 0x1ffffe010}
key = 0x4a11e9 "?H\215u?H\215}??\t,"
value = 0x7fffffffe010 "@????\177"
content_type = (string_t *) 0x1
#4 0x00000000004a1bb6 in message_parser_init_from_parts 
(parts=0x450f848, input=0x7fffffffe0c0, hdr_flags=32767, flags=16769184)
at message-parser.c:718
ctx = (struct message_parser_ctx *) 0xffffe040
#5 0x0000000010c2355d in fts_mailbox_search_next_nonblock () from 
/usr/local/lib/dovecot/imap/lib20_fts_plugin.so
No symbol table info available.
#6 0x000000000046b353 in mailbox_search_deinit (_ctx=0xc42200) at 
mail-storage.c:624
ctx = (struct mail_search_context *) 0xd8f448
#7 0x0000000000418f2f in imap_search_deinit (cmd=0x60c300, ctx=0x61d048) 
at cmd-search.c:64
ret = 0
#8 0x000000000041916e in cmd_search_more (cmd=0x4b2216) at cmd-search.c:119
ctx = (struct imap_search_context *) 0x7fffffffe1e0
end_time = {tv_sec = 140737488347616, tv_usec = 4297070}
tryagain = false
ret = 3
#9 0x00000000004b25ef in io_loop_handle_timeouts_real (ioloop=0x5ff240) 
at ioloop.c:257
diff = 12939328
item = (struct priorityq_item *) 0xc57040
tv = {tv_sec = 0, tv_usec = 0}
tv_call = {tv_sec = 1202269828, tv_usec = 256050}
t_id = 3
#10 0x00000000004b263d in io_loop_handle_timeouts_real (ioloop=0x5ff240) 
at ioloop.c:267
item = (struct priorityq_item *) 0x20060a0e8
tv = {tv_sec = 140737488347728, tv_usec = 4924989}
tv_call = {tv_sec = 12939328, tv_usec = 6287936}
t_id = 0
#11 0x00000000004b351e in io_loop_handler_run (ioloop=0x5ff240) at 
ioloop-kqueue.c:123
ctx = (struct ioloop_handler_context *) 0x60a0e0
events = (struct kevent *) 0x60e000
event = (const struct kevent *) 0x60e000
tv = {tv_sec = 0, tv_usec = 0}
ts = {tv_sec = 0, tv_nsec = 0}
io = (struct io_file *) 0x5ff940
events_count = 4
t_id = 2
ret = 0
i = 0
__PRETTY_FUNCTION__ = "io_loop_handler_run"
#12 0x00000000004b2690 in io_loop_handle_timeouts_real (ioloop=0x5ff240) 
at ioloop.c:280
timeout = (struct timeout *) 0x60e000
item = (struct priorityq_item *) 0x609448
tv = {tv_sec = 140737488347872, tv_usec = 4925072}
tv_call = {tv_sec = 6332640, tv_usec = 6287936}
t_id = 0
#13 0x00000000004265de in main_deinit () at main.c:269
log_prefix = '\0' <repeats 16 times>, "?\036C",
'\0' <repeats 93 times>,
"p?C", '\0' <repeats 12 times>
log_io = (struct io *) 0x0
modules = (struct module *) 0x0
namespace_pool = 0x44d980
imap_max_line_length = 0
logout_format = 0x0
ioloop = (struct ioloop *) 0x0
client_workarounds = 6329376
capability_string = (string_t *) 0x0
hook_client_created = (void (*)(struct client **)) 0
client_workaround_list = {{name = 0x4c5ce4 "l index", num = 160},
{name
= 0x4c5ceb "", num = 164}, {
name = 0x4c5cf8 "list index desynced: Children flags for uid=%u wrong in 
mail index", num = 168}, {name = 0x0, num = 0}, {
name = 0x5fe430 "\002", num = 0}}
#14 0x000000000041418e in _start (ap=0x0, cleanup=0x7fffffffe6ad) at 
/usr/src/lib/csu/amd64/crt1.c:69
argc = 32767
argv = (char **) 0x7fffffffe6a0
env = (char **) 0x3
s = 0x0
#15 0x00007fffffffe6ca in ?? ()
No symbol table info available.
#16 0x00007fffffffe6dd in ?? ()
No symbol table info available.

>
> # 1.1.beta14: /usr/local/etc/dovecot.conf
> ssl_cert_file: /usr/local/etc/apache2/ssl/mail.pem
> ssl_key_file: /usr/local/etc/apache2/ssl/mail.pem
> login_dir: /var/run/dovecot/login
> login_executable: /usr/local/libexec/dovecot/imap-login
> mail_max_userip_connections: 25
> verbose_proctitle: yes
> first_valid_uid: 1000
> first_valid_gid: 1000
> mail_extra_groups: postlocal
> mail_location: 
>
maildir:%h/Maildir:CONTROL=%h/Maildir/dovecot/private/control:INDEX=%h/Maildir/dovecot/private/indexes
>
> mmap_disable: yes
> mail_nfs_storage: yes
> mail_nfs_index: yes
> mail_drop_priv_before_exec: yes
> mail_plugins: acl fts fts_squat
> mail_log_max_lines_per_sec: 0
> imap_client_workarounds: delay-newmail netscape-eoh tb-extra-mailbox-sep
> namespace:
> type: private
> separator: /
> inbox: yes
> list: yes
> subscriptions: yes
> namespace:
> type: private
> separator: /
> prefix: mail/
> hidden: yes
> subscriptions: yes
> namespace:
> type: private
> separator: /
> prefix: Mail/
> hidden: yes
> subscriptions: yes
> namespace:
> type: public
> separator: /
> prefix: #shared/decs/
> location: 
>
maildir:/egr/mail/shared/decs:CONTROL=%h/Maildir/dovecot/public/control/decs:INDEX=%h/Maildir/dovecot/public/indexes/decs
>
> list: yes
> subscriptions: yes
> auth default:
> passdb:
> driver: pam
> userdb:
> driver: passwd
> args: system_user> socket:
> type: listen
> client:
> path: /var/spool/postfix/private/auth
> mode: 384
> user: postfix
> group: postfix
> plugin:
> acl: vfile:/usr/local/etc/dovecot-acls:cache_secs=10
> fts: squat
>
>

On Wed, 2008-02-06 at 00:28 -0500, Adam McDougall wrote:
> I noticed these happen when one of my users searches his Trash folder 
> which he doesn't empty.
> He uses thunderbird and it is reproducable.
> 
> Feb  5 22:47:39 boomhauer dovecot: IMAP(username): file 
> message-header-parser.c: line 350 (message_parse_header_next): assertion 
> failed:
> +(IS_LWSP(line->value[0]))
I can't really understand how this is possible. I tried a few ways to
reproduce this but couldn't. Can you reproduce this by copying the mails
to a test account and then identify which mail causes it?

It looks like there's a Content-Type header which continues to a new
line, but the variables in the bt full show that the second line is
actually empty.. I guess it could be also that the backtrace is just a
bit broken (it clearly is in some places).
> Feb  5 22:47:41 boomhauer dovecot: child 8022 (imap) killed with signal 6
> Feb  5 22:48:21 boomhauer dovecot: IMAP(username): file 
> message-header-parser.c: line 350 (message_parse_header_next): assertion 
> failed:
> +(IS_LWSP(line->value[0]))
> Feb  5 22:48:24 boomhauer dovecot: child 8121 (imap) killed with signal 6
> Feb  5 22:49:13 boomhauer dovecot: IMAP(username): file 
> message-header-parser.c: line 350 (message_parse_header_next): assertion 
> failed:
> +(IS_LWSP(line->value[0]))
> Feb  5 22:49:15 boomhauer dovecot: child 8171 (imap) killed with signal 6
> 
> I hope this is enough of a backtrace, let me know if not:
> 
> GNU gdb 6.1.1 [FreeBSD]
> Copyright 2004 Free Software Foundation, Inc.
> GDB is free software, covered by the GNU General Public License, and you
are
> welcome to change it and/or distribute copies of it under certain 
> conditions.
> Type "show copying" to see the conditions.
> There is absolutely no warranty for GDB.  Type "show warranty"
for details.
> This GDB was configured as "amd64-marcel-freebsd"...
> Core was generated by `imap'.
> Program terminated with signal 6, Aborted.
> Reading symbols from /usr/local/lib/libiconv.so.3...done.
> Loaded symbols for /usr/local/lib/libiconv.so.3
> Reading symbols from /lib/libc.so.6...done.
> Loaded symbols for /lib/libc.so.6
> Reading symbols from
/usr/local/lib/dovecot/imap/lib01_acl_plugin.so...done.
> Loaded symbols for /usr/local/lib/dovecot/imap/lib01_acl_plugin.so
> Reading symbols from
/usr/local/lib/dovecot/imap/lib20_fts_plugin.so...done.
> Loaded symbols for /usr/local/lib/dovecot/imap/lib20_fts_plugin.so
> Reading symbols from 
> /usr/local/lib/dovecot/imap/lib21_fts_squat_plugin.so...done.
> Loaded symbols for /usr/local/lib/dovecot/imap/lib21_fts_squat_plugin.so
> Reading symbols from /libexec/ld-elf.so.1...done.
> Loaded symbols for /libexec/ld-elf.so.1
> #0  0x00000000109d54ac in __res_pquery () from /lib/libc.so.6
> (gdb) bt
> #0  0x00000000109d54ac in __res_pquery () from /lib/libc.so.6
> #1  0x00000000004a8e1b in i_panic (format=0x4d60e0 "Tue") at
failures.c:191
> #2  0x00000000004a0149 in message_parse_header_next (ctx=0x18c3f00, 
> hdr_r=0x7fffffffdff0) at message-header-parser.c:341
> #3  0x00000000004a11e9 in parse_content_type (ctx=0x600180, hdr=0x0) at 
> message-parser.c:441
> #4  0x00000000004a1bb6 in message_parser_init_from_parts 
> (parts=0x450f848, input=0x7fffffffe0c0, hdr_flags=32767, flags=16769184)
>     at message-parser.c:718
> #5  0x0000000010c2355d in fts_mailbox_search_next_nonblock () from 
> /usr/local/lib/dovecot/imap/lib20_fts_plugin.so
> #6  0x000000000046b353 in mailbox_search_deinit (_ctx=0xc42200) at 
> mail-storage.c:624
> #7  0x0000000000418f2f in imap_search_deinit (cmd=0x60c300, 
> ctx=0x61d048) at cmd-search.c:64
> #8  0x000000000041916e in cmd_search_more (cmd=0x4b2216) at
cmd-search.c:119
> #9  0x00000000004b25ef in io_loop_handle_timeouts_real (ioloop=0x5ff240) 
> at ioloop.c:257
> #10 0x00000000004b263d in io_loop_handle_timeouts_real (ioloop=0x5ff240) 
> at ioloop.c:267
> #11 0x00000000004b351e in io_loop_handler_run (ioloop=0x5ff240) at 
> ioloop-kqueue.c:123
> #12 0x00000000004b2690 in io_loop_handle_timeouts_real (ioloop=0x5ff240) 
> at ioloop.c:280
> #13 0x00000000004265de in main_deinit () at main.c:269
> #14 0x000000000041418e in _start (ap=0x0, cleanup=0x7fffffffe6ad) at 
> /usr/src/lib/csu/amd64/crt1.c:69
> #15 0x00007fffffffe6ca in ?? ()
> #16 0x00007fffffffe6dd in ?? ()
> #17 0x00007fffffffe6f8 in ?? ()
> #18 0x00007fffffffe709 in ?? ()
> #19 0x00007fffffffe71a in ?? ()
> #20 0x00007fffffffe733 in ?? ()
> #21 0x00007fffffffe747 in ?? ()
> 
> # 1.1.beta14: /usr/local/etc/dovecot.conf
> ssl_cert_file: /usr/local/etc/apache2/ssl/mail.pem
> ssl_key_file: /usr/local/etc/apache2/ssl/mail.pem
> login_dir: /var/run/dovecot/login
> login_executable: /usr/local/libexec/dovecot/imap-login
> mail_max_userip_connections: 25
> verbose_proctitle: yes
> first_valid_uid: 1000
> first_valid_gid: 1000
> mail_extra_groups: postlocal
> mail_location: 
>
maildir:%h/Maildir:CONTROL=%h/Maildir/dovecot/private/control:INDEX=%h/Maildir/dovecot/private/indexes
> mmap_disable: yes
> mail_nfs_storage: yes
> mail_nfs_index: yes
> mail_drop_priv_before_exec: yes
> mail_plugins: acl fts fts_squat
> mail_log_max_lines_per_sec: 0
> imap_client_workarounds: delay-newmail netscape-eoh tb-extra-mailbox-sep
> namespace:
>   type: private
>   separator: /
>   inbox: yes
>   list: yes
>   subscriptions: yes
> namespace:
>   type: private
>   separator: /
>   prefix: mail/
>   hidden: yes
>   subscriptions: yes
> namespace:
>   type: private
>   separator: /
>   prefix: Mail/
>   hidden: yes
>   subscriptions: yes
> namespace:
>   type: public
>   separator: /
>   prefix: #shared/decs/
>   location: 
>
maildir:/egr/mail/shared/decs:CONTROL=%h/Maildir/dovecot/public/control/decs:INDEX=%h/Maildir/dovecot/public/indexes/decs
>   list: yes
>   subscriptions: yes
> auth default:
>   passdb:
>     driver: pam
>   userdb:
>     driver: passwd
>     args: system_user>   socket:
>     type: listen
>     client:
>       path: /var/spool/postfix/private/auth
>       mode: 384
>       user: postfix
>       group: postfix
> plugin:
>   acl: vfile:/usr/local/etc/dovecot-acls:cache_secs=10
>   fts: squat
> 
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 189 bytes
Desc: This is a digitally signed message part
URL:
<http://dovecot.org/pipermail/dovecot/attachments/20080206/a7ab869e/attachment-0002.bin>