Date: Mon, 24 Jul 2017 20:25:52 +0300 From: Alexander Motin <mav@FreeBSD.org> To: Eugene Grosbein <eugen@grosbein.net>, Mark Johnston <markj@FreeBSD.org> Cc: FreeBSD Stable <freebsd-stable@FreeBSD.org> Subject: Re: stable/11 debugging kernel unable to produce crashdump again Message-ID: <accdd071-035f-215b-d2a9-d1aa1c83f705@FreeBSD.org> In-Reply-To: <59762849.5090208@grosbein.net> References: <587928B3.2050607@grosbein.net> <20170113193726.GC77535@wkstn-mjohnston.west.isilon.com> <587A0E12.7070205@grosbein.net> <59746BD5.5010301@grosbein.net> <20170724014445.GA20872@raichu> <59762849.5090208@grosbein.net>
next in thread | previous in thread | raw e-mail | index | archive | help
I guess that problem of g_raid_shutdown_post_sync in case of panic can
be explained by the fact it tries to write clean metadata in regular
(not dumping) way while system is already in panic mode and there is no
proper scheduling. May be it could be just bypassed in case of dumping
(should be trivial and probably OK), or use g_raid_subdisk_kerneldump()
in that case instead of normal GEOM I/O.
On 24.07.2017 20:03, Eugene Grosbein wrote:
> CCing mav@ as graid expert.
>
> On 24.07.2017 08:44, Mark Johnston wrote:
>
>>> Sadly, this time 11.1-STABLE r321371 SMP hangs instead of doing crashdump:
>>>
>>> - "call doadump" from DDB prompt works just fine;
>>> - "shutdown -r now" reboots the system without problems;
>>> - "sysctl debug.kdb.panic=1" triggers a panic just fine but system hangs just afer showing uptime
>>> instead of continuing with crashdump generation; same if "real" panic occurs.
>>>
>>> Same for debug.minidump set to 1 or 0. How do I debug this?
>>
>> I'm not able to reproduce the problem in bhyve using r321401. Looking
>> at the code, the culprits might be cngrab(), or one of the
>> shutdown_post_sync eventhandlers. Since you're apparently able to see
>> the console output at the time of the panic, I guess it's probably the
>> latter. Could you try your test with the patch below applied? It'll
>> print a bunch of "entering post_sync"/"leaving post_sync" messages with
>> addresses that can be resolved using kgdb. That'll help determine where
>> we're getting stuck.
>>
>> Index: sys/sys/eventhandler.h
>> ===================================================================
>> --- sys/sys/eventhandler.h (revision 321401)
>> +++ sys/sys/eventhandler.h (working copy)
>> @@ -85,7 +85,11 @@
>> _t = (struct eventhandler_entry_ ## name *)_ep; \
>> CTR1(KTR_EVH, "eventhandler_invoke: executing %p", \
>> (void *)_t->eh_func); \
>> + if (strcmp(__STRING(name), "shutdown_post_sync") == 0) \
>> + printf("entering post_sync %p\n", (void *)_t->eh_func); \
>> _t->eh_func(_ep->ee_arg , ## __VA_ARGS__); \
>> + if (strcmp(__STRING(name), "shutdown_post_sync") == 0) \
>> + printf("leaving post_sync %p\n", (void *)_t->eh_func); \
>> EHL_LOCK((list)); \
>> } \
>> } \
>>
>
> Thanks, this helped:
>
> $ addr2line -f -e kernel.debug 0xffffffff80919c00
> g_raid_shutdown_post_sync
> /home/src/sys/geom/raid/g_raid.c:2458
>
> That is GEOM_RAID's g_raid_shutdown_post_sync() that hangs if called just before
> crashdump generation but works just fine during normal system shutdown.
>
> I should note my graid's RAID1 is running in degraded state currently
> due to dead SSD module that does not respond. Here is part of boot log:
>
> ahcich5: AHCI reset: device not ready after 31000ms (tfd = 00000080)
> ahcich5: Poll timeout on slot 2 port 0
> ahcich5: is 00000000 cs 00000004 ss 00000000 rs 00000004 tfd 80 serr 00000000 cmd 0000c217
> (aprobe2:ahcich5:0:0:0): NOP FLUSHQUEUE. ACB: 00 00 00 00 00 00 00 00 00 00 00 00
> (aprobe2:ahcich5:0:0:0): CAM status: Command timeout
> (aprobe2:ahcich5:0:0:0): Error 5, Retries exhausted
> run_interrupt_driven_hooks: still waiting after 60 seconds for xpt_config
> ahcich5: Poll timeout on slot 3 port 0
> ahcich5: is 00000000 cs 00000008 ss 00000000 rs 00000008 tfd 80 serr 00000000 cmd 0000c317
> (aprobe2:ahcich5:0:0:0): SOFT_RESET. ACB: 00 00 00 00 00 00 00 00 00 00 00 00
> (aprobe2:ahcich5:0:0:0): CAM status: Command timeout
> (aprobe2:ahcich5:0:0:0): Error 5, Retries exhausted
> [skip]
> Trying to mount root from ufs:/dev/raid/r0s4a [rw,noatime]...
> Root mount waiting for: GRAID-Intel
> Root mount waiting for: GRAID-Intel
> Root mount waiting for: GRAID-Intel
> Root mount waiting for: GRAID-Intel
> Root mount waiting for: GRAID-Intel
> GEOM_RAID: Intel-c291fe96: Force array start due to timeout.
> GEOM_RAID: Intel-c291fe96: Disk ada0 state changed from NONE to ACTIVE.
> GEOM_RAID: Intel-c291fe96: Subdisk r0:0-ada0 state changed from NONE to STALE.
> GEOM_RAID: Intel-c291fe96: Array started.
> GEOM_RAID: Intel-c291fe96: Subdisk r0:0-ada0 state changed from STALE to ACTIVE.
> GEOM_RAID: Intel-c291fe96: Volume r0 state changed from STARTING to DEGRADED.
> GEOM_RAID: Intel-c291fe96: Provider raid/r0 for volume r0 created.
>
>
>
--
Alexander Motin
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?accdd071-035f-215b-d2a9-d1aa1c83f705>