pstore dump inside an nmi handler

Hi Tony,

I was playing with the APEI EINJ module, injecting errors trying to capture a GHES record, then panic into a kdump kernel and reboot.

Matthew brought to my attention that pstore should capture an error record on the panic path using kmsg_dump(). After injecting an error with EINJ, I went to check to see if there was a pstore entry. There wasn't.

Playing on another box, I noticed the machine double faulted and didn't even make it into a kdump kernel.

Upon investigation, I noticed that when a fatal error occurs on the platform, it will generate an NMI that will be handle by the ghes_nmi_handler. This handler calls panic() which calls kmsg_dump() which calls pstore_dump().

Inside pstore_dump(), the first thing it tries to grab is a mutex_lock() (inside an nmi hander). This seems to be the root cause of my problems.

I am not familiar enough with pstore to just modify its locking, so I wanted to ask you.

My first thought was to wrap the mutex_lock with a 'if !in_nmi()', but that seemed kinda hacky. Then I was wondering if there was a way to do this locklessly or atomically because you are only dealing with whole blocks I think. I don't know.

Wanted to give you a heads up and seek your thoughts. I am willing to hack up some code and test. :-)

Cheers,
Don

Someone else pointed out that mutex_lock() is a problem here too. They wondered whether spin_lock_irqsave() would work - or whether pstore backends were allowed to sleep - to which I said I hoped they didn't, but wasn't really sure what the future will hold.

So ... ideas (and patches) are most welcome.

-Tony

From: "Luck, Tony" <[email protected]>
Date: Fri, 8 Jul 2011 14:40:13 -0700

Probably you'll need to queue things atomically using something based upon cmpxchg() like the generic ring buffer does.

EFI can't sleep (at least, not as far as the kernel's concerned), so we're safe there. I think it's fair to assume atomicity here - crash dumping is a pretty specific situation. Although we may need to think about whether pstore should be saving reboot and poweroff in that case.

Matthew Garrett | [email protected]

Hitachi engineers were very vocal about wanting the reboot/poweroff logs (so they could deal with customers who accidentally rebooted the wrong machine, and then denied doing so while also logging reports that the victim machine had spontaneously reset).

-Tony

Hmm, reading the ERST spec in ACPI4 (which is the backend behind pstore on x86 boxes), it seems that reading/writing involves a state machine. The code doesn't seem to account for this if in the middle of reading an error record, a system error occurs and you need to write an error record. I imagine the state machine would get screwed up and you would lose any info you tried writing.

But perhaps, if we detect a spinlock is in use, we can bust it and reset the state machine to solve that problem?

Cheers,
Don

I tested the spin_lock_irqsave thing on my one box where it was failing and got past my initial problem into kdump. So that is a positive and I can post the patch for that. Though it probably isn't a complete solution, it is better than a mutex.

However, I have been scratching my head at a follow up problem, which is when I inject an error which produces an NMI->GHES->panic, the error record doesn't get stored under pstore (or maybe ERST too). I do see the ERST code follow all the correct steps in storing the kmsg_dump logs into the ERST table. Just on the reboot, when I mount pstore it isn't there.

When I perform an 'echo c > /proc/sysrq-trigger', it shows up on the reboot. Not sure what can be going wrong. I cc'd Ying with hopes he might have some thoughts.

Cheers,
Don

Actually, is it expected that the ERST can handle only 8 records? Also if you remove those records with pstore mount under /mnt; 'rm -rf /mnt/dmesg-*', are those records removed immediately or are they cached to be removed later? IOW, if a did a 'rm -rf ..' and then an 'echo c > /proc/sysrq-trigger' immediately after it, would I expect those records to be removed or not? Testing shows they are removed on reboot but the later 'echo c > ..' didn't save any new error records. :-/

Cheers,
Don

It isn't specified how much storage will be provided by ERST. I tried to find a limit on the system on which I did the original development, but got bored at a hundred ... which seemed to be plenty enough since the usual mode of operation ought to be to copy the records from pstore to some other storage and remove them from pstore early in boot.

The unlink from pstore is passed immediately to the backing store to do it's clear/erase operation ... but whether the BIOS implementation of ERST makes that space immediately available might vary from platform to platform.

-Tony

The ERST table specifies a series of actions to perform to make the records get saved to (or read from) the platform persistent store. These actions will be dependent on the h/w, and also on the creativity of the BIOS writer who composed the ERST action table.

Resetting the state machine looks like it might be tricky from any arbitrary point in the sequence.

-Tony

I agree and I think Matthew told me privately, it would probably be an untested path, which would make things more problematic. It would be nice to have an NVRAM implementation. That looks simpler and more robust in a panic path. But that is up to the vendor's BIOS. :-(

Cheers,
Don