Ralf Hildebrandt
2009-Dec-01 19:48 UTC
[Dovecot] dovecot-1.2.8 imap crash (with backtrace)
In the log:
Dec 1 17:24:00 postamt dovecot: IMAP(scxxxxx):
/home/s/c/scxxxxx/Maildir/dovecot-uidlist: Duplicate file entry at line 1:
1259679049.M329485P1617.postamt.charite.de,S=142073,W=143959:2,Sb (uid 3157
-> 3159)
Dec 1 17:24:00 postamt dovecot: IMAP(scxxxxx): Panic: file maildir-uidlist.c:
line 403 (maildir_uidlist_records_array_delete): assertion failed: (pos != NULL)
Dec 1 17:24:00 postamt dovecot: IMAP(scxxxxx): Raw backtrace: imap [0x80f13d1]
-> imap [0x80f1442] -> imap [0x80f0db9] -> imap
[0x8088e76] -> imap(maildir_uidlist_refresh+0x9e9) [0x8089e99] -> imap
[0x80865d4] -> imap(maildir_storage_sync_init+0x125) [0x8086ab5] ->
imap(imap_sync_init+0x54) [0x8070304] -> imap [0x8062aa2] -> imap
[0x80a604c] -> imap(io_loop_handle_timeouts+0xe9) [0x80f96f9] ->
imap(io_loop_handler_run+0x82) [0x80f9fc2] -> imap(io_loop_run+0x20)
[0x80f9490] -> imap(main+0x5d2) [0x8070e22] ->
/lib/i686/cmov/libc.so.6(__libc_start_main+0xe5) [0xb7f17b35] -> imap
[0x80602d1]
The backtrace:
GNU gdb (GDB) 7.0-debian
Copyright (C) 2009 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".
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>...
Reading symbols from /usr/local/libexec/dovecot/imap...done.
Reading symbols from /lib/i686/cmov/libdl.so.2...Reading symbols from
/usr/lib/debug/lib/i686/cmov/libdl-2.10.1.so...done.
(no debugging symbols found)...done.
Loaded symbols for /lib/i686/cmov/libdl.so.2
Reading symbols from /lib/i686/cmov/librt.so.1...Reading symbols from
/usr/lib/debug/lib/i686/cmov/librt-2.10.1.so...done.
(no debugging symbols found)...done.
Loaded symbols for /lib/i686/cmov/librt.so.1
Reading symbols from /lib/i686/cmov/libc.so.6...Reading symbols from
/usr/lib/debug/lib/i686/cmov/libc-2.10.1.so...done.
(no debugging symbols found)...done.
Loaded symbols for /lib/i686/cmov/libc.so.6
Reading symbols from /lib/ld-linux.so.2...Reading symbols from
/usr/lib/debug/lib/ld-2.10.1.so...done.
(no debugging symbols found)...done.
Loaded symbols for /lib/ld-linux.so.2
Reading symbols from /lib/i686/cmov/libpthread.so.0...Reading symbols from
/usr/lib/debug/lib/i686/cmov/libpthread-2.10.1.so...done.
(no debugging symbols found)...done.
Loaded symbols for /lib/i686/cmov/libpthread.so.0
Reading symbols from /usr/local/lib/dovecot/imap/lib10_quota_plugin.so...done.
Loaded symbols for /usr/local/lib/dovecot/imap/lib10_quota_plugin.so
Reading symbols from
/usr/local/lib/dovecot/imap/lib11_imap_quota_plugin.so...done.
Loaded symbols for /usr/local/lib/dovecot/imap/lib11_imap_quota_plugin.so
Reading symbols from /usr/local/lib/dovecot/imap/lib11_trash_plugin.so...done.
Loaded symbols for /usr/local/lib/dovecot/imap/lib11_trash_plugin.so
Reading symbols from
/usr/local/lib/dovecot/imap/lib20_autocreate_plugin.so...done.
Loaded symbols for /usr/local/lib/dovecot/imap/lib20_autocreate_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/lib20_mail_log_plugin.so...done.
Loaded symbols for /usr/local/lib/dovecot/imap/lib20_mail_log_plugin.so
Reading symbols from /usr/local/lib/dovecot/imap/lib20_zlib_plugin.so...done.
Loaded symbols for /usr/local/lib/dovecot/imap/lib20_zlib_plugin.so
Reading symbols from /usr/lib/libz.so.1...(no debugging symbols found)...done.
Loaded symbols for /usr/lib/libz.so.1
Reading symbols from /lib/libbz2.so.1.0...(no debugging symbols found)...done.
Loaded symbols for /lib/libbz2.so.1.0
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 /lib/libgcc_s.so.1...(no debugging symbols found)...done.
Loaded symbols for /lib/libgcc_s.so.1
Core was generated by `imap [scxxxxx 88.73.137.113]'.
Program terminated with signal 6, Aborted.
#0 0xb8064424 in __kernel_vsyscall ()
#0 0xb8064424 in __kernel_vsyscall ()
No symbol table info available.
#1 0xb7f2b8c0 in *__GI_raise (sig=6)
at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
resultvar = <value optimized out>
pid = -1207676940
selftid = 7704
#2 0xb7f2edf5 in *__GI_abort () at abort.c:88
act = {__sigaction_handler = {sa_handler = 0x8723738,
sa_sigaction = 0x8723738}, sa_mask = {__val = {3216510312,
135196426, 3087288032, 0, 3216510432, 3216510420, 128, 0, 0,
3216510496, 3087541872, 134566866, 549, 0, 0, 0, 1, 135269694,
128, 1, 3216510420, 141702936, 69, 3216510548, 3216510392,
135198022, 141703517, 3216510420, 3216510424, 550, 141702968,
3086750483}}, sa_flags = 550,
sa_restorer = 0x8106b49 <write_full+57>}
sigs = {__val = {32, 0 <repeats 31 times>}}
#3 0x080f13e5 in default_fatal_finish (type=<value optimized out>,
status=0)
at failures.c:160
backtrace = 0x8723308 "imap [0x80f13d1] -> imap [0x80f1442]
-> imap [0x80f0db9] -> imap [0x8088e76] ->
imap(maildir_uidlist_refresh+0x9e9) [0x8089e99] -> imap [0x80865d4] ->
imap(maildir_storage_sync_init+0x125) [0x8086ab5]"...
#4 0x080f1442 in i_internal_fatal_handler (type=LOG_TYPE_PANIC, status=0,
fmt=0x8109b8c "file %s: line %d (%s): assertion failed: (%s)",
args=0xbfb80eb4 "\232\352\020\b\223\001") at failures.c:443
No locals.
#5 0x080f0db9 in i_panic (
format=0x8109b8c "file %s: line %d (%s): assertion failed: (%s)")
at failures.c:207
No locals.
#6 0x08088e76 in maildir_uidlist_records_array_delete (uidlist=0x8739cd8,
rec=0x8758228) at maildir-uidlist.c:403
recs = 0x8757428
__PRETTY_FUNCTION__ = "maildir_uidlist_records_array_delete"
#7 0x08089e99 in maildir_uidlist_next (uidlist=0x8739cd8)
at maildir-uidlist.c:544
rec = 0x8758308
uid = 3159
#8 maildir_uidlist_update_read (uidlist=0x8739cd8) at maildir-uidlist.c:741
storage = 0x872d4b8
orig_uid_validity = 1214127123
fd = 10
orig_next_uid = 3159
input = 0x8757f20
st = {st_dev = 65024, __pad1 = 0, __st_ino = 7668251, st_mode = 33152,
st_nlink = 1, st_uid = 58166, st_gid = 100, st_rdev = 0, __pad2 = 0,
st_size = 10622, st_blksize = 4096, st_blocks = 24, st_atim = {
tv_sec = 1259684618, tv_nsec = 893433866}, st_mtim = {
tv_sec = 1259684639, tv_nsec = 641099786}, st_ctim = {
tv_sec = 1259684639, tv_nsec = 641099786}, st_ino = 7668251}
last_read_offset = 10550
#9 maildir_uidlist_refresh (uidlist=0x8739cd8) at maildir-uidlist.c:889
i = 0
retry = <value optimized out>
ret = <value optimized out>
#10 0x080865d4 in have_recent_messages (ctx=0x8723240, forced=false,
find_uid=0x0, lost_files_r=0xbfb8106b) at maildir-sync.c:659
hdr = <value optimized out>
#11 maildir_sync_get_changes (ctx=0x8723240, forced=false, find_uid=0x0,
lost_files_r=0xbfb8106b) at maildir-sync.c:679
flags = <value optimized out>
#12 maildir_sync_context (ctx=0x8723240, forced=false, find_uid=0x0,
lost_files_r=0xbfb8106b) at maildir-sync.c:714
sync_flags = <value optimized out>
flags = 135324992
new_changed = <value optimized out>
cur_changed = <value optimized out>
lock_failure = <value optimized out>
fname = 0x8733030 "/home/s/c/scxxxxx/Maildir"
ret = <value optimized out>
__PRETTY_FUNCTION__ = "maildir_sync_context"
#13 0x08086ab5 in maildir_storage_sync_init (box=0x8732e98, flags=0)
at maildir-sync.c:924
_data_stack_cur_id = 4
ctx = 0x8723240
lost_files = <value optimized out>
ret = 0
__PRETTY_FUNCTION__ = "maildir_storage_sync_init"
#14 0x08070304 in imap_sync_init (client=0x872dba0, box=0x8732e98,
imap_flags=0, flags=0) at imap-sync.c:146
ctx = 0x8762138
__PRETTY_FUNCTION__ = "imap_sync_init"
#15 0x08062aa2 in idle_sync_now (box=<value optimized out>, ctx=0x872deb8)
at cmd-idle.c:127
__PRETTY_FUNCTION__ = "idle_sync_now"
#16 0x080a604c in notify_delay_callback (ibox=0x8732e98)
at index-mailbox-check.c:49
No locals.
#17 0x080f96f9 in io_loop_handle_timeouts_real (ioloop=0x872b9b0)
at ioloop.c:313
item = 0x8764e78
tv = {tv_sec = 0, tv_usec = 0}
tv_call = {tv_sec = 1259684640, tv_usec = 146065}
t_id = 3
#18 io_loop_handle_timeouts (ioloop=0x872b9b0) at ioloop.c:324
_data_stack_cur_id = 2
#19 0x080f9fc2 in io_loop_handler_run (ioloop=0x872b9b0) at ioloop-epoll.c:180
ctx = 0x872bab8
event = <value optimized out>
list = <value optimized out>
io = <value optimized out>
tv = {tv_sec = 0, tv_usec = 3024}
t_id = <value optimized out>
msecs = 4
ret = 0
i = <value optimized out>
j = <value optimized out>
call = <value optimized out>
#20 0x080f9490 in io_loop_run (ioloop=0x872b9b0) at ioloop.c:335
No locals.
#21 0x08070e22 in main (argc=) at main.c:327
No locals.
$1 = {prev = 0x0, next = 0x0, client = 0x872dba0, pool = 0x872de18,
tag = 0x872dea8 "22.4", name = 0x872deb0 "IDLE", args =
0x0, cmd_flags = 10,
func = 0x80628b0 <cmd_idle_continue>, context = 0x872deb8,
module_contexts = {arr = {buffer = 0x872de70, element_size = 4},
v = 0x872de70, v_modifiable = 0x872de70}, parser = 0x8730620,
state = CLIENT_COMMAND_STATE_WAIT_INPUT, sync = 0x0, uid = 0, cancel = 0,
param_error = 0, search_save_result = 0, temp_executed = 0}
(gdb) quit
--
Ralf Hildebrandt
Gesch?ftsbereich IT | Abteilung Netzwerk
Charit? - Universit?tsmedizin Berlin
Campus Benjamin Franklin
Hindenburgdamm 30 | D-12203 Berlin
Tel. +49 30 450 570 155 | Fax: +49 30 450 570 962
ralf.hildebrandt at charite.de | http://www.charite.de
I found this post from a couple of weeks ago:
http://www.mail-archive.com/dovecot at dovecot.org/msg24127.html
Any update on this? I'm experiencing the same issue. Out of a user
population of 4000, I get about 20 of these dumps a day, so it's not
major issue, but I thought I'd follow up.
Here is an example:
http://pastebin.com/f29c55de5
I can provide a more detailed debug log from teh core dump if necessary,
but since the above email already had it I figured I'd wait.
Note this is *not* the same issue as:
- maildir: v1.2.7 and v1.2.8 caused assert-crashes in
maildir_uidlist_records_drop_expunges()
I applied those patches to my 1.2.8 installation before 1.2.9 was
released and that immediately fixed the expunge crash, but the
array_delete bug is still there.
dovecot -n
---------------
bash-3.2# /usr/sbin/dovecot -n
# 1.2.8: /etc/dovecot.conf
# OS: Linux 2.6.18-164.6.1.el5 x86_64 CentOS release 5.4 (Final)
listen: *
ssl_cert_file: /rci/local/certs/imapd-pop3d.pem
ssl_key_file: /rci/local/certs/imapd-pop3d.pem
disable_plaintext_auth: yes
login_dir: /var/run/dovecot/login
login_executable(default): /usr/libexec/dovecot/imap-login
login_executable(imap): /usr/libexec/dovecot/imap-login
login_executable(pop3): /usr/libexec/dovecot/pop3-login
login_max_processes_count: 2048
max_mail_processes: 2048
first_valid_uid: 100
mail_location:
maildir:~/Maildir:INDEX=/rci/nqu%h/dovecot:CONTROL=/rci/nqu%h/dovecot
mmap_disable: yes
mail_nfs_storage: yes
mail_nfs_index: yes
mail_drop_priv_before_exec: yes
mail_executable(default): /rci/local/etc/convert-courier-imap.sh
mail_executable(imap): /rci/local/etc/convert-courier-imap.sh
mail_executable(pop3): /rci/local/etc/convert-courier-pop.sh
mail_plugin_dir(default): /usr/lib64/dovecot/imap
mail_plugin_dir(imap): /usr/lib64/dovecot/imap
mail_plugin_dir(pop3): /usr/lib64/dovecot/pop3
pop3_uidl_format(default): %08Xu%08Xv
pop3_uidl_format(imap): %08Xu%08Xv
pop3_uidl_format(pop3): UID%u-%v
namespace:
type: private
separator: .
prefix: INBOX.
inbox: yes
list: yes
subscriptions: yes
auth default:
passdb:
driver: pam
args: dovecot
userdb:
driver: passwd
--
===============================David Halik
System Administrator
OIT-CSS Rutgers University
dhalik at jla.rutgers.edu
================================