Changeset 90972 in vbox for trunk/src/VBox/VMM

Timestamp:

Aug 27, 2021 11:00:48 PM (3 years ago)

Author:

vboxsync

Message:

VMM: Correctly update idxBuf so we flush the right buffer when we get to ring-3. Tweaked the EMT/flusher race mitigation hack in vmmR3LogReturnFlush and added a couple of counters for it. bugref:10086

Location:

trunk/src/VBox/VMM

Files:

• VMMR0/VMMR0.cpp (modified) (1 diff)
• VMMR3/VMM.cpp (modified) (3 diffs)
• include/VMMInternal.h (modified) (1 diff)

trunk/src/VBox/VMM/VMMR0/VMMR0.cpp

@@ -3223 +3223 @@
              * We always switch buffer if we have more than one.
              */
+#if VMMLOGGER_BUFFER_COUNT == 1
+            fFlushedBuffer = true;
+#else
             AssertCompile(VMMLOGGER_BUFFER_COUNT >= 1);
-            fFlushedBuffer = VMMLOGGER_BUFFER_COUNT == 1;
+            pShared->idxBuf = (idxBuffer + 1) % VMMLOGGER_BUFFER_COUNT;
+            fFlushedBuffer = false;
+#endif
         }
         else

trunk/src/VBox/VMM/VMMR3/VMM.cpp

@@ -476 +476 @@
         STAMR3RegisterF(pVM, &pShared->StatFlushes,     STAMTYPE_COUNTER, STAMVISIBILITY_USED, STAMUNIT_OCCURENCES,     "", "/VMM/LogFlush/CPU%u/Reg", i);
         STAMR3RegisterF(pVM, &pShared->StatCannotBlock, STAMTYPE_COUNTER, STAMVISIBILITY_USED, STAMUNIT_OCCURENCES,     "", "/VMM/LogFlush/CPU%u/Reg/CannotBlock", i);
+        STAMR3RegisterF(pVM, &pShared->StatRaces,       STAMTYPE_COUNTER, STAMVISIBILITY_USED, STAMUNIT_OCCURENCES,     "", "/VMM/LogFlush/CPU%u/Reg/Races", i);
+        STAMR3RegisterF(pVM, &pShared->StatRacesReal,   STAMTYPE_COUNTER, STAMVISIBILITY_USED, STAMUNIT_OCCURENCES,     "", "/VMM/LogFlush/CPU%u/Reg/RacesReal", i);
         STAMR3RegisterF(pVM, &pShared->StatWait,        STAMTYPE_PROFILE, STAMVISIBILITY_USED, STAMUNIT_TICKS_PER_CALL, "", "/VMM/LogFlush/CPU%u/Reg/Wait", i);
         STAMR3RegisterF(pVM, &pShared->cbDropped,       STAMTYPE_U32,     STAMVISIBILITY_USED, STAMUNIT_BYTES,          "", "/VMM/LogFlush/CPU%u/Reg/cbDropped", i);
@@ -484 +486 @@
         STAMR3RegisterF(pVM, &pShared->StatFlushes,     STAMTYPE_COUNTER, STAMVISIBILITY_USED, STAMUNIT_OCCURENCES,     "", "/VMM/LogFlush/CPU%u/Rel", i);
         STAMR3RegisterF(pVM, &pShared->StatCannotBlock, STAMTYPE_COUNTER, STAMVISIBILITY_USED, STAMUNIT_OCCURENCES,     "", "/VMM/LogFlush/CPU%u/Rel/CannotBlock", i);
+        STAMR3RegisterF(pVM, &pShared->StatRaces,       STAMTYPE_COUNTER, STAMVISIBILITY_USED, STAMUNIT_OCCURENCES,     "", "/VMM/LogFlush/CPU%u/Rel/Races", i);
+        STAMR3RegisterF(pVM, &pShared->StatRacesReal,   STAMTYPE_COUNTER, STAMVISIBILITY_USED, STAMUNIT_OCCURENCES,     "", "/VMM/LogFlush/CPU%u/Rel/RacesReal", i);
         STAMR3RegisterF(pVM, &pShared->StatWait,        STAMTYPE_PROFILE, STAMVISIBILITY_USED, STAMUNIT_TICKS_PER_CALL, "", "/VMM/LogFlush/CPU%u/Rel/Wait", i);
         STAMR3RegisterF(pVM, &pShared->cbDropped,       STAMTYPE_U32,     STAMVISIBILITY_USED, STAMUNIT_BYTES,          "", "/VMM/LogFlush/CPU%u/Rel/cbDropped", i);
@@ -942 +946 @@
 {
 #if VMMLOGGER_BUFFER_COUNT > 1
-    /* Yield if other log buffers are being flushed already, so we try
-       avoid totally mixing things up... */
+    /*
+     * To avoid totally mixing up the output, make some effort at delaying if
+     * there are buffers still being worked on by the flusher thread.
+     */
     if (pShared->cFlushing > 0)
-        RTThreadYield();
+    {
+        STAM_REL_COUNTER_INC(&pShared->StatRaces);
+        for (uint32_t iTry = 0; iTry < 32 && pShared->cFlushing != 0; iTry++)
+        {
+            RTLogBulkWrite(pDstLogger, "", 0); /* A no-op, but it takes the lock and the hope is */
+            if (pShared->cFlushing != 0)       /* that we end up waiting on the flusher finish up. */
+                RTThreadYield();
+        }
+        if (pShared->cFlushing != 0)
+        {
+            RTLogLoggerEx(pDstLogger, RTLOGGRPFLAGS_LEVEL_1, UINT32_MAX, "*MAYBE WRONG ORDER*\n");
+            if (pShared->cFlushing != 0)
+                STAM_REL_COUNTER_INC(&pShared->StatRacesReal);
+        }
+    }
 #endif
     RTLogBulkWrite(pDstLogger, pShared->aBufs[idxBuf].pchBufR3, pShared->aBufs[idxBuf].AuxDesc.offBuf);

trunk/src/VBox/VMM/include/VMMInternal.h

@@ -123 +123 @@
     STAMCOUNTER             StatFlushes;
     STAMCOUNTER             StatCannotBlock;
+    STAMCOUNTER             StatRaces;
+    STAMCOUNTER             StatRacesReal;
     STAMPROFILE             StatWait;
 } VMMR3CPULOGGER;