Changeset 2839 in vbox

Timestamp:

May 24, 2007 1:24:07 PM (18 years ago)

Author:

vboxsync

svn:sync-xref-src-repo-rev:

21469

Message:

More release logging in relation to aborting of ATA commands.

File:

• trunk/src/VBox/Devices/Storage/DevATA.cpp (modified) (11 diffs)

trunk/src/VBox/Devices/Storage/DevATA.cpp

@@ -198 +198 @@
 
     /** Enable passing through commands directly to the ATAPI drive. */
-    bool fATAPIPassthrough;
+    bool            fATAPIPassthrough;
     /** Number of errors we've reported to the release log.
      * This is to prevent flooding caused by something going horribly wrong.
      * this value against MAX_LOG_REL_ERRORS in places likely to cause floods
      * like the ones we currently seeing on the linux smoke tests (2006-11-10). */
-    uint32_t cErrors;
+    uint32_t        cErrors;
+    /** Timestamp of last started command. 0 if no command pending. */
+    uint64_t        u64CmdTS;
 
     /** Pointer to the attached driver's base interface. */
@@ -3226 +3228 @@
             break;
         case ATA_IDLE_IMMEDIATE:
+            LogRel(("PIIX3 ATA: LUN#%d: aborting current command\n", s->iLUN));
             ataAbortCurrentCommand(s, false);
             break;
@@ -3244 +3247 @@
             if (!s->fATAPI)
                 goto abort_cmd;
+            LogRel(("PIIX3 ATA: LUN#%d: performing device RESET\n", s->iLUN));
             ataAbortCurrentCommand(s, true);
             break;
@@ -3538 +3542 @@
 #ifdef IN_RING3
         /* Software RESET low to high */
-        LogRel(("PIIX3 ATA: Ctl#%d: RESET, DevSel=%d AIOIf=%d CmdIf0=%#04x CmdIf1=%#04x\n",
+        uint32_t uCmdWait0 = -1, uCmdWait1 = -1;
+        uint64_t uNow = RTTimeNanoTS();
+        if (pCtl->aIfs[0].u64CmdTS)
+            uCmdWait0 = (pCtl->aIfs[0].u64CmdTS - uNow) / 1000;
+        if (pCtl->aIfs[1].u64CmdTS)
+            uCmdWait1 = (pCtl->aIfs[1].u64CmdTS - uNow) / 1000;
+        LogRel(("PIIX3 ATA: Ctl#%d: RESET, DevSel=%d AIOIf=%d CmdIf0=%#04x (%d usec ago) CmdIf1=%#04x (%d usec ago)\n",
                     ATACONTROLLER_IDX(pCtl), pCtl->iSelectedIf, pCtl->iAIOIf,
-                    pCtl->aIfs[0].uATARegCommand, pCtl->aIfs[1].uATARegCommand));
+                    pCtl->aIfs[0].uATARegCommand, uCmdWait0,
+                    pCtl->aIfs[1].uATARegCommand, uCmdWait1));
         pCtl->fReset = true;
         /* Everything must be done after the reset flag is set, otherwise
@@ -4074 +4085 @@
                 s->iSourceSink = pReq->u.t.iSourceSink;
                 s->iIOBufferEnd = 0;
+                s->u64CmdTS = u64TS;
 
                 pCtl->fChainedTransfer = false;
@@ -4294 +4306 @@
                 pCtl->uAsyncIOState = ATA_AIO_NEW;
                 pCtl->fReset = false;
+                LogRel(("PIIX3 ATA: Ctl#%d: finished processing RESET\n",
+                        ATACONTROLLER_IDX(pCtl)));
                 for (uint32_t i = 0; i < RT_ELEMENTS(pCtl->aIfs); i++)
                 {
@@ -4345 +4359 @@
             uWait = u64TS / 1000;
             Log(("%s: Ctl#%d: LUN#%d finished I/O transaction in %d microseconds\n", __FUNCTION__, ATACONTROLLER_IDX(pCtl), pCtl->aIfs[pCtl->iAIOIf].iLUN, (uint32_t)(uWait)));
+            /* Mark command as finished. */
+            pCtl->aIfs[pCtl->iAIOIf].u64CmdTS = 0;
 
             /*
@@ -4353 +4369 @@
             if (pCtl->aIfs[pCtl->iAIOIf].uATARegCommand != ATA_PACKET)
             {
-                if (uWait > 10 * 1000 * 1000)
+                if (uWait > 8 * 1000 * 1000)
                 {
                     /*
-                     * Command took longer than 10 seconds. This is close
+                     * Command took longer than 8 seconds. This is close
                      * enough or over the guest's command timeout, so place
                      * an entry in the release log to allow tracking such
@@ -4994 +5010 @@
     bool            fVMLocked;
     uint64_t        u64Start;
+    PATACONTROLLER  pCtl;
     bool            fAllIdle = false;
 
@@ -5016 +5033 @@
         for (uint32_t i = 0; i < RT_ELEMENTS(pData->aCts); i++)
         {
-            fAllIdle &= ataAsyncIOIsIdle(&pData->aCts[i], false);
+            pCtl = &pData->aCts[i];
+            fAllIdle &= ataAsyncIOIsIdle(pCtl, false);
             if (!fAllIdle)
                 break;
@@ -5030 +5048 @@
     if (fVMLocked)
         pDevIns->pDevHlp->pfnLockVM(pDevIns);
+
+    if (!fAllIdle)
+        LogRel(("PIIX3 ATA: Ctl#%d is still executing, DevSel=%d AIOIf=%d CmdIf0=%#04x CmdIf1=%#04x\n",
+                ATACONTROLLER_IDX(pCtl), pCtl->iSelectedIf, pCtl->iAIOIf,
+                pCtl->aIfs[0].uATARegCommand, pCtl->aIfs[1].uATARegCommand));
 
     return fAllIdle;