Index: /trunk/include/VBox/vusb.h =================================================================== --- /trunk/include/VBox/vusb.h (revision 56453) +++ /trunk/include/VBox/vusb.h (revision 56454) @@ -1088,4 +1088,8 @@ /** The USR state. */ VUSBURBSTATE enmState; + /** Flag whether the URB is about to be completed, + * either by the I/O thread or the cancellation worker. + */ + volatile bool fCompleting; /** URB description, can be null. intended for logging. */ char *pszDesc; Index: /trunk/src/VBox/Devices/USB/DevOHCI.cpp =================================================================== --- /trunk/src/VBox/Devices/USB/DevOHCI.cpp (revision 56453) +++ /trunk/src/VBox/Devices/USB/DevOHCI.cpp (revision 56454) @@ -375,17 +375,17 @@ /** The framer thread. */ - R3PTRTYPE(PPDMTHREAD) hThreadFrame; + R3PTRTYPE(PPDMTHREAD) hThreadFrame; /** Event semaphore to interact with the framer thread. */ - R3PTRTYPE(RTSEMEVENT) hSemEventFrame; + R3PTRTYPE(RTSEMEVENTMULTI) hSemEventFrame; /** Event semaphore to release the thread waiting for the framer thread to stop. */ R3PTRTYPE(RTSEMEVENTMULTI) hSemEventFrameStopped; /** Flag whether the framer thread should processing frames. */ - volatile bool fBusStarted; + volatile bool fBusStarted; /** Alignment. */ - uint32_t Alignment5; + uint32_t Alignment5; /** How long to wait until the next frame. */ - uint64_t nsWait; + uint64_t nsWait; /** Critical section to synchronize the framer and URB completion handler. */ - RTCRITSECT CritSect; + RTCRITSECT CritSect; } OHCI; @@ -2214,5 +2214,8 @@ } if (uNewFrameRate != pThis->uFrameRate) + { + LogFlow(("Frame rate changed from %u to %u\n", pThis->uFrameRate, uNewFrameRate)); ohciCalcTimerIntervals(pThis, uNewFrameRate); + } } @@ -2606,5 +2609,5 @@ /* Calculate new frame rate and wakeup the . */ ohciFramerateCalcNew(pThis); - RTSemEventSignal(pThis->hSemEventFrame); + RTSemEventMultiSignal(pThis->hSemEventFrame); RTCritSectLeave(&pThis->CritSect); } @@ -2980,6 +2983,6 @@ { /* Get validate the previous TD */ - int iInFlightPrev = ohci_in_flight_find(pThis, ITdAddr); - AssertMsgReturn(iInFlightPrev >= 0, ("ITdAddr=%#RX32\n", ITdAddr), false); + int iInFlightPrev = ohci_in_flight_find(pThis, ITdAddrPrev); + AssertMsgReturn(iInFlightPrev >= 0, ("ITdAddr=%#RX32\n", ITdAddrPrev), false); PVUSBURB pUrbPrev = pThis->aInFlight[iInFlightPrev].pUrb; if (ohciHasUrbBeenCanceled(pThis, pUrbPrev, pEd)) /* ensures the copy is correct. */ @@ -3870,29 +3873,42 @@ static DECLCALLBACK(int) ohciR3ThreadFrame(PPDMDEVINS pDevIns, PPDMTHREAD pThread) { - int rc = VINF_SUCCESS; POHCI pThis = (POHCI)pThread->pvUser; - uint64_t tsNanoStart = 0; + uint64_t tsBeginServicing = 0; + uint64_t cFramesProcessed = 0; if (pThread->enmState == PDMTHREADSTATE_INITIALIZING) return VINF_SUCCESS; + tsBeginServicing = RTTimeNanoTS(); + cFramesProcessed = 0; + while (pThread->enmState == PDMTHREADSTATE_RUNNING) { while ( !ASMAtomicReadBool(&pThis->fBusStarted) - && pThread->enmState == PDMTHREADSTATE_RUNNING - && RT_SUCCESS(rc)) + && pThread->enmState == PDMTHREADSTATE_RUNNING) { /* Signal the waiter that we are stopped now. */ - rc = RTSemEventMultiSignal(pThis->hSemEventFrameStopped); + int rc = RTSemEventMultiSignal(pThis->hSemEventFrameStopped); AssertRC(rc); - rc = RTSemEventWait(pThis->hSemEventFrame, RT_INDEFINITE_WAIT); + rc = RTSemEventMultiReset(pThis->hSemEventFrame); + AssertRC(rc); + + /* + * We have to check that the Bus was not started and the thread state + * did not change or otherwise we risk hanging here indefinitely + * if the signaller set the event semaphore before we reset it. + */ + if (ASMAtomicReadBool(&pThis->fBusStarted) || pThread->enmState != PDMTHREADSTATE_RUNNING) + break; + + rc = RTSemEventMultiWait(pThis->hSemEventFrame, RT_INDEFINITE_WAIT); + AssertLogRelMsgReturn(RT_SUCCESS(rc) || rc == VERR_TIMEOUT, ("%Rrc\n", rc), rc); + tsBeginServicing = RTTimeNanoTS(); + cFramesProcessed = 0; } - AssertLogRelMsgReturn(RT_SUCCESS(rc) || rc == VERR_TIMEOUT, ("%Rrc\n", rc), rc); if (RT_UNLIKELY(pThread->enmState != PDMTHREADSTATE_RUNNING)) break; - tsNanoStart = RTTimeNanoTS(); - RTCritSectEnter(&pThis->CritSect); @@ -3900,20 +3916,60 @@ pThis->fIdle = true; - /* Frame boundary, so do EOF stuff here. */ - bump_frame_number(pThis); - if ( (pThis->dqic != 0x7) && (pThis->dqic != 0)) - pThis->dqic--; - - /* Clean up any URBs that have been removed. */ - ohciCancelOrphanedURBs(pThis); - - /* Start the next frame. */ - ohciStartOfFrame(pThis); + /* + * Process new frames until we reached the required amount of + * frames for this service period. We might need to catch up + * here and process multiple frames at once due to scheduling + * preempting us. This is required because isochronous transfers + * have a tight timing requirement. + */ + uint64_t tsNow = RTTimeNanoTS(); + uint64_t nsWait = 0; + while (tsBeginServicing + (cFramesProcessed * RT_NS_1MS) < tsNow) + { + uint64_t tsNanoStart = RTTimeNanoTS(); + LogFlowFunc(("Starting new frame at ts %llu\n", tsNanoStart)); + + /* Frame boundary, so do EOF stuff here. */ + bump_frame_number(pThis); + if ( (pThis->dqic != 0x7) && (pThis->dqic != 0)) + pThis->dqic--; + + /* Clean up any URBs that have been removed. */ + ohciCancelOrphanedURBs(pThis); + + /* Start the next frame. */ + ohciStartOfFrame(pThis); + cFramesProcessed++; + + tsNow = RTTimeNanoTS(); + uint64_t tsFrameNext = tsNanoStart + pThis->nsWait; + + if (tsFrameNext > tsNow) + { + nsWait = tsFrameNext - tsNow; + LogFlowFunc(("Current frame took %llu nano seconds to finish, we can wait %llu ns for the next frame\n", tsNow - tsNanoStart, nsWait)); + break; + } + else if (tsBeginServicing + (cFramesProcessed + 100) * RT_NS_1MS < tsNow) + { + /* If we lag to far behind stop trying to catch up. */ + LogRel(("OHCI#%u: Lagging too far behind, not trying to catch up anymore. Expect glitches with USB devices\n", + pThis->pDevInsR3->iInstance)); + tsBeginServicing = tsNow; + cFramesProcessed = 0; + } + } RTCritSectLeave(&pThis->CritSect); /* Wait for the next round. */ - RTMSINTERVAL msWait = (RTMSINTERVAL)(((RTTimeNanoTS() + pThis->nsWait) - tsNanoStart) / 1000000); - rc = RTSemEventWait(pThis->hSemEventFrame, msWait); + if (nsWait >= 500 * RT_NS_1US) + { + LogFlowFunc(("Going to sleep for at least %llu ns\n", nsWait)); + int rc = RTSemEventMultiWaitEx(pThis->hSemEventFrame, RTSEMWAIT_FLAGS_RELATIVE | RTSEMWAIT_FLAGS_NANOSECS | RTSEMWAIT_FLAGS_UNINTERRUPTIBLE, + nsWait); + AssertLogRelMsg(RT_SUCCESS(rc) || rc == VERR_TIMEOUT, ("%Rrc\n", rc)); + RTSemEventMultiReset(pThis->hSemEventFrame); + } } @@ -3931,5 +3987,5 @@ { POHCI pThis = PDMINS_2_DATA(pDevIns, POHCI); - return RTSemEventSignal(pThis->hSemEventFrame); + return RTSemEventMultiSignal(pThis->hSemEventFrame); } @@ -3937,9 +3993,6 @@ * Do frame processing on frame boundary */ -static void ohciFrameBoundaryTimer(PPDMDEVINS pDevIns, PTMTIMER pTimer, void *pvUser) -{ - POHCI pThis = (POHCI)pvUser; - STAM_PROFILE_START(&pThis->StatTimer, a); - STAM_PROFILE_STOP(&pThis->StatTimer, a); +static DECLCALLBACK(void) ohciFrameBoundaryTimer(PPDMDEVINS pDevIns, PTMTIMER pTimer, void *pvUser) +{ } @@ -3958,5 +4011,5 @@ bool fBusActive = ASMAtomicXchgBool(&pThis->fBusStarted, true); if (!fBusActive) - RTSemEventSignal(pThis->hSemEventFrame); + RTSemEventMultiSignal(pThis->hSemEventFrame); } @@ -3973,5 +4026,5 @@ /* Signal the frame thread to stop. */ - RTSemEventSignal(pThis->hSemEventFrame); + RTSemEventMultiSignal(pThis->hSemEventFrame); /* Wait for signal from the thrad that it stopped. */ @@ -5609,5 +5662,5 @@ LogFlowFunc(("Bus was active, restart frame thread\n")); ASMAtomicXchgBool(&pThis->fBusStarted, true); - RTSemEventSignal(pThis->hSemEventFrame); + RTSemEventMultiSignal(pThis->hSemEventFrame); } } @@ -5703,5 +5756,5 @@ */ if (pThis->hSemEventFrame) - RTSemEventDestroy(pThis->hSemEventFrame); + RTSemEventMultiDestroy(pThis->hSemEventFrame); if (pThis->hSemEventFrameStopped) RTSemEventMultiDestroy(pThis->hSemEventFrameStopped); @@ -5874,5 +5927,5 @@ N_("EHCI: Failed to create critical section")); - rc = RTSemEventCreate(&pThis->hSemEventFrame); + rc = RTSemEventMultiCreate(&pThis->hSemEventFrame); AssertRCReturn(rc, rc); @@ -5886,5 +5939,5 @@ rc = PDMDevHlpThreadCreate(pDevIns, &pThis->hThreadFrame, pThis, ohciR3ThreadFrame, - ohciR3ThreadFrameWakeup, 0, RTTHREADTYPE_IO, "OhciFramer"); + ohciR3ThreadFrameWakeup, 0, RTTHREADTYPE_TIMER, "OhciFramer"); if (RT_FAILURE(rc)) return PDMDevHlpVMSetError(pDevIns, rc, RT_SRC_POS, @@ -5903,5 +5956,4 @@ PDMDevHlpSTAMRegister(pDevIns, &pThis->StatCanceledGenUrbs, STAMTYPE_COUNTER, "/Devices/OHCI/CanceledGenUrbs", STAMUNIT_OCCURENCES, "Detected canceled general URBs."); PDMDevHlpSTAMRegister(pDevIns, &pThis->StatDroppedUrbs, STAMTYPE_COUNTER, "/Devices/OHCI/DroppedUrbs", STAMUNIT_OCCURENCES, "Dropped URBs (endpoint halted, or URB canceled)."); - PDMDevHlpSTAMRegister(pDevIns, &pThis->StatTimer, STAMTYPE_PROFILE, "/Devices/OHCI/Timer", STAMUNIT_TICKS_PER_CALL, "Profiling ohciFrameBoundaryTimer."); #endif Index: /trunk/src/VBox/Devices/USB/DrvVUSBRootHub.cpp =================================================================== --- /trunk/src/VBox/Devices/USB/DrvVUSBRootHub.cpp (revision 56453) +++ /trunk/src/VBox/Devices/USB/DrvVUSBRootHub.cpp (revision 56454) @@ -429,4 +429,5 @@ */ pUrb->enmState = VUSBURBSTATE_ALLOCATED; + pUrb->fCompleting = false; pUrb->pszDesc = NULL; pUrb->VUsb.pNext = NULL; @@ -598,5 +599,5 @@ * Cancel and reap the URB(s) on an endpoint. */ - LogFlow(("vusbRhCancelUrbsEp: pRh=%p pUrb=%p\n", pRh)); + LogFlow(("vusbRhCancelUrbsEp: pRh=%p pUrb=%p\n", pRh, pUrb)); vusbUrbCancelAsync(pUrb, CANCELMODE_UNDO); Index: /trunk/src/VBox/Devices/USB/VUSBDevice.cpp =================================================================== --- /trunk/src/VBox/Devices/USB/VUSBDevice.cpp (revision 56453) +++ /trunk/src/VBox/Devices/USB/VUSBDevice.cpp (revision 56454) @@ -1047,5 +1047,4 @@ * Iterate the URBs and cancel them. */ - RTCritSectEnter(&pDev->CritSectAsyncUrbs); PVUSBURB pUrb = pDev->pAsyncUrbHead; while (pUrb) @@ -1064,4 +1063,5 @@ * Reap any URBs which became ripe during cancel now. */ + RTCritSectEnter(&pDev->CritSectAsyncUrbs); unsigned cReaped; do Index: /trunk/src/VBox/Devices/USB/VUSBUrb.cpp =================================================================== --- /trunk/src/VBox/Devices/USB/VUSBUrb.cpp (revision 56453) +++ /trunk/src/VBox/Devices/USB/VUSBUrb.cpp (revision 56454) @@ -977,5 +977,8 @@ || pUrb->enmState == VUSBURBSTATE_CANCELLED); if (pUrb->enmState != VUSBURBSTATE_CANCELLED) + { pUrb->enmState = VUSBURBSTATE_ALLOCATED; + pUrb->fCompleting = false; + } RTCritSectLeave(&pPipe->CritSectCtrl); @@ -1012,5 +1015,6 @@ || pUrb->enmState == VUSBURBSTATE_CANCELLED, ("%d\n", pUrb->enmState)); - if (pUrb->VUsb.pDev->hSniffer) + if ( pUrb->VUsb.pDev + && pUrb->VUsb.pDev->hSniffer) { int rc = VUSBSnifferRecordEvent(pUrb->VUsb.pDev->hSniffer, pUrb, @@ -1288,4 +1292,5 @@ */ pExtra->Urb.enmState = VUSBURBSTATE_ALLOCATED; + pExtra->Urb.fCompleting = false; } @@ -1299,5 +1304,8 @@ pExtra->enmStage = CTLSTAGE_SETUP; if (pExtra->Urb.enmState != VUSBURBSTATE_CANCELLED) + { pExtra->Urb.enmState = VUSBURBSTATE_ALLOCATED; + pExtra->Urb.fCompleting = false; + } } @@ -1345,4 +1353,5 @@ Assert(pUrb->VUsb.pvFreeCtx == &pExtra->Urb); pUrb->enmState = VUSBURBSTATE_ALLOCATED; + pUrb->fCompleting = false; } } @@ -1394,4 +1403,5 @@ pExtra->Urb.u32Magic = VUSBURB_MAGIC; pExtra->Urb.enmState = VUSBURBSTATE_ALLOCATED; + pExtra->Urb.fCompleting = false; #ifdef LOG_ENABLED RTStrAPrintf(&pExtra->Urb.pszDesc, "URB %p msg->%p", &pExtra->Urb, pUrb); @@ -1460,4 +1470,5 @@ pExtra->pMsg = (PVUSBSETUP)pExtra->Urb.abData; pExtra->Urb.enmState = VUSBURBSTATE_ALLOCATED; + pExtra->Urb.fCompleting = false; } @@ -2180,6 +2191,10 @@ void vusbUrbCancelAsync(PVUSBURB pUrb, CANCELMODE mode) { - int rc = vusbDevIoThreadExec(pUrb->VUsb.pDev, 0 /* fFlags */, (PFNRT)vusbUrbCancelWorker, 2, pUrb, mode); - AssertRC(rc); + /* Don't try to cancel the URB when completion is in progress at the moment. */ + if (!ASMAtomicXchgBool(&pUrb->fCompleting, true)) + { + int rc = vusbDevIoThreadExec(pUrb->VUsb.pDev, 0 /* fFlags */, (PFNRT)vusbUrbCancelWorker, 2, pUrb, mode); + AssertRC(rc); + } } @@ -2200,5 +2215,6 @@ { pUrb->enmState = VUSBURBSTATE_REAPED; - vusbUrbCompletion(pUrb); + if (!ASMAtomicXchgBool(&pUrb->fCompleting, true)) + vusbUrbCompletion(pUrb); } else if (pUrb->enmState == VUSBURBSTATE_CANCELLED)