HI Frankh,
When I did this 30000df1c50::print struct dev_info devi_busy_thread|::findstack -v stack pointer for thread 2a100541cc0: 2a100540521 000002a1005405c1 i_ndi_config_node+0x4c(30002e83290, 2, 10b9be8, 3fffffffc, 1852800, 10b9800) 000002a100540671 ndi_devi_online+0x24(30002e83290, 0, 701d5ce0, 0, 30000df1c50 , 1177000) 000002a100540731 abc_LDCreateDevInfo+0x204(30002adf380, 30002e85440, 7, 30002d90040, 1, 0) 000002a100540801 abc_ArrayPathAttachEvent+0x1c4(30002adf380, 30002d90040, 0, 0 , 0, 8) 000002a1005408e1 swspiPathEvent+0x98(30002d90040, 0, 30003a4d248, 5f, 701e8ac0 , 0) 000002a1005409d1 pathAttach+0x1b0(30002d90040, 701e8ab8, 2000, 5f, 0, 0) 000002a100540aa1 def_PathCreate+0x1b8(30002e1cae0, 30002e1cae0, 16, 58, 2a100541434, 2a100541438) 000002a100540b81 def_attach+0x2c(30002e1cae0, 0, 0, 0, 0, 0) 000002a100540c51 devi_attach+0xac(30002e1cae0, 0, 300000f31c0, 300000ec000, 0 , 7bba6530) 000002a100540d21 attach_node+0x80(30002e1cae0, 1, 0, 1, 2, 4) 000002a100540dd1 i_ndi_config_node+0x104(30002e1cae0, 114, 10b9be8, 10, 1852800, 10b9800) 000002a100540e81 i_ddi_attachchild+0x48(30002e1cae0, ffffffffffffffff, 1, 300003b9a68, 0, 0) 000002a100540f41 devi_attach_node+0x5c(30002e1cae0, 4014048, 4014048, 1, 4014048, 20000) 000002a100540ff1 devi_attach_children+0x6c(30002e1ccc0, 4014048, 30002e1cae0, 8, ffffffffffffffff, ffffffff) 000002a1005410a1 config_immediate_children+0x68(300003b9a68, 1, ffffffff, 300003b9ad0, 0, 18bd368) 000002a100541161 devi_config_common+0xa4(300003b9a68, 2, ffffffff, 18ab800, 0 , 4004048) 000002a100541211 mt_config_thread+0x60(30002b0b5e0, 0, 1835b00, 1835b00, 300003b9a68, 300024aa540) 000002a1005412d1 thread_start+4(30002b0b5e0, 0, 4080a1334323300, 730064697361626c, 6564000000000000, 4031c0000001f) > This is one of the thread which is currently running I can see the same thread when I do ::cpuinfo ID ADDR FLG NRUN BSPL PRI RNRN KRNRN SWITCH THREAD PROC 0 00001837430 1b 0 0 109 no no t-0 2a100047cc0 sched 1 30001baa000 1d 0 0 60 yes no t-23092 2a100541cc0 sched Yeah sure, Its not a problem sharing the core dump. Regards, Kiran -----Original Message----- From: Frank.Hofmann at Sun.COM [mailto:frank.hofm...@sun.com] Sent: Wednesday, September 06, 2006 5:31 PM To: C, Kiran (STSD) Cc: mdb-discuss at opensolaris.org Subject: RE: [mdb-discuss] How to debug a Kernel Hang using mdb??? On Wed, 6 Sep 2006, C, Kiran (STSD) wrote: > Hi Frankh, > > Thanks very much for the reply, > > I am posting the stack trace of the mt_config_thread > > 000002a100549cc0::findstack -v > stack pointer for thread 2a100549cc0: 2a100548511 [ 000002a100548511 > cv_wait+0x38() ] > 000002a1005485c1 ndi_devi_enter+0x44(30000df1c50, 2a100548f2c, 190, > 701d5ce0, 2a100541cc0, 4) > 000002a100548671 ndi_devi_online+0x14(30002e7d478, 0, 701d5ce0, 1, > 30000df1c50 , 1177000) Again, same game - source tells us this is devcfg.c, here: 1612 /* 1613 * Single thread entry into devinfo node for modifying its children. 1614 * To verify in ASSERTS use DEVI_BUSY_OWNED macro. 1615 */ 1616 void 1617 ndi_devi_enter(dev_info_t *dip, int *circular) 1618 { 1619 struct dev_info *devi = DEVI(dip); 1620 ASSERT(dip != NULL); 1621 1622 /* for vHCI, enforce (vHCI, pHCI) ndi_deve_enter() order */ 1623 ASSERT(!MDI_VHCI(dip) || (mdi_devi_pdip_entered(dip) == 0) || 1624 DEVI_BUSY_OWNED(dip)); 1625 1626 mutex_enter(&devi->devi_lock); 1627 if (devi->devi_busy_thread == curthread) { 1628 devi->devi_circular++; 1629 } else { 1630 while (DEVI_BUSY_CHANGING(devi) && !panicstr) 1631 cv_wait(&(devi->devi_cv), &(devi->devi_lock)); Now, the analysis branches up: 1. It is possible that there's a busy thread active on that devinfo node. So find devi->devi_busy_thread: disassemble a bit of the code of ndi_devi_enter() to see what register / what place on the stack contains the "devi" pointer; arg#0 (30000df1c50) is a quick guess but you need to verify that the compiler hasn't decided to move that around to a different register. ::print it as "struct dev_info", and check for the devi_busy_thread field. If you find one, again try ::findstack on that to see what it does. Shortcut (may not work if the compiler re-used %i0): 30000df1c50::print struct dev_info devi_busy_thread | ::findstack -v 2. Otherwise, DEVI_BUSY_CHANGING(devi) may be true even though there's currently noone operating on that devinfo node. Someone more familiar with the devvfg code than myself may be able to comment on such situations and whether/when they are allowed to happen. For me personally, I'd suspect a bug if I'd find that, it should never be the case that DEVI_BUSY_CHANGING(devi) is true but devi->devi_busy_thread is NULL ... Should you find this, would you mind then sharing this crashdump with us ? Bye, FrankH. > 000002a100548731 abcd_CreateDevInfo+0x204(30002adf380, 30002e84180, > 7, 30002d90540, 1, 0) > 000002a100548801 abcd_ArrayPathAttachEvent+0x1c4(30002adf380, > 30002d90540, 0, 0 , 0, 8) > 000002a1005488e1 abcd_iPathEvent+0x98(30002d90540, 0, 30003a4d108, > 13, 701e8ac0 , 0) > 000002a1005489d1 pathAttach+0x1b0(30002d90540, 701e8ab8, 2000, 13, 0, > 0) > 000002a100548aa1 def_PathCreate+0x1b8(30002de13d0, 30002de13d0, 16, > 58, 2a100549434, 2a100549438) > 000002a100548b81 def_attach+0x2c(30002de13d0, 0, 0, 0, 0, 0) > 000002a100548c51 devi_attach+0xac(30002de13d0, 0, 300000f31c0, > 300000ec000, 0 , 7bba6530) > 000002a100548d21 attach_node+0x80(30002de13d0, 1, 0, 1, 2, 4) > 000002a100548dd1 i_ndi_config_node+0x104(30002de13d0, 114, 10b9be8, > 10, 1852800, 10b9800) > 000002a100548e81 i_ddi_attachchild+0x48(30002de13d0, > ffffffffffffffff, 1, 300003b94c8, 0, 0) > 000002a100548f41 devi_attach_node+0x5c(30002de13d0, 4014048, 4014048, > 50000000 , 4014048, 20000) > 000002a100548ff1 devi_attach_children+0x6c(30002de15b0, 4014048, > 30002de13d0, 8, ffffffffffffffff, ffffffff) > 000002a1005490a1 config_immediate_children+0x68(300003b94c8, 1, > ffffffff, 300003b9530, 0, 18bd368) > 000002a100549161 devi_config_common+0xa4(300003b94c8, 2, ffffffff, > 300000b5ef8 , 0, 4004048) > 000002a100549211 mt_config_thread+0x60(30002b0b5c0, 0, 3000036a748, > 1835b00, 300003b94c8, 300024aa540) > 000002a1005492d1 thread_start+4(30002b0b5c0, 0, 0, 0, 0, 0) > > Regards, > Kiran > > > -----Original Message----- > From: Frank.Hofmann at Sun.COM [mailto:Frank.Hofmann at Sun.COM] > Sent: Wednesday, September 06, 2006 4:36 PM > To: C, Kiran (STSD) > Cc: mdb-discuss at opensolaris.org > Subject: RE: [mdb-discuss] How to debug a Kernel Hang using mdb??? > > On Wed, 6 Sep 2006, C, Kiran (STSD) wrote: > >> Hi, >> Yeah, the whole is system is hung.. >> When you do a reboot.. It is hung at a point and it is not coming up >> after that.. >> >> When I do ::filndlocks it Is showing a thread which is holding the >> lock.. When I check the stack trace of this thread there are various >> functions which is blocked and the thread is waiting for cv to be >> released. >> >> ::findlocks >> 1852a38 (struct di_cache.cache_lock) is owned by 300025d4640 >> findlocks: nota bene: other locks may be held >>> 300025d4640::findstack >> stack pointer for thread 300025d4640: 2a1005a0c41 [ 000002a1005a0c41 >> cv_wait+0x38() ] >> 000002a1005a0cf1 mt_config_fini+0x20() >> 000002a1005a0da1 devi_config_common+0x118() >> 000002a1005a0e51 di_copytree+0x50() >> 000002a1005a0f01 di_snapshot+0xf0() >> 000002a1005a1011 di_cache_update+0x28() >> 000002a1005a10c1 di_ioctl+0x564() >> 000002a1005a1191 ioctl+0x184() >> 000002a1005a12e1 syscall_trap32+0xcc() >>> >> >> I am stuck at this point. Now my doubt is who is holding the lock and >> how to release it.. > > The above reminds me of 6348316 - is this an unpatched Solaris 10 system ? > If so, install the kernel patch, might well help. If it's OpenSolaris (i.e. > a Solaris Express, SchilliX, Nexenta, Belenix, home-grown install) > then you may wish to do further analysis as it's something else then ... > > Noone is holding the "lock" that _this_ guy is waiting for. "Lock" is > a wonderful term anyway, with about O(googolplex) overloaded meanings ... > > In Solaris (in the kernel, specifically), there are multiple types of > what we call "synchronization primitives": > > - adaptive mutexes ("mutually exclusive"). > These are locks that, in the adaptive variant, have owners. > A mutex is used to ensure that "critical sections" (access to > a specific piece of global data) can never be entered by two or > more threads at a time. > - spinlocks > Same purpose as mutexes - but have no owner, and don't put a > thread that attempts to grab such a lock to sleep; instead, the > attempt to acquire such a lock will burn CPU cycles in an > endless loop (hence "spin"). Generally only used for interrupt > handlers, scheduling - areas where high efficiency in the usual > codepath is more important than low impact in the unusual. > Solaris has multiple variants of these - spin mutexes, thread > locks, dispatcher locks. Your ordinary driver/kernel code will > not often use these. > - reader/writer locks (shared/exclusive) > A tri-state (unlocked, shared, exclusive) lock used in cases > where preventing modification of state is "unusual". Codepaths > that just need a critical section to stay stable will readlock > it, and many such readers can process concurrently. The attempt > to change such a critical section requires exclusive (write) > access, and only one such writer can be active at a time, and > will, while holding the lock, block out all attempts to aquire > the lock either shared or exclusive by others. > rwlocks have owners but only if exclusively/write locked. When > readlocked, they're only tagged as "locked by N readers". > - semaphores. > Only used for I/O in Solaris; read standard CS books on what > a semaphore is, please - Solaris mostly uses degenerate > semaphores, with a hold count 1. I never really had to bother > with these in eight years ... > - condition variables. > These are not locks. They're state. You use a condition variable > like this: > > mutex_enter(some_lock); > while (condition == FALSE) > cv_wait(some_cv, some_lock); > [ ... perform your processing ... ] > mutex_exit(some_lock); > > I.e. you enter a critical section, notice that there's still > something "insufficient" and wait (which drops the mutex). > Some other code section will do: > > mutex_enter(some_lock); > [ ... do some processing ... ] > condition = TRUE; > cv_broadcast(some_cv); > mutex_exit(some_lock); > > You use these for example to have a batch processing thread > wait for its worker threads to finish a unit of work before > submitting another one. This is what you see above with the > mt_config_fini(). > > See also mutex(9F), condvar(9F), rwlock(9F), semaphore(9F). As said, > the only type of lock that is "held" by an owner is the adaptive > mutex, and the exclusively-locked rwlock. Other synchronization primitives have no "owners" > ... > > Here, mt_config_fini() is waiting on a condition variable. The > interesting question is, is there any other thread around in a > codepath that eventually will lead to this condition variable being "triggered", i.e. > cv_signal/cv_broadcast called on it. > >> >> Alexander, "You need to look at stack traces for threads and see >> whether something looks suspicious. " >> >> I am really sorry I did not get what you meant by this statement. >> Could be more specific > > Getting a feeling for what's "suspicious" requires some experience > with crashdump analysis. There are many things suspicious to the > initiated that the beginner will never spot. So don't worry, you'll > become more and more suspicious the more crashdumps you look at :) > > In the above specific case, i.e. attempting to find out why that shown > thread is not making progress, start like this: > > 1. Check the OpenSolaris code for mt_config_fini(), and find out what this > condition variable is. You'll end up with this piece of devcfg.c: > > 6406 static int > 6407 mt_config_fini(struct mt_config_handle *hdl) > 6408 { > 6409 int rv; > 6410 #ifdef DEBUG > 6411 int real_time; > 6412 timestruc_t end_time; > 6413 #endif /* DEBUG */ > 6414 > 6415 mutex_enter(&hdl->mtc_lock); > 6416 while (hdl->mtc_thr_count > 0) > 6417 cv_wait(&hdl->mtc_cv, &hdl->mtc_lock); > 6418 rv = hdl->mtc_error; > 6419 mutex_exit(&hdl->mtc_lock); > > 2. Check the source for callers of cv_signal/cv_broadcast on mtc_cv. > You'll find the following location, again devcfg.c: > > 6448 static void > 6449 mt_config_thread(void *arg) > 6450 { > [ ... ] > 6483 mutex_enter(&hdl->mtc_lock); > [ ... ] > 6516 if (--hdl->mtc_thr_count == 0) > 6517 cv_broadcast(&hdl->mtc_cv); > 6518 mutex_exit(&hdl->mtc_lock); > 6519 kmem_free(mcd, sizeof (*mcd)); > 6520 } > > Now, since your crashdump shows mt_config_fini() is still waiting for > some other thread in mt_config_thread() to finish its processing and > issue the shown cv_broadcast() call, you of course need to start > looking for a thread with a stacktrace that contains > mt_config_thread(). That's what Alex meant with "suspicious". > > Find that, pls. post it here, and I'll tell you the next step. > Debugging hangs (following such dependency chains of > who-waits-for-what) is an iterative process ... > > The above mt_config_fini()/mt_config_thread() synchronization (even if > it works out to be 6348316, may or may not be the only thing that your > dump shows. Again, "suspicious". But not everyone in a cv_wait() call > must necessarily be starving to death - there's nothing wrong with a > long-term wait as such. It all depends on the codepath, and here > reading and understanding the source comes in when you evaluate "suspicious" things. > > Of course, CPU states (interrupt level blockage) can cause hangs. > Memory exhaustion can cause hangs. True deadlocks involving > mutexes/rwlocks or even combinations of such can cause hangs. And every such hang is different ... > > See above for some ideas; as said, pls. come back with the stacktrace > for > mt_config_thread() once you've found it, and I'll comment again. > > Bye, > FrankH. > >> >> Cheers >> Kiran >> >> >> -----Original Message----- >> From: Alexander Kolbasov [mailto:akolb at eng.sun.com] >> Sent: Wednesday, September 06, 2006 3:33 AM >> To: C, Kiran (STSD) >> Cc: mdb-discuss at opensolaris.org >> Subject: Re: [mdb-discuss] How to debug a Kernel Hang using mdb??? >> >>> Hi, >>> >>> >>> I have a Solaris 10 system.. and it hanged I initiated a forced >>> panic >> using "sync" I have a core dump when i do $c it shows the stack >> backtrace. and i can see it is hanging in a solaris system call.. >>> >>> Now my question is how to debug the kernel hang... I am suspecting a >> locking issue in one of the functions.. for the system hang.. >>> Is there any command to see the locking issues and not being >>> unlocked in any functions (doing a mutex_enter and not exiting) >>> >>> is there any commands in mdb where in i can find the pssible reason >> for the system hang.. >> >> When investigating system hangs you need to figure out >> >> - Is it the whole system that is hang or some processes? >> - Is there any forward progress? >> >> Before you force the core dump you may try running ::cpuinfo -v >> command >> >> It will show you what threads are on CPUs and on run queues. You may >> use ::findstack to get stack information for these threads. >> >> The $c will not show you anything useful if the core dump was >> produced by sync. >> You need to look at stack traces for threads and see whether >> something looks suspicious. >> >> To check for possible locking issues you can do >> >> ::typegraph >> >> followed by >> >> ::findlocks >> >> This will show kernel locks hold, you may check stack traces of lock >> owners. >> >> - Alexander Kolbasov >> >> _______________________________________________ >> mdb-discuss mailing list >> mdb-discuss at opensolaris.org >> > > ------------------------------------------------------------------------ -- > If anything's worth doing, do it with all your heart. The Buddha > Wheresoever you go, go with all your heart. Confucius > Whatever you do, do it with all your heart. St.Paul, Col 3:23 > ---------------------------------------------------------------------- > ---- > > ------------------------------------------------------------------------ -- If anything's worth doing, do it with all your heart. The Buddha Wheresoever you go, go with all your heart. Confucius Whatever you do, do it with all your heart. St.Paul, Col 3:23 ------------------------------------------------------------------------ --
