Subject: sys_obreak related panic in 2.0
To: None <tech-kern@netbsd.org>
From: Matthew Mondor <mm_lists@pulsar-zone.net>
List: tech-kern
Date: 01/07/2005 15:54:51
This morning at work an i686 running NetBSD 2.0 crashed:


UNAME

NetBSD pluton.pleiades 2.0 NetBSD 2.0 (PLUTON) #0: Sat Jan  1 15:12:24 EST 2005  root@hal.xisop:/usr/src/sys/arch/i386/compile/PLUTON i386


DMESG

panic: amap_pp_adjref: negative reference count


BACKTRACE

(gdb) bt
#0  0xc0481000 in ?? ()
#1  0xc0285e97 in cpu_reboot (howto=256, bootstr=0x0)
    at ../../../../arch/i386/i386/machdep.c:745
#2  0xc021a149 in panic (
    fmt=0xc0365fa0 "amap_pp_adjref: negative reference count")
    at ../../../../kern/subr_prf.c:242
#3  0xc0267a3c in amap_pp_adjref (amap=0xc741d714, curslot=15340, slotlen=16, 
    adjval=-1) at ../../../../uvm/uvm_amap.c:1147
#4  0xc02720ec in uvm_unmap_detach (first_entry=0xc732e7e8, flags=0)
    at ../../../../uvm/uvm_map.c:534
#5  0xc026f043 in uvm_unmap (map=0xc745bcec, start=201424896, end=201490432)
    at ../../../../uvm/uvm_map_i.h:154
#6  0xc027d5b5 in sys_obreak (l=0xc72c5ce8, v=0xc6cd7f64, retval=0xc6cd7f5c)
    at ../../../../uvm/uvm_unix.c:113
#7  0xc028ef25 in syscall_plain (frame=0xc6cd7fa8)
    at ../../../../arch/i386/i386/syscall.c:156


DETAILS

Unfortunately, this is a development box at work for which I cannot supply
a core dump due to IP and security reasons, however it happened when a
threaded application was getting out of tsleep I believe, although I can't
confirm this. The process seemed to currently only have a single lwp at the
time of this crash. I'll personally try to reproduce this at home, so that
I could get more detailed information and supply core dump image if needed.
However, this system was running well for some time, so I'm not sure what
to try exactly to reproduce it. I however post this in case someone with a
better clue finds out what's wrong, either to fix it or to be able to fill a
PR with worthwhile information...


 Result of "ps -axsw | grep sfdpd":
1014 26801 1208624111   3   1    1  51 10 94080   0 -        R-   ?? 0:09.00 (sfdpd)


(gdb) frame 4
#4  0xc02720ec in uvm_unmap_detach (first_entry=0xc732e7e8, flags=0)
    at ../../../../uvm/uvm_map.c:534
534             amap_unref(entry->aref.ar_amap, entry->aref.ar_pageoff,
(gdb) info locals
first_entry = (struct vm_map_entry *) 0xc732e7e8
flags = 0
next_entry = (struct vm_map_entry *) 0xc745bcec
(gdb) print *(struct vm_map_entry *)0xc732e7e8
$1 = {rb_entry = {rbe_left = 0xc732e370, rbe_right = 0x0,
    rbe_parent = 0xc73356e4, rbe_color = 0}, ownspace = 1010298880,
  space = 1010298880, prev = 0x0, next = 0x0, start = 201424896,
  end = 201490432, object = {uvm_obj = <incomplete type>, sub_map = 0x0},
  offset = 0, etype = 4, protection = 3, max_protection = 7, inheritance = 1,
  wired_count = 0, aref = {ar_pageoff = 15340, ar_amap = 0xc741d714},
  advice = 0, flags = 0 '\0'}
(gdb) frame 7
#7  0xc028ef25 in syscall_plain (frame=0xc6cd7fa8)
    at ../../../../arch/i386/i386/syscall.c:156
156                     error = (*callp->sy_call)(l, args, rval);
(gdb) info locals
params = 0x0
callp = (const struct sysent *) 0xc037ddac
l = (struct lwp *) 0xc72c5ce8
p = (struct proc *) 0x0
error = 0
argsize = 0
code = 0
args = {201424896, -959611000, -961938008, -959610976, -1071075526,
  -961939984, -959610980, -1071110953}
rval = {0, 0}
(gdb) print *l
$2 = {l_forw = 0xc03c17f0, l_back = 0x0, l_list = {le_next = 0xc72c5b5c,
    le_prev = 0xc72c5d74}, l_proc = 0xc77197fc, l_sibling = {le_next = 0x0,
    le_prev = 0xc7719850}, l_cpu = 0xc03849e0, l_flag = 9437188, l_stat = 7,
  l_lid = 1, l_swtime = 285290, l_slptime = 0, l_wchan = 0x0, l_tsleep_ch = {
    c_list = {cq_next = {elem = 0xc72c53d8, list = 0xc72c53d8}, cq_prev = {
        elem = 0xc039d140, list = 0xc039d140}},
    c_func = 0xc020b970 <endtsleep>, c_arg = 0xc72c5ce8, c_time = 47159118,
    c_flags = 12}, l_wmesg = 0xc0340416 "sawait", l_holdcnt = 0,
  l_ctxlink = 0x0, l_dupfd = 0, l_savp = 0xc6afe000, l_priority = 73 'I',
  l_usrpri = 73 'I', l_private = 0xdeadbeef, l_emuldata = 0xdeadbeef,
  l_locks = -559038737, l_addr = 0xc6cd4000, l_md = {md_regs = 0xc6cd7fa8,
    md_flags = 1, md_tss_sel = 704}}
(gdb) print *(struct proc *)0xc77197fc
$3 = {p_list = {le_next = 0xc7719994, le_prev = 0xc7719b2c},
  p_cred = 0xc6a996a8, p_fd = 0xc74247b0, p_cwdi = 0xc6a9b2b8,
  p_stats = 0xc7695c50, p_limit = 0xc6b32750, p_vmspace = 0xc745bcec,
  p_sigacts = 0xc60f72d8, p_ksems = 0x0, p_exitsig = 20, p_flag = 17408,
  p_stat = 2 '\002', p_pad1 = "", p_pid = 26801, p_pglist = {le_next = 0x0,
    le_prev = 0xc771936c}, p_pptr = 0xc7719994, p_sibling = {le_next = 0x0,
    le_prev = 0xc7719378}, p_children = {lh_first = 0x0}, p_lock = {
    lock_data = -559038737}, p_lwps = {lh_first = 0xc72c5ce8}, p_raslist = {
    lh_first = 0xc7397064}, p_nlwps = 1, p_nrlwps = 1, p_nzlwps = 0,
  p_nlwpid = 4, p_nstopchild = 0, p_sa = 0xc6af3000, p_estcpu = 3,
  p_cpticks = 10, p_pctcpu = 80, p_opptr = 0x0, p_timers = 0xc0d17c00,
  p_rtime = {tv_sec = 21789, tv_usec = 839031}, p_uticks = 1527047,
  p_sticks = 155579, p_iticks = 4207, p_traceflag = 0, p_tracep = 0x0,
  p_systrace = 0x0, p_textvp = 0xc7156174, p_emul = 0xc031f680,
  p_emuldata = 0x0, p_userret = 0, p_userret_arg = 0xc0d17c00,
  p_execsw = 0xc031f490, p_klist = {slh_first = 0x0}, p_sigctx = {
    ps_siglist = {__bits = {0, 0, 0, 0}}, ps_sigcheck = 0 '\0',
    ps_sigwaited = 0x0, ps_sigwait = 0x0, ps_silock = {lock_data = 0},
    ps_siginfo = {cqh_first = 0xc77198ec, cqh_last = 0xc77198ec}, ps_sigstk = {
      ss_sp = 0x0, ss_size = 0, ss_flags = 4}, ps_oldmask = {__bits = {
        536870912, 0, 0, 0}}, ps_flags = 0, ps_signo = 0, ps_code = 0,
    ps_lwp = 0, ps_sigcode = 0x0, ps_sigmask = {__bits = {0, 0, 0, 0}},
    ps_sigignore = {__bits = {2554892294, 0, 0, 0}}, ps_sigcatch = {__bits = {
        1672, 0, 0, 0}}}, p_nice = 30 '\036', p_comm = "sfdpd\0session\0\0\0",
  p_pgrp = 0xc6ad5310, p_psstr = 0xbfbffff0, p_psargv = 0, p_psnargv = 4,
  p_psenv = 8, p_psnenv = 12, p_xstat = 48879, p_acflag = 0,
  p_ru = 0xdeadbeef, p_md = {md_flags = 0,
    md_syscall = 0xc028eea0 <syscall_plain>, md_astpending = 0}}
...
(gdb) frame 4
#4  0xc02720ec in uvm_unmap_detach (first_entry=0xc732e7e8, flags=0)
    at ../../../../uvm/uvm_map.c:534
534             amap_unref(entry->aref.ar_amap, entry->aref.ar_pageoff,
(gdb) print *entry->aref.ar_amap
$7 = {am_l = {lock_data = -559038737}, am_ref = 1, am_flags = 0, 
  am_maxslot = 16384, am_nslot = 15735, am_nused = 14761, 
  am_slots = 0xc10a2000, am_bckptr = 0xc10b2000, am_anon = 0xc10c2000, 
  am_ppref = 0xc1092000}
(gdb) print entry->aref.ar_pageoff
$8 = 15340
...
(gdb) frame 6
#6  0xc027d5b5 in sys_obreak (l=0xc72c5ce8, v=0xc6cd7f64, retval=0xc6cd7f5c)
    at ../../../../uvm/uvm_unix.c:113
113                     uvm_deallocate(&vm->vm_map, new, old - new);
(gdb) print vm->vm_map
$14 = {pmap = 0xc6a9fda8, lock = {lk_interlock = {lock_data = 0}, 
    lk_flags = 0, lk_sharecount = 0, lk_exclusivecount = 0, 
    lk_recurselevel = 0, lk_waitcount = 0, lk_wmesg = 0xc0343631 "vmmaplk", 
    lk_un = {lk_un_sleep = {lk_sleep_lockholder = -1, lk_sleep_locklwp = 0, 
        lk_sleep_prio = 4, lk_sleep_timo = 0}, lk_un_spin = {
        lk_spin_cpu = 4294967295}}}, rbhead = {rbh_root = 0xc6ec9b60}, 
  header = {rb_entry = {rbe_left = 0x0, rbe_right = 0x0, rbe_parent = 0x0, 
      rbe_color = 0}, ownspace = 0, space = 0, prev = 0xc7335f7c, 
    next = 0xc73320b4, start = 3217031168, end = 0, object = {uvm_obj = 0x0, 
      sub_map = 0x0}, offset = 0, etype = 0, protection = 0, 
    max_protection = 0, inheritance = 0, wired_count = 0, aref = {
      ar_pageoff = 0, ar_amap = 0x0}, advice = 0, flags = 0 '\0'}, 
  nentries = 208, size = 854376448, ref_count = 1, ref_lock = {lock_data = 0}, 
  hint = 0xc732e370, hint_lock = {lock_data = 0}, first_free = 0xc732e370, 
  flags = 1, flags_lock = {lock_data = 0}, timestamp = 26165}
(gdb) print new
$15 = 201424896
(gdb) print old
$16 = 201490432
...
(gdb) frame 3
#3  0xc0267a3c in amap_pp_adjref (amap=0xc741d714, curslot=15340, slotlen=16,
    adjval=-1) at ../../../../uvm/uvm_amap.c:1147
1147                            panic("amap_pp_adjref: negative reference count");
(gdb) print ref
$17 = 0
(gdb) info locals
stopslot = 15356
ppref = (int *) 0x1
lcv = -959611288
prevlcv = 15335
ref = 0
len = 56881
prevref = 1
prevlen = 5


Thanks,
Matt