[Dovecot] rc15 dumped core

[Hans Morten Kind]

We have been running rc15 since Sunday experiencing no trouble,
but today one user crashed.

rc15 on Solaris-5.9, the server had app 6GB free memory at the time
of the crash, app 70% idle running with an avg.load at 4 of 8
processors available. The USER's INBOX was quite smooth, app 13MB
containing 320 messages.

The core dump was accompanied with these log-entries:

Nov 23 2006
 12:27:00 [local3.error] IMAP(USER):
   Corrupted index cache file imapindex/USER/.imap/INBOX/dovecot.index.cache:
    invalid field header size
 12:28:23 [local3.error] IMAP(USER):
   mremap_anon(1164206080) failed: Not enough space
 12:28:23 [local3.error] IMAP(USER):
   mremap_anon(8192) failed: Invalid argument
 12:28:24 [local3.error]
   child 17510 (imap) killed with signal 10
 12:28:25 [local3.info] imap-login:
   Login: user=<USER>, method=PLAIN, rip=000.177.00.21, pid=19178

We have been observing a few of the 'invalid field header size'
messages while running rc15. But as this USER, others seem to recover
after the message has been logged.

The messages from 'mremap_anon' have never been seen before.
Actually '1164206080' looks very much like a timestamp, differing
75223 seconds from the time of the crash ... spooky

I will start running the supplied code for memory debugging on this
user and I enclose a back trace from the crash.

The interessting stuff from the back trace is probably that hdr (and
so cache->hdr) is 0xffffffff so that hdr->continued_record_count
gives no sense (Cannot access memory at address 0xb) but
cache->index->map->records_count is 320

Still on this and another server running rc15 (Sol5.8),
we have thousands of happy users beeing served very fast by Dovecot.

hmk

-------------- next part --------------
GNU gdb 6.3
Copyright 2004 Free Software Foundation, Inc.

Core was generated by `imap [USER 000.177.00.21]'.

#0  0x000857a8 in mail_cache_update_need_compress (cache=0x14f078) at mail-cache.c:461
461	        cont_percentage = hdr->continued_record_count * 100 /
#0  0x000857a8 in mail_cache_update_need_compress (cache=0x14f078) at mail-cache.c:461
	hdr = (const struct mail_cache_header *) 0xffffffff
	cont_percentage = 0
	max_del_space = 5889534034182144
#1  0x00085a88 in mail_cache_unlock (cache=0x14f078) at mail-cache.c:499
	ret = 0
	__PRETTY_FUNCTION__ = "mail_cache_unlock"
#2  0x0008b2c4 in mail_cache_transaction_commit (ctx=0x14ec80)
    at mail-cache-transaction.c:591
	cache = (struct mail_cache *) 0x14f078
	ret = 0
#3  0x00096e6c in mail_index_transaction_commit (_t=0x14ef3c, log_file_seq_r=0xffbff3e0, 
    log_file_offset_r=0xffbff3d8) at mail-index-transaction.c:368
	t = (struct mail_index_transaction *) 0x14e1a8
	ret = 0
#4  0x00084008 in index_transaction_commit (_t=0x14ef28) at index-transaction.c:44
	t = (struct index_transaction_context *) 0x14ef28
	seq = 1331256
	offset = 5097129749334968
	ret = 1395248
#5  0x0004e478 in mbox_transaction_commit (_t=0x14ef28, flags=0) at mbox-transaction.c:35
	t = (struct mbox_transaction_context *) 0x14ef28
	mbox = (struct mbox_mailbox *) 0x14bd98
	lock_id = 2
	mbox_modified = false
	ret = 0
#6  0x000b4ddc in mailbox_transaction_commit (_t=0x14715c, flags=0) at mail-storage.c:504
	t = (struct mailbox_transaction_context *) 0x14ef28
#7  0x0002b24c in imap_fetch_deinit (ctx=0x147150) at imap-fetch.c:340
	handlers = (const struct imap_fetch_context_handler *) 0x147270
	i = 2
	count = 2
#8  0x00020284 in cmd_fetch_finish (ctx=0x147150) at cmd-fetch.c:80
	cmd = (struct client_command_context *) 0x11fd8c
	ok_message = 0xf1090 "OK Fetch completed."
	failed = false
	partial = false
#9  0x000207b4 in cmd_fetch (cmd=0x11fd8c) at cmd-fetch.c:188
	client = (struct client *) 0x11fd48
	ctx = (struct imap_fetch_context *) 0x147150
	args = (struct imap_arg *) 0x145100
	search_arg = (struct mail_search_arg *) 0x147118
	messageset = 0x1451b8 "302"
	ret = 1
#10 0x000278e8 in client_handle_input (cmd=0x11fd8c) at client.c:423
	client = (struct client *) 0x11fd48
	__PRETTY_FUNCTION__ = "client_handle_input"
#11 0x00027ad0 in _client_input (context=0x11fd48) at client.c:474
	client = (struct client *) 0x11fd48
	cmd = (struct client_command_context *) 0x11fd8c
	ret = 657473
#12 0x000dc5e4 in io_loop_handler_run (ioloop=0x135e40) at ioloop-poll.c:199
	ctx = (struct ioloop_handler_context *) 0x1212d0
	pollfd = (struct pollfd *) 0x144220
	tv = {tv_sec = 0, tv_usec = 999470}
	io = (struct io *) 0x121b58
	t_id = 2
	msecs = 999
	ret = 0
	call = true
#13 0x000db6b0 in io_loop_run (ioloop=0x135e40) at ioloop.c:281
No locals.
#14 0x0003832c in main (argc=3, argv=0xffbff974, envp=0xffbff984) at main.c:280
No locals.