Fix panic message to indicate right action that was improper.

[imp]

Summary

Require and enforce that dareprobe() has to be called with the periph lock held.

Update the softc state of the da driver before releasing the CCB.

There are contexts where releasing the ccb triggers dastart() to be run
inline. When da was written, there was always a deferral, so it didn't matter
much. Now, with direct dispatch, we can call dastart from the dadone*
routines. If the probe state isn't updated, then dastart will redo things with
stale information. This normally isn't a problem, because we run the probe state
machine once at boot... Except that we also run it for each open of the device,
which means we can have multiple threads racing each other to try to kick off
the probe. However, if we update the state before we release the CCB, we can
avoid the race. While it's needed only for the probewp and proberc* states, do
it everywhere because it won't hurt the other places.

Add asserts for some state transitions

For the PROBEWP and PROBERC* states, add assertiosn that both the da device
state is in the right state, as well as the ccb state is the right one when we
enter dadone_probe{wp,rc}. This will ensure that we don't sneak through when
we're re-probing the size and write protection status of the device and thereby
leak a reference which can later lead to an invalidated peripheral going away
before all references are released (and resulting panic).

Test Plan

We have like 32 reprobes that happen on boot for the USB sticks that the Netflix OCA hardware has for emergency backup booting. These race, as I've been able to get a reliable panic because we get into the state machine stuff twice due to the race presented here. This fixes things so that we only get into it once.

I added debugging and would see sequences like this:

(da0:umass-sim0:0:0:0): starting to reprobing...
(da0:umass-sim0:0:0:0): WP START 0xfffff800043ce000
KDB: stack backtrace:
db_trace_self_wrapper() at db_trace_self_wrapper+0x2b/frame 0xfffffe00d5afe280
dastart() at dastart+0xb17/frame 0xfffffe00d5afe2d0
xpt_run_allocq() at xpt_run_allocq+0x1a2/frame 0xfffffe00d5afe320
daopen() at daopen+0x140/frame 0xfffffe00d5afe360
g_disk_access() at g_disk_access+0xef/frame 0xfffffe00d5afe3a0
g_access() at g_access+0x28f/frame 0xfffffe00d5afe410
g_access() at g_access+0x28f/frame 0xfffffe00d5afe480
g_eli_read_metadata_offset() at g_eli_read_metadata_offset+0xb5/frame 0xfffffe00d5afe540
g_eli_taste() at g_eli_taste+0xbb/frame 0xfffffe00d5afeb50
g_new_provider_event() at g_new_provider_event+0xaa/frame 0xfffffe00d5afeb70
g_run_events() at g_run_events+0x1a6/frame 0xfffffe00d5afebb0
fork_exit() at fork_exit+0x80/frame 0xfffffe00d5afebf0
fork_trampoline() at fork_trampoline+0xe/frame 0xfffffe00d5afebf0
--- trap 0, rip = 0, rsp = 0, rbp = 0 ---
(da0:umass-sim0:0:0:0): PROBEWP CCB state 18 da state 0 da flags 0x102e48 ccb 0xfffff800043ce000 softc 0xfffffe0384752000
KDB: stack backtrace:
db_trace_self_wrapper() at db_trace_self_wrapper+0x2b/frame 0xfffffe00d5bc2ae0
dadone_probewp() at dadone_probewp+0x75/frame 0xfffffe00d5bc2b20
xpt_done_process() at xpt_done_process+0x358/frame 0xfffffe00d5bc2b60
xpt_done_td() at xpt_done_td+0xf5/frame 0xfffffe00d5bc2bb0
fork_exit() at fork_exit+0x80/frame 0xfffffe00d5bc2bf0
fork_trampoline() at fork_trampoline+0xe/frame 0xfffffe00d5bc2bf0
--- trap 0, rip = 0, rsp = 0, rbp = 0 ---
(da0:umass-sim0:0:0:0): WP START 0xfffff80006000000
KDB: stack backtrace:
db_trace_self_wrapper() at db_trace_self_wrapper+0x2b/frame 0xfffffe00d5bc2a40
dastart() at dastart+0xb17/frame 0xfffffe00d5bc2a90
xpt_run_allocq() at xpt_run_allocq+0x1a2/frame 0xfffffe00d5bc2ae0
dadone_probewp() at dadone_probewp+0x126/frame 0xfffffe00d5bc2b20
xpt_done_process() at xpt_done_process+0x358/frame 0xfffffe00d5bc2b60
xpt_done_td() at xpt_done_td+0xf5/frame 0xfffffe00d5bc2bb0
fork_exit() at fork_exit+0x80/frame 0xfffffe00d5bc2bf0
fork_trampoline() at fork_trampoline+0xe/frame 0xfffffe00d5bc2bf0
--- trap 0, rip = 0, rsp = 0, rbp = 0 ---
(da0:umass-sim0:0:0:0): PROBEWP CCB state 18 da state 2 da flags 0x102e48 ccb 0xfffff80006000000 softc 0xfffffe0384752000
KDB: stack backtrace:
db_trace_self_wrapper() at db_trace_self_wrapper+0x2b/frame 0xfffffe00d5bc2ae0
dadone_probewp() at dadone_probewp+0x75/frame 0xfffffe00d5bc2b20
xpt_done_process() at xpt_done_process+0x358/frame 0xfffffe00d5bc2b60
xpt_done_td() at xpt_done_td+0xf5/frame 0xfffffe00d5bc2bb0
fork_exit() at fork_exit+0x80/frame 0xfffffe00d5bc2bf0
fork_trampoline() at fork_trampoline+0xe/frame 0xfffffe00d5bc2bf0
--- trap 0, rip = 0, rsp = 0, rbp = 0 ---

Notice that we get back into dadone_probewp() from a call to dadone_probewp(). Reversing the order of the state update and release fixed this race. I was hitting it every boot, now I rebooted 10 times w/o hitting it, or the stringent kasserts I added.

Note, the tracebacks are a little odd because dareprobe() is aggressively inlined. And the debug writes were added in the logical spots in the code (STARTs right before xpt_action, PROBE* lines right at the top of the dadone_probe* routines). dareprobe() prints the starting message... The funky 0x100000 bit in the da flags is a debug flag I added (but don't have in this patch) that I set when I took the reference, and cleared when I released it....

[imp]

I think what we're seeing is that we're running this with the queue unfrozen. This sometimes leads to the race I found because, I think, we run things twice: once in the ccb release path, and then again in the schedule path. The freezes and single stepping has always confused me. Part of the confusion is why we only see this sometimes... How does that come to be... The other is why does setting the state *SEEM* to fix this issue, because we should see double entry into the PROBERC state, rather than re-entry into the PROBEWC. I suspect this just never matter before the write-protect probing code was added since we always exited from PROBERC, race or no and there was no chance to actually race due to the DA_FLAGS_PROBED short-circuiting.

[ken]

Good catch, thank you!