powerpc64 head -r314687 (PowerMac G5 so-called "Quad Core", clang based): CAM status: Command timeout (always?)

[Mark Johnston]

On Tue, Mar 07, 2017 at 12:10:31AM -0800, Mark Millard wrote:
> The debug kernel has not failed so far but does report
> sleeping with a non-sleepable lock held (in addition
> to a lor):
> 
> Expensive timeout(9) function: 0xe84630(0xdc4a10) 0.026154120 s

What symbol does this correspond to?

> Sleeping on "smu" with the following non-sleepable locks held:

Looks like smu_gettime() calls smu_run_cmd(), which may sleep. This is
specific to powerpc.

> exclusive sleep mutex tod2rl (tod2rl) r = 0 (0x122ef50) locked @ /usr/src/sys/kern/subr_rtc.c:135
> stack backtrace:
> #0 0x60e3bc at .get_spr+0x50d4dc
> #1 0x59a200 at .get_spr+0x499320
> #2 0x91b4cc at .rtascall+0x11dac
> #3 0x91a76c at .rtascall+0x1104c
> #4 0x5f0680 at .get_spr+0x4ef7a0
> #5 0x68729c at .get_spr+0x5863bc
> #6 0x512af4 at .get_spr+0x411c14
> #7 0x546600 at .get_spr+0x445720
> #8 0x935f70 at .fork_trampoline+0x10
> #9 0x935e44 at blocked_loop+0x38
> lock order reversal: (Giant after non-sleepable)
>  1st 0x122ef50 tod2rl (tod2rl) @ /usr/src/sys/kern/subr_rtc.c:135
>  2nd 0x1200b00 Giant (Giant) @ /usr/src/sys/kern/kern_synch.c:230
> stack backtrace:
> #0 0x60c9e4 at .get_spr+0x50bb04
> #1 0x56c504 at .get_spr+0x46b624
> #2 0x59a5d0 at .get_spr+0x4996f0
> #3 0x91b4cc at .rtascall+0x11dac
> #4 0x91a76c at .rtascall+0x1104c
> #5 0x5f0680 at .get_spr+0x4ef7a0
> #6 0x68729c at .get_spr+0x5863bc
> #7 0x512af4 at .get_spr+0x411c14
> #8 0x546600 at .get_spr+0x445720
> #9 0x935f70 at .fork_trampoline+0x10
> #10 0x935e44 at blocked_loop+0x38

This looks to be related to the above. vfs_mountroot() calls inittodr()
with Giant held, so the tsleep() in smu_run_cmd() will acquire Giant
after the (non-sleepable) tod2rl mutex upon waking up.

> uhub3: 3 ports with 2 removable, bus powered
> Setting hostuuid: 11fe4cb1-3cac-11e4-a5a8-001451685a44.
> Setting hostid: 0x489b688f.
> Starting file system checks:
> /dev/ufs/FBSDG5Lrootfs: FILE SYSTEM CLEAN; SKIPPING CHECKS
> /dev/ufs/FBSDG5Lrootfs: clean, 82126801 free (1058921 frags, 10133485 blocks, 1.1% fragmentation)
> Mounting local filesystems:.
> 
> (The symbolic routine names it shows are not of much use.
> I could use /usr/local/bin/objdump to look things up.)
> 
> Later there is another lor:
> 
> lock order reversal:
>  1st 0xa046b78 ufs (ufs) @ /usr/src/sys/kern/vfs_subr.c:2600
>  2nd 0xc0000000b6c90ba0 bufwait (bufwait) @ /usr/src/sys/ufs/ffs/ffs_vnops.c:280
>  3rd 0xb22e5f0 ufs (ufs) @ /usr/src/sys/kern/vfs_subr.c:2600

This is a known benign LOR.