Article: 77734 of comp.unix.solaris From: Gavin Maltby Newsgroups: comp.unix.solaris Subject: Re: SC 3.0 cluster crash Date: Mon, 17 May 2004 15:33:27 +0100 Organization: Sun Microsystems Lines: 137 Message-ID: References: NNTP-Posting-Host: montgomery.uk.sun.com Mime-Version: 1.0 Content-Type: text/plain; charset=us-ascii; format=flowed Content-Transfer-Encoding: 7bit X-Trace: new-usenet.uk.sun.com 1084804408 28210 129.156.195.50 (17 May 2004 14:33:28 GMT) X-Complaints-To: usenet@new-usenet.uk.sun.com NNTP-Posting-Date: 17 May 2004 14:33:28 GMT User-Agent: Mozilla/5.0 (X11; U; SunOS sun4u; en-US; rv:1.7a) Gecko/20040114 X-Accept-Language: en-us, en In-Reply-To: Path: news.meer.net!sea-read.news.verio.net!dfw-artgen!newspeer1.stngva01.us.to.verio.net!news.verio.net!news.glorb.com!prodigy.com!atl-c02.usenetserver.com!news.usenetserver.com!border1.nntp.dca.giganews.com!nntp.giganews.com!newsfeed-east.nntpserver.com!nntpserver.com!206.253.211.161!newsfeed1.sea.pnap.net!newsfeed2.sea.pnap.net!newsfeed.pnap.net!brmea-news-1.sun.com!news1nwk.sfbay.sun.com!new-usenet.uk.sun.com!not-for-mail Xref: archive.mv.meer.net comp.unix.solaris:77734 Hi Dragan Cvetkovic wrote: > Hi, > > one of our Suns (FR280R) crashed (after starting devfsadm) and produced the > following message in /var/adm/messages: > > May 14 14:42:42 sc1 ^Mpanic[cpu0]/thread=30004d157e0: > May 14 14:42:42 sc1 unix: [ID 237512 kern.notice] bad kernel MMU miss at TL 2 > May 14 14:42:42 sc1 unix: [ID 100000 kern.notice] > May 14 14:42:42 sc1 unix: [ID 293396 kern.notice] %tl %tpc %tnpc %tstate %tt > May 14 14:42:42 sc1 unix: [ID 785305 kern.notice] 1 00000000013fa228 00000000013fa22c 4480001605 068 > May 14 14:42:42 sc1 unix: [ID 898499 kern.notice] %ccr: 44 %asi: 80 %cwp: 5 %pstate: 16 > May 14 14:42:42 sc1 unix: [ID 785305 kern.notice] 2 00000000010071f0 00000000010071f4 9180001506 068 > May 14 14:42:42 sc1 unix: [ID 898499 kern.notice] %ccr: 91 %asi: 80 %cwp: 6 %pstate: 15 > May 14 14:42:42 sc1 unix: [ID 216294 kern.notice] %g0-3: 0000000000000000 0000000000000002 00000000ff400900 00000 > 000ff400900 > May 14 14:42:42 sc1 unix: [ID 600269 kern.notice] %g4-7: 0000000000000000 0000000000000002 000000000140a440 00000 > 00000000068 > May 14 14:42:42 sc1 unix: [ID 531632 kern.notice] Register window 6, caller hidparser_GlobalItem+2b4 > May 14 14:42:42 sc1 unix: [ID 454034 kern.notice] %o0-3: 000002a10238de90 000002a10238c000 0000000000000031 00000 > 00000000000 > May 14 14:42:42 sc1 %o4-7: 00000000000002a1 0000000000000000 000002a10238d551 00000000013fae60 > May 14 14:42:42 sc1 unix: [ID 960796 kern.notice] %l0-3: 00000000013fa228 00000000013fa22c 0000004480001605 00000 > 0000102c90c > > [the rest snipped] There's been a DMMU miss while already handling a DMMU miss - isn't supposed to happen (the initial DMMU handling takes all sorts of care to avoid triggering further misses) and can't be recovered. The most common reason for "bad kernel MMU miss at TL 2" panics is kernel stack overflow - eg with some (usually 3rd party) STREAMs modules recursing too much or being greedy on stack, or when you have 300 layers above your disks. But this one does not look like a stack overflow - not quite the correct signature I think. The stuff you snipped may tell us more. Solaris 9 (certainly by KU-11) dumps a lot more info for this type of panic than used to be the case. You can dig it up manually in mdb as follows: - '::print -at cpu_t ! tail -10' and note the offset of the cpu_m member: > ::print -at cpu_t ! tail -10 4c8 void * [1] _opaque } 4d0 kmutex_t cpu_pid_lock { 4d0 void * [1] _opaque } 4d8 uintptr_t cpu_dtrace_caller 4e0 hrtime_t cpu_dtrace_chillmark 4e8 hrtime_t cpu_dtrace_chilled 4f0 struct machcpu cpu_m (forward declaration) } So I'd note '4f0' in my case - panic_cpu+4f0::print -t machcpu_t ptl1_state (substituting your value for the '4f0'). - that will print out a whole bunch of info collected as the problem happened, and it's that which appears (reformatted and not all of it) on the console. For eacg ptl1_tpc and ptl1_tnpc value dumped above, do a /ai in mdb so we can see what code that is > > After the reboot, I have done mdb on the crash files and here is the > output: > > sc1# mdb unix.2 vmcore.2 > Loading modules: [ unix krtld genunix ip ipc ufs_log s1394 usba logindmux ptm cpc random nfs ] > >>$c > > panicsys+0x44(1057830, 1401f08, 1438120, 1, 0, 0) > vpanic+0xcc(1057830, 1401f08, 0, 0, 0, 0) > panic+0x1c(1057830, 1057790, 2, 0, 0, 0) > ptl1_panic_handler+0x6c(1400900, 30004d157e0, 20, 0, 100c6c0, 0) > kmem_cache_alloc+0x64(0, ffffffffffffffff, 20, 0, 85, 0) That's incomplete. Some digging may turn up a fuller stack frame. For a start try 30004d157e0::findstack >>::status > > debugging crash dump vmcore.2 (64-bit) from sc1 > operating system: 5.9 Generic_112233-11 (sun4u) > panic message: bad kernel MMU miss at TL 2 > dump content: kernel pages only > > > Now, this machine is a part of a cluster (SC 3.0) and a rather unfortunate > thing was that the other machine could not take over the disk sets (on a > shared D1000 disk array) the first one owned. For one diskset, mount > command insisted that it was still mounted (global FS), but it could not be > seen. For the same reason scshutdown didn't work so I had to do init 6 on > both machines. > > After that it refused to mount the said FS until I did fsck on it. > > I was expecting cluster machines to gracefully take over, but at the end, > it didn't work. I know nothing about cluster and hope to keep it that way :-) > We are running Solaris 9 and generally try to keep with the patches (or did > try until a month or two ago). > > What does the above message mean (bad kernel MMU miss at TL 2)? > SPARC v9 has nested traps. You run at trap level (TL) most of the time, and "trap" up a level to TL1 on an exception (eg, a window spill - write register window out to stack). Once at this elvated trap level things are much more restricted, and only certain traps are allowed to happen from there (for example on a window spill you may get a nested DMMU miss if the stack page we have to write to is not translated in the MMU - we just pop a translation in and then resume the window spill handling). One of the illegal combinations is to take a MMU miss while already handling an MMU miss; that's because MMU miss has only one set of resources associated with it (registers to record what address was being accessed, how, scratch registers to work in while resolving etc) and the second occurence overwrites the first. Software has to take care not to do anything that could cause illegal traps while it's already handling an exception. I'd suggest raising a service call. The panic dump will be interesting but probably not enough on it's own to diagnose this. Gavin Article: 77844 of comp.unix.solaris From: Gavin Maltby Newsgroups: comp.unix.solaris Subject: Re: SC 3.0 cluster crash Date: Tue, 18 May 2004 17:12:41 +0100 Organization: Sun Microsystems Lines: 128 Message-ID: References: NNTP-Posting-Host: montgomery.uk.sun.com Mime-Version: 1.0 Content-Type: text/plain; charset=us-ascii; format=flowed Content-Transfer-Encoding: 7bit X-Trace: new-usenet.uk.sun.com 1084896765 25013 129.156.195.50 (18 May 2004 16:12:45 GMT) X-Complaints-To: usenet@new-usenet.uk.sun.com NNTP-Posting-Date: 18 May 2004 16:12:45 GMT User-Agent: Mozilla/5.0 (X11; U; SunOS sun4u; en-US; rv:1.7a) Gecko/20040114 X-Accept-Language: en-us, en In-Reply-To: Path: news.meer.net!sea-read.news.verio.net!dfw-artgen!newspeer1.stngva01.us.to.verio.net!news.verio.net!news.glorb.com!news3.optonline.net!newsfeed-east.nntpserver.com!nntpserver.com!206.253.211.161!newsfeed1.sea.pnap.net!newsfeed2.sea.pnap.net!newsfeed.pnap.net!brmea-news-1.sun.com!news1brm.central.sun.com!new-usenet.uk.sun.com!not-for-mail Xref: archive.mv.meer.net comp.unix.solaris:77844 Dragan Cvetkovic wrote: > > For one CPU, it's > > >>> 0x10071f0/ai > > user_trap+0xb8: > user_trap+0xb8: stx %l0, [%l7 + 0x80] > >>> 0x10071f4/ai > > user_trap+0xbc: > user_trap+0xbc: stx %l1, [%l7 + 0x88] OK, that's some trap glue trying to preserve some information on a stack ... > for the other > > >>> 0x13fa228/ai > > hidparser_Items+0xc: > hidparser_Items+0xc: clrx [%fp + 0x7f7] and that is trying to zero something on stack ... so a stack overflow may well be on the cards, and >>> 0x13fa22c/ai > > hidparser_Items+0x10: > hidparser_Items+0x10: sra %l0, 0, %o1 > > >>30004d157e0::findstack > > stack pointer for thread 30004d157e0: 2a10238d8f1 > 000002a10238d9c1 hidparser_ItemList+0x44() > 000002a10238da91 hidparser_ItemList+0x44() > 000002a10238db61 hidparser_ItemList+0x44() > 000002a10238dc31 hidparser_ItemList+0x44() > 000002a10238dd01 hidparser_ItemList+0x44() > 000002a10238ddd1 hidparser_ItemList+0x44() > 000002a10238dea1 hidparser_ItemList+0x44() > 000002a10238df71 hidparser_ItemList+0x44() > 000002a10238e041 hidparser_ItemList+0x44() > 000002a10238e111 hidparser_ItemList+0x44() > 000002a10238e1e1 hidparser_ItemList+0x44() > 000002a10238e2b1 hidparser_ItemList+0x44() > 000002a10238e381 hidparser_ItemList+0x44() > 000002a10238e451 hidparser_ItemList+0x44() > 000002a10238e521 hidparser_ItemList+0x44() > 000002a10238e5f1 hidparser_MainItem+0xb4() > 000002a10238e6b1 hidparser_ItemList+0x2c() > 000002a10238e781 hidparser_ItemList+0x44() > 000002a10238e851 hidparser_ItemList+0x44() > 000002a10238e921 hidparser_ItemList+0x44() > 000002a10238e9f1 hidparser_ItemList+0x44() > 000002a10238eac1 hidparser_ItemList+0x44() > 000002a10238eb91 hidparser_ItemList+0x44() > 000002a10238ec61 hidparser_ItemList+0x44() > 000002a10238ed31 hidparser_ItemList+0x44() > 000002a10238ee01 hidparser_ItemList+0x44() > 000002a10238eed1 hidparser_ItemList+0x44() > 000002a10238efa1 hidparser_ItemList+0x44() > 000002a10238f071 hidparser_ItemList+0x44() > 000002a10238f141 hidparser_ItemList+0x44() > 000002a10238f211 hidparser_ItemList+0x44() > 000002a10238f2e1 hidparser_ItemList+0x44() > 000002a10238f3b1 hidparser_ItemList+0x44() > 000002a10238f481 hidparser_ItemList+0x44() > 000002a10238f551 hidparser_ItemList+0x44() > 000002a10238f621 hidparser_ItemList+0x44() > 000002a10238f6f1 hidparser_ItemList+0x44() > 000002a10238f7c1 hidparser_ItemList+0x44() > 000002a10238f891 hidparser_ItemList+0x44() > 000002a10238f961 hidparser_ItemList+0x44() > 000002a10238fa31 hidparser_ItemList+0x44() > 000002a10238fb01 hidparser_ItemList+0x44() > 000002a10238fbd1 hidparser_ItemList+0x44() > 000002a10238fca1 hidparser_ItemList+0x44() > 000002a10238fd71 hidparser_ItemList+0x44() > 000002a10238fe41 hidparser_ItemList+0x44() > 000002a10238ff11 hidparser_ItemList+0x44() > 000002a10238ffe1 hidparser_ItemList+0x44() > 000002a1023900b1 hidparser_ItemList+0x44() > 000002a102390181 hidparser_ItemList+0x44() > 000002a102390251 hidparser_MainItem+0xb4() > 000002a102390311 hidparser_ItemList+0x2c() > 000002a1023903e1 hidparser_MainItem+0xb4() > 000002a1023904a1 hidparser_ItemList+0x2c() > 000002a102390571 hidparser_ReportDescriptor+0x10() > 000002a102390621 hidparser_ReportDescriptorDash+0x10() > 000002a1023906d1 hidparser_main+0x74() > 000002a102390781 hidparser_parse_report_descriptor+0x14() > 000002a102390841 hid_handle_report_descriptor+0x7c() > 000002a102390911 hid_attach+0x308() > 000002a102390a01 devi_attach+0xac() > 000002a102390ad1 attach_node+0x6c() > 000002a102390b81 i_ndi_config_node+0xe8() > 000002a102390c31 impl_initdev+0x30() > 000002a102390ce1 impl_proto_to_cf2+0xa0() > 000002a102390da1 attach_driver_to_hw_nodes+0xe8() > 000002a102390e61 ddi_hold_installed_driver+0x234() > 000002a102390f21 di_hold_drivers+0x108() > 000002a102390fd1 di_snapshot+0x34() > 000002a1023910e1 di_ioctl+0x4e8() > 000002a1023911a1 ioctl+0x1f8() > 000002a1023912f1 syscall_trap32+0xa8() > Whoa! That seems like a lot of recursion from an attach(9e) point?? Each hidparser_ItemList is grabbing 208 bytes of stack, and hidparser_MainItem looks like it takes 192 bytes of stack. Kernel stacks don't like lots of recursion. There's a sunsolve infodoc on stack recursions; #20151 I *think*. The above *may* have been avoided by increasing the default size for lwps. Cheers Gavin Article: 77836 of comp.unix.solaris From: jwadams@gmail.com (Jonathan Adams) Newsgroups: comp.unix.solaris Subject: Re: SC 3.0 cluster crash Date: 18 May 2004 07:48:04 -0700 Organization: http://groups.google.com Lines: 22 Message-ID: References: NNTP-Posting-Host: 66.92.16.223 Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: 8bit X-Trace: posting.google.com 1084891685 1678 127.0.0.1 (18 May 2004 14:48:05 GMT) X-Complaints-To: groups-abuse@google.com NNTP-Posting-Date: Tue, 18 May 2004 14:48:05 +0000 (UTC) Path: news.meer.net!sea-read.news.verio.net!dfw-artgen!newspeer1.stngva01.us.to.verio.net!news.verio.net!news.glorb.com!postnews1.google.com!not-for-mail Xref: archive.mv.meer.net comp.unix.solaris:77836 Gavin Maltby wrote: > The stuff you snipped may tell us more. Solaris 9 (certainly by KU-11) > dumps a lot more info for this type of panic than used to be the case. > You can dig it up manually in mdb as follows: > > - '::print -at cpu_t ! tail -10' and note the offset of the cpu_m member: > > > ::print -at cpu_t ! tail -10 ... > 4e8 hrtime_t cpu_dtrace_chilled > 4f0 struct machcpu cpu_m (forward declaration) > } > > So I'd note '4f0' in my case > > - panic_cpu+4f0::print -t machcpu_t ptl1_state An easier way to do this is to do: > panic_cpu::print -t unix`cpu_t cpu_m.plt1_state - jonathan