On 1/29/20 7:00 AM, Cornelia Huck wrote: > On Tue, 28 Jan 2020 23:13:30 -0500 > Eric Farman <farman@xxxxxxxxxxxxx> wrote: > >> On 1/28/20 9:42 AM, Eric Farman wrote: >>> >>> >>> On 1/28/20 4:58 AM, Cornelia Huck wrote: >>>> On Mon, 27 Jan 2020 16:28:18 -0500 >> >> ...snip... >> >>>> >>>> cp_init checking cp->initialized would probably be good to catch >>>> errors, in any case. (Maybe put a trace there, just to see if it fires?) >>> >>> I did this last night, and got frustrated. The unfortunate thing was >>> that once it fires, we end up flooding our trace buffers with errors as >>> the guest continually retries. So I need to either make a smarter trace >>> that is rate limited or just crash my host once this condition occurs. >>> Will try to do that between meetings today. >>> >> >> I reverted the subject patch, and simply triggered >> BUG_ON(cp->initialized) in cp_init(). It sprung VERY quickly (all >> traces are for the same device): >> >> 366.399682 03 ...sch_io_todo state=4 o.cpa=03017810 >> i.w0=00c04007 i.cpa=03017818 i.w2=0c000000 >> 366.399832 03 ...sch_io_todo state=3 o.cpa=7f53dd30 UNSOLICITED >> i.w0=00c00011 i.cpa=03017818 i.w2=85000000 >> 366.400086 03 ...sch_io_todo state=2 o.cpa=03017930 >> i.w0=00c04007 i.cpa=03017938 i.w2=0c000000 >> 366.400313 03 ...sch_io_todo state=3 o.cpa=03017930 >> i.w0=00001001 i.cpa=03017938 i.w2=00000000 >> >> Ah, of course... Unsolicited interrupts DO reset private->state back to >> idle, but leave cp->initialized and any channel_program struct remains >> allocated. So there's one problem (a memory leak), and an easy one to >> rectify. > > For a moment, I suspected a deferred condition code here, but it seems > to be a pure unsolicited interrupt. > > But that got me thinking: If we get an unsolicited interrupt while > building the cp, it means that the guest is currently executing ssch. > We need to get the unsolicited interrupt to the guest, while not > executing the ssch. So maybe we need to do the following: > > - deliver the unsolicited interrupt to the guest > - make sure we don't execute the ssch, but relay a cc 1 for it back to > the guest > - clean up the cp > > Maybe not avoiding issuing the ssch is what gets us in that pickle? We > either leak memory or free too much, it seems. It's possible... I'll try hacking at that for a bit. > >> >> After more than a few silly rabbit holes, I had this trace: >> >> 429.928480 07 ...sch_io_todo state=4 init=1 o.cpa=7fed8e10 >> i.w0=00001001 i.cpa=7fed8e18 i.w2=00000000 >> 429.929132 07 ...sch_io_todo state=4 init=1 o.cpa=0305aed0 >> i.w0=00c04007 i.cpa=0305aed8 i.w2=0c000000 >> 429.929538 07 ...sch_io_todo state=4 init=1 o.cpa=0305af30 >> i.w0=00c04007 i.cpa=0305af38 i.w2=0c000000 >> 467.339389 07 ...chp_event mask=0x80 event=1 >> 467.339865 03 ...sch_io_todo state=3 init=0 o.cpa=01814548 >> i.w0=00c02001 i.cpa=0305af38 i.w2=00000000 >> >> So my trace is at the beginning of vfio_ccw_sch_io_todo(), but the >> BUG_ON() is at the end of that function where private->state is >> (possibly) updated. Looking at the contents of the vfio_ccw_private >> struct in the dump, the failing device is currently state=4 init=1 >> instead of 3/0 as in the above trace. So an I/O was being built in >> parallel here, and there's no serializing action within the stacked >> vfio_ccw_sch_io_todo() call to ensure they don't stomp on one another. >> The io_mutex handles the region changes, and the subchannel lock handles >> the start/halt/clear subchannel instructions, but nothing on the >> interrupt side, nor contention between them. Sigh. > > I feel we've been here a few times already, and never seem to come up > with a complete solution :( > > There had been some changes by Pierre regarding locking the fsm; maybe > that's what's needed here? Hrm... I'd forgotten all about those. I found them on patchwork.kernel.org; will see what they encompass. > >> >> My brain hurts. I re-applied this patch (with some validation that the >> cpa is valid) to my current franken-code, and will let it run overnight. >> I think it's going to be racing other CPUs and I'll find a dead system >> by morning, but who knows. Maybe not. :) >> > > I can relate to the brain hurting part :) > :) My system crashed after about six hours, but not because of the BUG_ON() traps I placed. Rather, dma-kmalloc-8 got clobbered again with what looks like x100 bytes of data from one of the other CCWs. Of course, I didn't trace the CCW/IDA data this time, so I don't know when the memory in question was allocated/released/used. But, there are 35 deferred cc=1 interrupts in the trace though, so I'll give some some thought to the ideas above while re-running with the full traces in place. Thanks!
