[Dovecot] 1.2.9 imap crash with backtrace

Ralf Hildebrandt Ralf.Hildebrandt at charite.de
Fri Jan 8 10:34:37 EET 2010


* David Halik <dhalik at jla.rutgers.edu>:
> 
> Ralf, you're seeing the same panic I've been going back and forth
> with Timo on for the last two weeks. Do you think you could run a
> couple of quick gdb commands? Timo asked me for these last week, but
> I thought it might be useful if they came from you as well for
> comparison. It also looks like you have optimization turned off which
> is great for debugging.
> 
> From Timo...
> 
> Could you do in gdb something like:
> 
> fr 6 (or whatever frame gives usable results)

Yes, it's frame 6

> p *rec

(gdb) p *rec
$2 = {uid = 1721, flags = 8, 
  filename = 0x9c4e2b0 "1247223070.M198961P26186.postamt.charite.de,S=4080,W=4182:2,Sa", extensions = 0x0}

> p count

(gdb) p count
$3 = <value optimized out>

Sorry :(

> p *recs[0]

(gdb) p *recs[0]
$4 = {uid = 1962, flags = 8, 
  filename = 0x9c531a8 "1262613886.M868332P16003.postamt.charite.de,W=39324,S=38791:2,Sa", extensions = 0x0}

> p *recs[1]
> p *recs[..up until count-1]

Since count is optimized out, how should I know?
OK, trial and error:

(gdb) p *recs[0]
$16 = {uid = 1962, flags = 8, 
  filename = 0x9c531a8
"1262613886.M868332P16003.postamt.charite.de,W=39324,S=38791:2,Sa",
extensions = 0x0}
(gdb) p *recs[1]
$17 = {uid = 1963, flags = 8, 
  filename = 0x9c53200
"1262613886.M868333P16003.postamt.charite.de,W=3061,S=2987:2,Sa",
extensions = 0x0}
(gdb) p *recs[2]
$18 = {uid = 1964, flags = 8, 
  filename = 0x9c53250
"1262613886.M868334P16003.postamt.charite.de,W=407687,S=402422:2,Sa", 
  extensions = 0x0}
  (gdb) p *recs[3]
  $19 = {uid = 1965, flags = 8, 
    filename = 0x9c532a8
"1262613886.M868335P16003.postamt.charite.de,W=3576,S=3496:2,RSa",
extensions = 0x0}
(gdb) p *recs[4]
$20 = {uid = 1966, flags = 8, 
  filename = 0x9c532f8
"1262613886.M868336P16003.postamt.charite.de,W=20045,S=19472:2,Sa",
extensions = 0x0}
(gdb) p *recs[5]
$21 = {uid = 1967, flags = 8, 
  filename = 0x9c53350
"1262613886.M868337P16003.postamt.charite.de,W=99371,S=97957:2,Sa",
extensions = 0x0}
(gdb) p *recs[6]
$22 = {uid = 1968, flags = 8, 
  filename = 0x9c533a8
"1262613886.M868338P16003.postamt.charite.de,W=4552,S=4453:2,Sa",
extensions = 0x0}

...

(gdb) p *recs[50]
$23 = {uid = 2012, flags = 8, 
  filename = 0x9c54260 "1262613886.M868382P16003.postamt.charite.de,W=29656,S=28920:2,Sa",
extensions = 0x0}
(gdb) p *recs[51]
$24 = {uid = 2013, flags = 8, 
  filename = 0x9c542b8 "1262613886.M868383P16003.postamt.charite.de,W=83093,S=81992:2,Sa",
extensions = 0x0}
(gdb) p *recs[52]
$25 = {uid = 2014, flags = 8, 
  filename = 0x9c54310 "1262613886.M868384P16003.postamt.charite.de,W=2104892,S=2077799:2,Sb", 
  extensions = 0x0}
(gdb) p *recs[53]
$26 = {uid = 2015, flags = 8, 
    filename = 0x9c54368 "1262613886.M868385P16003.postamt.charite.de,W=89389,S=88208:2,Sa",
extensions = 0x0}
(gdb) p *recs[54]
$27 = {uid = 2016, flags = 8, 
  filename = 0x9c543c0 "1262613886.M868386P16003.postamt.charite.de,W=12822,S=12457:2,Sa",
extensions = 0x0}
(gdb) p *recs[55]
$28 = {uid = 2017, flags = 8, 
  filename = 0x9c54428 "1262613886.M868387P16003.postamt.charite.de,W=14356,S=14096:2,Sa",
extensions = 0x0}
(gdb) p *recs[56]
$29 = {uid = 2018, flags = 8, 
  filename = 0x9c54480 "1262613886.M868388P16003.postamt.charite.de,W=15126,S=14718:2,Sa",
extensions = 0x0}
(gdb) p *recs[57]
Cannot access memory at address 0x0

> If count is large, the main things I want to know are:
> 
> 1) Is the array sorted (recs[n]->uid < recs[n+1]->uid always)?

Yes, it's sorted!
 
> 2) is rec->uid anywhere in the recs array?

I don't understand this question. All the entries recs[0] ... recs[56]
are containing entries like the ones above.

> On 01/04/2010 05:09 AM, Ralf Hildebrandt wrote:
> >> From the log:
> >
> >Jan  3 20:26:07 postamt dovecot: IMAP(nixxxxx): copy: uid=3526, dest=Deleted Messages, msgid=<DC8A4BE5-41A0-4240-8F07-090E95414F7A at charite.de>, size=2726
> >Jan  3 20:26:07 postamt dovecot: IMAP(nixxxxx): delete: uid=3526, msgid=<DC8A4BE5-41A0-4240-8F07-090E95414F7A at charite.de>
> >Jan  3 20:26:11 postamt dovecot: IMAP(nixxxxx): expunge: uid=3526, msgid=<DC8A4BE5-41A0-4240-8F07-090E95414F7A at charite.de>, size=2726
> >Jan  3 20:26:42 postamt dovecot: IMAP(nixxxxx): copy: uid=415, box=Deleted Messages, dest=INBOX, msgid=<d539ffeb1001030758n1acc33c1m1fc67e0f1d227e92 at mail.gmail.com>, size=3604
> >Jan  3 20:26:42 postamt dovecot: IMAP(nixxxxx): /home/n/i/nixxxxx/Maildir/dovecot-uidlist: Duplicate file entry at line 1:
> >1262534293.M822904P8880.postamt.charite.de,S=3604,W=3690:2,RSaf (uid 3528 ->  3531)
> >Jan  3 20:26:42 postamt dovecot: IMAP(nixxxxx): Panic: file maildir-uidlist.c: line 403 (maildir_uidlist_records_array_delete):
> >assertion failed: (pos != NULL)
> >Jan  3 20:26:42 postamt dovecot: IMAP(nixxxxx): Raw backtrace: imap [0x80f1631] ->  imap [0x80f16a2] ->  imap [0x80f1019] ->  imap
> >[0x8088fa6] ->  imap(maildir_uidlist_refresh+0x9e9) [0x8089fc9] ->  imap [0x8086704] ->  imap(maildir_storage_sync_init+0x125) [0x8086be5] ->
> >imap(imap_sync_init+0x54) [0x8070434] ->  imap [0x8062aa2] ->  imap [0x80a619c] ->  imap(io_loop_handle_timeouts+0xe9) [0x80f9959] ->
> >imap(io_loop_handler_run+0x82) [0x80fa222] ->  imap(io_loop_run+0x20) [0x80f96f0] ->  imap(main+0x5d2) [0x8070f52] ->
> >/lib/i686/cmov/libc.so.6(__libc_start_main+0xe5) [0xb75bcb55] ->  imap [0x80602d1]
> >Jan  3 20:26:42 postamt dovecot: IMAP(nixxxxx): delete: uid=415, box=Deleted Messages, msgid=<d539ffeb1001030758n1acc33c1m1fc67e0f1d227e92 at mail.gmail.com>
> >Jan  3 20:26:42 postamt dovecot: IMAP(nixxxxx): expunge: uid=415, box=Deleted Messages, msgid=<d539ffeb1001030758n1acc33c1m1fc67e0f1d227e92 at mail.gmail.com>, size=3604
> >Jan  3 20:26:45 postamt dovecot: IMAP(nixxxxx): Disconnected: Logged out bytes=63917/47203
> >Jan  3 20:26:45 postamt dovecot: IMAP(nixxxxx): Disconnected: Logged out bytes=360/168380
> >Jan  3 20:26:45 postamt dovecot: IMAP(nixxxxx): Disconnected: Logged out bytes=670290/672304
> >
> >
> >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.2.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.2.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.2.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.2.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.2.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 [nixxxxx 87.162.56.10]'.
> >Program terminated with signal 6, Aborted.
> >#0  0xb7708424 in __kernel_vsyscall ()
> >#0  0xb7708424 in __kernel_vsyscall ()
> >No symbol table info available.
> >#1  0xb75d08e0 in *__GI_raise (sig=6)
> >     at ../nptl/sysdeps/unix/sysv/linux/raise.c:64
> >         resultvar =<value optimized out>
> >         pid = -1217490956
> >         selftid = 25023
> >#2  0xb75d3e15 in *__GI_abort () at abort.c:88
> >         act = {__sigaction_handler = {sa_handler = 0x9505708,
> >             sa_sigaction = 0x9505708}, sa_mask = {__val = {3219827960,
> >               135197034, 3077474016, 0, 3219828080, 3219828068, 128, 0, 0,
> >               3219828144, 3077727856, 134566866, 549, 0, 0, 0, 1, 135270350,
> >               128, 1, 3219828068, 156260072, 69, 3219828196, 3219828040,
> >               135198630, 156260653, 3219828068, 3219828072, 550, 156260104,
> >               3076940867}}, sa_flags = 550,
> >           sa_restorer = 0x8106dd9<write_full+57>}
> >         sigs = {__val = {32, 0<repeats 31 times>}}
> >#3  0x080f1645 in default_fatal_finish (type=<value optimized out>, status=0)
> >     at failures.c:160
> >         backtrace = 0x95052d8 "imap [0x80f1631] ->  imap [0x80f16a2] ->  imap [0x80f1019] ->  imap [0x8088fa6] ->  imap(maildir_uidlist_refresh+0x9e9) [0x8089fc9] ->  imap [0x8086704] ->  imap(maildir_storage_sync_init+0x125) [0x8086be5]"...
> >#4  0x080f16a2 in i_internal_fatal_handler (type=LOG_TYPE_PANIC, status=0,
> >     fmt=0x8109e2c "file %s: line %d (%s): assertion failed: (%s)",
> >     args=0xbfeaae44 ":\355\020\b\223\001") at failures.c:443
> >No locals.
> >#5  0x080f1019 in i_panic (
> >     format=0x8109e2c "file %s: line %d (%s): assertion failed: (%s)")
> >     at failures.c:207
> >No locals.
> >#6  0x08088fa6 in maildir_uidlist_records_array_delete (uidlist=0x951b0b0,
> >     rec=0x9534500) at maildir-uidlist.c:403
> >         recs = 0x9536fa0
> >         __PRETTY_FUNCTION__ = "maildir_uidlist_records_array_delete"
> >#7  0x08089fc9 in maildir_uidlist_next (uidlist=0x951b0b0)
> >     at maildir-uidlist.c:544
> >         rec = 0x95346b8
> >         uid = 3531
> >#8  maildir_uidlist_update_read (uidlist=0x951b0b0) at maildir-uidlist.c:741
> >         storage = 0x950f4b8
> >         orig_uid_validity = 1186140978
> >         fd = 14
> >         orig_next_uid = 3531
> >         input = 0x95347a0
> >         st = {st_dev = 65024, __pad1 = 0, __st_ino = 5228663, st_mode = 33152,
> >           st_nlink = 1, st_uid = 50357, st_gid = 100, st_rdev = 0, __pad2 = 0,
> >           st_size = 763, st_blksize = 4096, st_blocks = 8, st_atim = {
> >             tv_sec = 1262546767, tv_nsec = 269770575}, st_mtim = {
> >             tv_sec = 1262546802, tv_nsec = 221806856}, st_ctim = {
> >             tv_sec = 1262546802, tv_nsec = 221806856}, st_ino = 5228663}
> >         last_read_offset = 693
> >#9  maildir_uidlist_refresh (uidlist=0x951b0b0) at maildir-uidlist.c:889
> >         i = 0
> >         retry =<value optimized out>
> >         ret =<value optimized out>
> >#10 0x08086704 in have_recent_messages (ctx=0x9505210, forced=false,
> >     find_uid=0x0, lost_files_r=0xbfeaaffb) at maildir-sync.c:659
> >         hdr =<value optimized out>
> >#11 maildir_sync_get_changes (ctx=0x9505210, forced=false, find_uid=0x0,
> >     lost_files_r=0xbfeaaffb) at maildir-sync.c:679
> >         flags =<value optimized out>
> >#12 maildir_sync_context (ctx=0x9505210, forced=false, find_uid=0x0,
> >     lost_files_r=0xbfeaaffb) at maildir-sync.c:714
> >         sync_flags =<value optimized out>
> >         flags = 135325664
> >         new_changed =<value optimized out>
> >         cur_changed =<value optimized out>
> >         lock_failure =<value optimized out>
> >         fname = 0x9515030 "/home/n/i/nixxxxx/Maildir"
> >         ret =<value optimized out>
> >         __PRETTY_FUNCTION__ = "maildir_sync_context"
> >#13 0x08086be5 in maildir_storage_sync_init (box=0x9514e98, flags=0)
> >     at maildir-sync.c:924
> >         _data_stack_cur_id = 4
> >         ctx = 0x9505210
> >         lost_files =<value optimized out>
> >         ret = 0
> >         __PRETTY_FUNCTION__ = "maildir_storage_sync_init"
> >#14 0x08070434 in imap_sync_init (client=0x950fba0, box=0x9514e98,
> >     imap_flags=0, flags=0) at imap-sync.c:146
> >         ctx = 0x95191a0
> >         __PRETTY_FUNCTION__ = "imap_sync_init"
> >#15 0x08062aa2 in idle_sync_now (box=<value optimized out>, ctx=0x950feb8)
> >     at cmd-idle.c:127
> >         __PRETTY_FUNCTION__ = "idle_sync_now"
> >#16 0x080a619c in notify_delay_callback (ibox=0x9514e98)
> >     at index-mailbox-check.c:49
> >No locals.
> >#17 0x080f9959 in io_loop_handle_timeouts_real (ioloop=0x950d9b0)
> >     at ioloop.c:313
> >         item = 0x9563c78
> >         tv = {tv_sec = 0, tv_usec = 0}
> >         tv_call = {tv_sec = 1262546802, tv_usec = 336801}
> >         t_id = 3
> >#18 io_loop_handle_timeouts (ioloop=0x950d9b0) at ioloop.c:324
> >         _data_stack_cur_id = 2
> >#19 0x080fa222 in io_loop_handler_run (ioloop=0x950d9b0) at ioloop-epoll.c:180
> >         ctx = 0x950dab8
> >         event =<value optimized out>
> >         list =<value optimized out>
> >         io =<value optimized out>
> >         tv = {tv_sec = 0, tv_usec = 108829}
> >         t_id =<value optimized out>
> >         msecs = 109
> >         ret = 0
> >         i =<value optimized out>
> >         j =<value optimized out>
> >         call =<value optimized out>
> >#20 0x080f96f0 in io_loop_run (ioloop=0x950d9b0) at ioloop.c:335
> >No locals.
> >#21 0x08070f52 in main (argc=) at main.c:327
> >No locals.
> >$1 = {prev = 0x0, next = 0x0, client = 0x950fba0, pool = 0x950fe18,
> >   tag = 0x950fea8 "104.6", name = 0x950feb0 "IDLE", args = 0x0,
> >   cmd_flags = 10, func = 0x80628b0<cmd_idle_continue>, context = 0x950feb8,
> >   module_contexts = {arr = {buffer = 0x950fe70, element_size = 4},
> >     v = 0x950fe70, v_modifiable = 0x950fe70}, parser = 0x9512620,
> >   state = CLIENT_COMMAND_STATE_WAIT_INPUT, sync = 0x0, uid = 0, cancel = 0,
> >   param_error = 0, search_save_result = 0, temp_executed = 0}
> >(gdb) quit
> >
> >----- End forwarded message -----
> >
> 
> 
> -- 
> ================================
> David Halik
> System Administrator
> OIT-CSS Rutgers University
> dhalik at jla.rutgers.edu
> ================================
> 

-- 
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
	    


More information about the dovecot mailing list