Panic: file istream.c: line 167 with 2.2.13 + istream.c/.h from dovecot-2-2-dffc6dd2be0d

Wed Aug 20 13:58:56 UTC 2014

On 22 Jul 2014, at 09:20, Toni Mattila <toni at solu.fi> wrote:

> Any further ideas on this one or suggestions how to provide more info?

I still can't reproduce. And I don't understand how it could get into that state. Can you still easily reproduce it with some specific mail? If so, could you send the mail to me (maybe with all the actual sensitive content replaced with 'x' letters or something)?

> 
> Thanks,
> Toni
> 
> On 7.7.2014 14:35, Toni Mattila wrote:
>> Hi,
>> 
>> On 7.7.2014 13:16, Timo Sirainen wrote:
>>> Should be fixed by http://hg.dovecot.org/dovecot-2.2/rev/1a38a85d952e
>> 
>> Nope. Still happens:
>> (gdb) bt
>> #0  0x00568402 in __kernel_vsyscall ()
>> #1  0x0070af30 in raise () from /lib/i686/nosegneg/libc.so.6
>> #2  0x0070c911 in abort () from /lib/i686/nosegneg/libc.so.6
>> #3  0x00d13c14 in default_fatal_finish (type=<value optimized out>,
>> status=0) at failures.c:193
>> #4  0x00d13c9d in i_internal_fatal_handler (ctx=0xbf824104,
>> format=0xd40784 "file %s: line %d (%s): assertion failed: (%s)",
>> args=0xbf824124 "\f��") at failures.c:657
>> #5  0x00d13514 in i_panic (format=0xd40784 "file %s: line %d (%s):
>> assertion failed: (%s)") at failures.c:267
>> #6  0x00d1d99b in i_stream_read (stream=0x85c7d20) at istream.c:170
>> #7  0x00d1dbfb in i_stream_read_data (stream=0x85c7d20,
>> data_r=0xbf824264, size_r=0xbf824268, threshold=31) at istream.c:538
>> #8  0x00d03b5e in message_parser_read_more (ctx=0x85dc020,
>> block_r=0xbf82425c, full_r=0xbf8241db) at message-parser.c:128
>> #9  0x00d05469 in parse_next_body_to_boundary (ctx=0x85dc020,
>> block_r=0xbf82425c) at message-parser.c:361
>> #10 0x00d03cd3 in message_parser_parse_next_block (ctx=0x85dc020,
>> block_r=0xbf82425c) at message-parser.c:1015
>> #11 0x00d03e4c in message_parser_parse_body (ctx=0x85dc020,
>> hdr_callback=0, context=0x0) at message-parser.c:1079
>> #12 0x0026fdd2 in index_mail_parse_body (mail=0x85da810,
>> field=MAIL_CACHE_FLAGS) at index-mail.c:914
>> #13 0x00270c7a in index_mail_get_parts (_mail=0x85da810,
>> parts_r=0xbf824358) at index-mail.c:285
>> #14 0x00245d76 in mail_get_parts (mail=0x85da810, parts_r=0xbf824358) at
>> mail.c:114
>> #15 0x00275a7c in search_match_once (ctx=0x85cbc28) at index-search.c:745
>> #16 0x00276a89 in search_more (ctx=0x85cbc28, mail_r=0xbf824458) at
>> index-search.c:1401
>> #17 0x002775fe in index_storage_search_next_nonblock (_ctx=0x85cbc28,
>> mail_r=0xbf8244c4, tryagain_r=0xbf8244cb) at index-search.c:1677
>> #18 0x0024d2ee in mailbox_search_next_nonblock (ctx=0x85cbc28,
>> mail_r=0xbf8244c4, tryagain_r=0xbf8244cb) at mail-storage.c:1796
>> #19 0x08062b40 in cmd_search_more (cmd=0x85ac430) at imap-search.c:443
>> #20 0x08063079 in imap_search_start (ctx=0x85ac4e8, sargs=0x85d9000,
>> sort_program=0x0) at imap-search.c:610
>> #21 0x08056d86 in cmd_search (cmd=0x85ac430) at cmd-search.c:48
>> #22 0x0805c953 in command_exec (cmd=0x85ac430) at imap-commands.c:158
>> #23 0x0805b69f in client_command_input (cmd=0x85ac430) at imap-client.c:778
>> #24 0x0805b751 in client_command_input (cmd=0x85ac430) at imap-client.c:839
>> #25 0x0805b913 in client_handle_input (client=0x85ab9c8) at
>> imap-client.c:877
>> #26 0x0805bd71 in client_input (client=0x85ab9c8) at imap-client.c:931
>> #27 0x00d25d88 in io_loop_call_io (io=0x85ac3b0) at ioloop.c:441
>> #28 0x00d2775f in io_loop_handler_run_internal (ioloop=0x8596490) at
>> ioloop-epoll.c:220
>> #29 0x00d25e2e in io_loop_handler_run (ioloop=0x8596490) at ioloop.c:488
>> #30 0x00d25eb8 in io_loop_run (ioloop=0x8596490) at ioloop.c:465
>> #31 0x00ccc42d in master_service_run (service=0x85963b8,
>> callback=0x8066000 <client_connected>) at master-service.c:566
>> #32 0x08065e9f in main (argc=Cannot access memory at address 0x0
>> ) at main.c:400
>> 
>> (gdb) f 6
>> #6  0x00d1d99b in i_stream_read (stream=0x85c7d20) at istream.c:170
>> 170                     i_assert(_stream->skip != _stream->pos);
>> (gdb) p *_stream
>> $1 = {m = {refcount = 2, name = 0x0, error = 0x85cc0a8 "Cached message
>> size smaller than expected (3082265 < 3082342)", close = 0xd1e1e0
>> <i_stream_default_close>, destroy = 0xd1e400 <i_stream_default_destroy>,
>>     set_max_buffer_size = 0xd1e140
>> <i_stream_default_set_max_buffer_size>, destroy_callbacks = {arr =
>> {buffer = 0x85cc070, element_size = 8}, v = 0x85cc070, v_modifiable =
>> 0x85cc070}}, read = 0x26bf10 <i_stream_mail_read>,
>>   seek = 0xd1cee0 <i_stream_default_seek_seekable>, sync = 0, stat =
>> 0xd1d140 <i_stream_default_stat>, get_size = 0xd1cf10
>> <i_stream_default_get_size>, switch_ioloop = 0, istream = {v_offset = 0,
>> stream_errno = 22, mmaped = 0,
>>     blocking = 1, closed = 0, readable_fd = 0, seekable = 1, eof = 0,
>> real_stream = 0x85c7ce8}, fd = 16, abs_start_offset = 0, statbuf =
>> {st_dev = 2050, __pad1 = 0, __st_ino = 45313747, st_mode = 33152,
>> st_nlink = 1, st_uid = 89,
>>     st_gid = 89, st_rdev = 0, __pad2 = 0, st_size = 3082342, st_blksize
>> = 4096, st_blocks = 6032, st_atim = {tv_sec = 1334256398, tv_nsec = 0},
>> st_mtim = {tv_sec = 1303455370, tv_nsec = 0}, st_ctim = {tv_sec =
>> 1334256398, tv_nsec = 0},
>>     st_ino = 45313747}, io = 0x0,
>>   buffer = 0x863cb30
>> "\nALUNAAC2DQAAtw0AALgNAAC5DQAAug0AALsNAAC8DQAAvQ0AAL4NAAC/DQAAwA0AAMENAADCDQAA\nww0AAMQNAADFDQAAxg0AAMcNAADIDQAAyQ0AAMoNAADLDQAAzA0AAM0NAADODQAAzw0AANANAADR\nDQAA0g0AANMNAADUDQAA1Q0AANYNAADXDQAA2A0AANkNA"...,
>> 
>>   w_buffer = 0x0, buffer_size = 0, max_buffer_size = 8192,
>> init_buffer_size = 8192, skip = 0, pos = 0, try_alloc_limit = 0, parent
>> = 0x8600988, parent_start_offset = 0, parent_expected_offset = 3077052,
>> access_counter = 1136,
>>   line_str = 0x0, line_crlf = 0, return_nolf_line = 0,
>> stream_size_passthrough = 1}
>> 
>> (gdb) p *_stream.parent.real_stream
>> $2 = {m = {refcount = 1, name = 0x85c7c70
>> "/cencored/Maildir/cur/1303455370.23018.cencored.fi,S=3082265:2,RS",
>> error = 0x0, close = 0xd217d0 <i_stream_file_close>,
>>     destroy = 0xd1e400 <i_stream_default_destroy>, set_max_buffer_size
>> = 0xd1e140 <i_stream_default_set_max_buffer_size>, destroy_callbacks =
>> {arr = {buffer = 0x0, element_size = 0}, v = 0x0, v_modifiable = 0x0}},
>>   read = 0xd213f0 <i_stream_file_read>, seek = 0xd212c0
>> <i_stream_file_seek>, sync = 0xd21000 <i_stream_file_sync>, stat =
>> 0xd21200 <i_stream_file_stat>, get_size = 0xd1cf10
>> <i_stream_default_get_size>, switch_ioloop = 0, istream = {
>>     v_offset = 3077052, stream_errno = 0, mmaped = 0, blocking = 1,
>> closed = 0, readable_fd = 1, seekable = 1, eof = 0, real_stream =
>> 0x8600950}, fd = 16, abs_start_offset = 0, statbuf = {st_dev = 2050,
>> __pad1 = 0, __st_ino = 45313747,
>>     st_mode = 33152, st_nlink = 1, st_uid = 89, st_gid = 89, st_rdev =
>> 0, __pad2 = 0, st_size = 3082342, st_blksize = 4096, st_blocks = 6032,
>> st_atim = {tv_sec = 1334256398, tv_nsec = 0}, st_mtim = {tv_sec =
>> 1303455370, tv_nsec = 0},
>>     st_ctim = {tv_sec = 1334256398, tv_nsec = 0}, st_ino = 45313747},
>> io = 0x0,
>>   buffer = 0x863cb30
>> "\nALUNAAC2DQAAtw0AALgNAAC5DQAAug0AALsNAAC8DQAAvQ0AAL4NAAC/DQAAwA0AAMENAADCDQAA\nww0AAMQNAADFDQAAxg0AAMcNAADIDQAAyQ0AAMoNAADLDQAAzA0AAM0NAADODQAAzw0AANANAADR\nDQAA0g0AANMNAADUDQAA1Q0AANYNAADXDQAA2A0AANkNA"...,
>> 
>>   w_buffer = 0x863cb30
>> "\nALUNAAC2DQAAtw0AALgNAAC5DQAAug0AALsNAAC8DQAAvQ0AAL4NAAC/DQAAwA0AAMENAADCDQAA\nww0AAMQNAADFDQAAxg0AAMcNAADIDQAAyQ0AAMoNAADLDQAAzA0AAM0NAADODQAAzw0AANANAADR\nDQAA0g0AANMNAADUDQAA1Q0AANYNAADXDQAA2A0AANkNA"...,
>> 
>>   buffer_size = 8192, max_buffer_size = 8192, init_buffer_size = 8192,
>> skip = 0, pos = 5290, try_alloc_limit = 0, parent = 0x0,
>> parent_start_offset = 0, parent_expected_offset = 0, access_counter =
>> 1136, line_str = 0x0, line_crlf = 0,
>>   return_nolf_line = 0, stream_size_passthrough = 0}