On 14/08/2009 9:00 AM, Timo Sirainen wrote:
On Thu, 2009-08-13 at 12:10 +1000, Phillip Macey wrote:
Aug 12 15:52:25 fury dovecot: IMAP(zhi): Panic: file istream.c: line 99 (i_stream_read): assertion failed: ((size_t)ret+old_size == _stream->pos
- _stream->skip)
This is kind of annoying problem. I've been adding more of these asserts to try to catch it, but no one's really found an easy way to reproduce it.
Til now. It would seem that I can reproduce it at will - except that it doesnt get logged if I have core dumps enabled :-) It could be specific to my maildir or an email in my maildir?
If you manage to get a core dump, it would also help to see what those values are:
fr 6 p ret p old_size p _stream.pos p _stream.skip
(You may need to compile Dovecot without -O2 parameter to get some of those values. Easiest way would be to just remove -O2 from src/lib/Makefile; touch src/lib/istream.c; make; sudo make install)
Is this what you are after? I got to this point using telnet to send a copy command as you suggested below and then attaching gdb to the process and stepping through.
0x080f2c2c 337 while (ioloop->running) (gdb) 338 io_loop_handler_run(ioloop); (gdb) 0x080f2c23 338 io_loop_handler_run(ioloop); (gdb)
Program received signal SIGABRT, Aborted. 0xb7f55402 in __kernel_vsyscall () (gdb) Aug 14 11:26:36 eyck dovecot: IMAP(pmacey): Panic: file istream.c: line 99 (i_stream_read): assertion failed: ((size_t)ret+old_size == _stream->pos - _stream->skip) Aug 14 11:26:36 eyck dovecot: IMAP(pmacey): Raw backtrace: imap [0x80eb000] -> imap [0x80eb05a] -> imap [0x80ea8ac] -> imap [0x80f0098] -> imap [0x80f25ca] -> imap(i_stream_read+0x3f) [0x80eff3f] -> imap(i_stream_read_data+0x1d) [0x80f00bd] -> imap [0x80e341f] -> imap [0x80e393e] -> imap(message_parser_parse_next_block+0x1d) [0x80e355d] -> imap(index_mail_cache_parse_continue+0x22) [0x809d3b2] -> imap(maildir_save_continue+0x45) [0x808ab55] -> imap(mail_storage_copy+0x6d) [0x80ac86d] -> imap(maildir_copy+0x4b) [0x80888db] -> imap(cmd_copy+0x1e0) [0x805e760] -> imap [0x80647ac] -> imap [0x806485b] -> imap(client_handle_input+0x33) [0x80649b3] -> imap(client_input+0x5f) [0x80654ff] -> imap(io_loop_handler_run+0x100) [0x80f3b40] -> imap(io_loop_run+0x28) [0x80f2c28] -> imap(main+0x738) [0x806da48] -> /lib/libc.so.6(__libc_start_main+0xdc) [0x58ae8c] -> imap [0x805d591] bt #0 0xb7f55402 in __kernel_vsyscall () #1 0x0059dd80 in raise () from /lib/libc.so.6 #2 0x0059f691 in abort () from /lib/libc.so.6 #3 0x080eb00d in default_fatal_finish (type=<value optimized out>, status=0) at failures.c:160 #4 0x080eb05a in i_internal_fatal_handler (type=LOG_TYPE_PANIC, status=0, fmt=0x8102a90 "file %s: line %d (%s): assertion failed: (%s)", args=0xbfa95a34 "Kb\021\bc") at failures.c:440 #5 0x080ea8ac in i_panic (format=0x8102a90 "file %s: line %d (%s): assertion failed: (%s)") at failures.c:207 #6 0x080f0098 in i_stream_read (stream=0x9b284c0) at istream.c:99 #7 0x080f25ca in i_stream_tee_read (stream=0x9b28578) at istream-tee.c:130 #8 0x080eff3f in i_stream_read (stream=0x9b285a0) at istream.c:80 #9 0x080f00bd in i_stream_read_data (stream=0x9b285a0, data_r=0xbfa95bb8, size_r=0xbfa95bbc, threshold=1) at istream.c:361 #10 0x080e341f in message_parser_read_more (ctx=0x9b2fda0, block_r=0xbfa95bb0, full_r=0xbfa95b4f) at message-parser.c:118 #11 0x080e393e in parse_next_body_to_eof (ctx=0x9b2fda0, block_r=0xbfa95bb0) at message-parser.c:412 #12 0x080e355d in message_parser_parse_next_block (ctx=0x9b2fda0, block_r=0xbfa95bb0) at message-parser.c:768 #13 0x0809d3b2 in index_mail_cache_parse_continue (_mail=0x9b29ca0) at index-mail.c:1367 #14 0x0808ab55 in maildir_save_continue (_ctx=0x9b28698) at maildir-save.c:426 #15 0x080ac86d in mail_storage_copy (ctx=0x9b28698, mail=0x9b23cb0) at mail-copy.c:40 #16 0x080888db in maildir_copy (ctx=0x9b28698, mail=0x9b23cb0) at maildir-copy.c:282 #17 0x0805e760 in cmd_copy (cmd=0x9ac0ea0) at cmd-copy.c:73 #18 0x080647ac in client_command_input (cmd=0x9ac0ea0) at client.c:611 #19 0x0806485b in client_command_input (cmd=0x9ac0ea0) at client.c:660 #20 0x080649b3 in client_handle_input (client=0x9ac0c10) at client.c:701 #21 0x080654ff in client_input (client=0x9ac0c10) at client.c:752 #22 0x080f3b40 in io_loop_handler_run (ioloop=0x9abf298) at ioloop-epoll.c:208 #23 0x080f2c28 in io_loop_run (ioloop=0x9abf298) at ioloop.c:338 #24 0x0806da48 in main (argc=Cannot access memory at address 0x3c10 ) at main.c:327 (gdb) fr 6 #6 0x080f0098 in i_stream_read (stream=0x9b284c0) at istream.c:99 99 i_assert((size_t)ret+old_size == _stream->pos - _stream->skip); (gdb) p ret $4 = 15376 (gdb) p old_size No symbol "old_size" in current context. (gdb) p _stream $5 = (struct istream_private *) 0x9b28498 (gdb) p _stream.pos $6 = 8191 (gdb) p _stream.skip $7 = 0 (gdb)
imap(i_stream_read_data+0x28) [0x4a2558] -> imap [0x4ab22e] -> imap(o_stream_send_istream+0x2e) [0x4aa63e] -> imap(maildir_save_continue+0x32) [0x443d12] -> imap(mail_storage_copy+0x6a) [0x462a1a] -> imap(maildir_copy+0x5e)
This is another thing I'm wondering. It's copying the mails by actually copying the data, instead of doing a hard link. But your dovecot -n output shows that you have it set to defaults, so it should have used a hard link. Or did you copy to a directory that was in another mount point? Or doesn't your filesystem support hard links?
Mail storage is on an XFS filesystem - it should support hard links. I have explicitly set maildir_copy_with_hardlinks=yes in the config file rather than just relying on the defaults because I was certain that I wanted it turned on. I just jumped onto the server and created a hardlink by hand without any problems. 'ls -lni' looks like it works:
22972186 -rw-r--r-- 2 30332 60 81 Jul 13 16:38 dot.forward 22972186 -rw-r--r-- 2 30332 60 81 Jul 13 16:38 dot.forward.hardlink 1575505744 drwx------ 99 30332 60 8192 Aug 14 09:08 Maildir
I was able to fairly reliably trigger the same behaviour myself by attempting to move a bunch (thousands) of emails in my account using thunderbird - I dont know exactly what it is that triggers the crash though.
If you're still able to reproduce this, can you also try if this does it:
Doing this also triggers the crash. See the gdb output above. The only thing I did differently was that 'testbox' already existed and had some emails in it so I didnt do the 'create'.
telnet localhost 143 a login user pass b select inbox c create testbox d copy 1:* testbox
Instead of getting a core dump you can also attach gdb to an already running process: gdb -p <imap process pid>
-- Thanks, Phill Macey (CiSRA IT Services)