VirtualBox

Changeset 72387 in vbox


Ignore:
Timestamp:
May 29, 2018 3:39:47 PM (7 years ago)
Author:
vboxsync
Message:

NEM/win: Better state logging on exit. bugref:9044

File:
1 edited

Legend:

Unmodified
Added
Removed

  • trunk/src/VBox/VMM/VMMAll/NEMAllNativeTemplate-win.cpp.h

    r72358 r72387  
    890890#endif /* NEM_WIN_USE_OUR_OWN_RUN_API */
    891891
    892 
    893892#ifdef LOG_ENABLED
     893
    894894/**
    895895 * Logs the current CPU state.
    … …  
    939939    }
    940940}
     941
     942
     943/**
     944 * Translates the execution stat bitfield into a short log string.
     945 *
     946 * @returns Read-only log string.
     947 * @param   pMsgHdr       The header which state to summarize.
     948 */
     949static const char *nemHCWinExecStateToLogStr(HV_X64_INTERCEPT_MESSAGE_HEADER const *pMsgHdr)
     950{
     951    unsigned u = (unsigned)pMsgHdr->ExecutionState.InterruptionPending
     952               | ((unsigned)pMsgHdr->ExecutionState.DebugActive << 1)
     953               | ((unsigned)pMsgHdr->ExecutionState.InterruptShadow << 2);
     954# define SWITCH_IT(a_szPrefix) \
     955        do \
     956            switch (u)\
     957            { \
     958                case 0x00: return a_szPrefix ""; \
     959                case 0x01: return a_szPrefix ",Pnd"; \
     960                case 0x02: return a_szPrefix ",Dbg"; \
     961                case 0x03: return a_szPrefix ",Pnd,Dbg"; \
     962                case 0x04: return a_szPrefix ",Shw"; \
     963                case 0x05: return a_szPrefix ",Pnd,Shw"; \
     964                case 0x06: return a_szPrefix ",Shw,Dbg"; \
     965                case 0x07: return a_szPrefix ",Pnd,Shw,Dbg"; \
     966                default: AssertFailedReturn("WTF?"); \
     967            } \
     968        while (0)
     969
     970    if (pMsgHdr->ExecutionState.EferLma)
     971        SWITCH_IT("LM");
     972    else if (pMsgHdr->ExecutionState.Cr0Pe)
     973        SWITCH_IT("PM");
     974    else
     975        SWITCH_IT("RM");
     976# undef SWITCH_IT
     977}
     978
    941979#endif /* LOG_ENABLED */
    942 
    943980
    944981/**
    … …  
    13491386            if (State.fCanResume)
    13501387            {
    1351                 Log4(("MemExit/%u: %04x:%08RX64: %RGp (=>%RHp) %s fProt=%u%s%s%s; restarting (%s)\n",
    1352                       pVCpu->idCpu, pMsg->Header.CsSegment.Selector, pMsg->Header.Rip,
     1388                Log4(("MemExit/%u: %04x:%08RX64/%s: %RGp (=>%RHp) %s fProt=%u%s%s%s; restarting (%s)\n",
     1389                      pVCpu->idCpu, pMsg->Header.CsSegment.Selector, pMsg->Header.Rip, nemHCWinExecStateToLogStr(&pMsg->Header),
    13531390                      pMsg->GuestPhysicalAddress, Info.HCPhys, g_apszPageStates[Info.u2NemState], Info.fNemProt,
    13541391                      Info.fHasHandlers ? " handlers" : "", Info.fZeroPage    ? " zero-pg" : "",
    … …  
    13571394            }
    13581395        }
    1359         Log4(("MemExit/%u: %04x:%08RX64: %RGp (=>%RHp) %s fProt=%u%s%s%s; emulating (%s)\n",
    1360               pVCpu->idCpu, pMsg->Header.CsSegment.Selector, pMsg->Header.Rip,
     1396        Log4(("MemExit/%u: %04x:%08RX64/%s: %RGp (=>%RHp) %s fProt=%u%s%s%s; emulating (%s)\n",
     1397              pVCpu->idCpu, pMsg->Header.CsSegment.Selector, pMsg->Header.Rip, nemHCWinExecStateToLogStr(&pMsg->Header),
    13611398              pMsg->GuestPhysicalAddress, Info.HCPhys, g_apszPageStates[Info.u2NemState], Info.fNemProt,
    13621399              Info.fHasHandlers ? " handlers" : "", Info.fZeroPage    ? " zero-pg" : "",
    … …  
    13641401    }
    13651402    else
    1366         Log4(("MemExit/%u: %04x:%08RX64: %RGp rc=%Rrc%s; emulating (%s)\n",
    1367               pVCpu->idCpu, pMsg->Header.CsSegment.Selector, pMsg->Header.Rip, pMsg->GuestPhysicalAddress, rc,
    1368               State.fDidSomething ? " modified-backing" : "", g_apszHvInterceptAccessTypes[pMsg->Header.InterceptAccessType]));
     1403        Log4(("MemExit/%u: %04x:%08RX64/%s: %RGp rc=%Rrc%s; emulating (%s)\n",
     1404              pVCpu->idCpu, pMsg->Header.CsSegment.Selector, pMsg->Header.Rip, nemHCWinExecStateToLogStr(&pMsg->Header),
     1405              pMsg->GuestPhysicalAddress, rc, State.fDidSomething ? " modified-backing" : "",
     1406              g_apszHvInterceptAccessTypes[pMsg->Header.InterceptAccessType]));
    13691407
    13701408    /*
    … …  
    14391477        {
    14401478            rcStrict = IOMIOPortWrite(pVM, pVCpu, pMsg->PortNumber, (uint32_t)pMsg->Rax & fAndMask, pMsg->AccessInfo.AccessSize);
    1441             Log4(("IOExit/%u: %04x:%08RX64: OUT %#x, %#x LB %u rcStrict=%Rrc\n",
    1442                   pVCpu->idCpu, pMsg->Header.CsSegment.Selector, pMsg->Header.Rip, pMsg->PortNumber,
    1443                   (uint32_t)pMsg->Rax & fAndMask, pMsg->AccessInfo.AccessSize, VBOXSTRICTRC_VAL(rcStrict) ));
     1479            Log4(("IOExit/%u: %04x:%08RX64/%s: OUT %#x, %#x LB %u rcStrict=%Rrc\n",
     1480                  pVCpu->idCpu, pMsg->Header.CsSegment.Selector, pMsg->Header.Rip, nemHCWinExecStateToLogStr(&pMsg->Header),
     1481                  pMsg->PortNumber, (uint32_t)pMsg->Rax & fAndMask, pMsg->AccessInfo.AccessSize, VBOXSTRICTRC_VAL(rcStrict) ));
    14441482            if (IOM_SUCCESS(rcStrict))
    14451483            {
    … …  
    14521490            uint32_t uValue = 0;
    14531491            rcStrict = IOMIOPortRead(pVM, pVCpu, pMsg->PortNumber, &uValue, pMsg->AccessInfo.AccessSize);
    1454             Log4(("IOExit/%u: %04x:%08RX64: IN %#x LB %u -> %#x, rcStrict=%Rrc\n", pVCpu->idCpu, pMsg->Header.CsSegment.Selector,
    1455                   pMsg->Header.Rip, pMsg->PortNumber, pMsg->AccessInfo.AccessSize, uValue, VBOXSTRICTRC_VAL(rcStrict) ));
     1492            Log4(("IOExit/%u: %04x:%08RX64/%s: IN %#x LB %u -> %#x, rcStrict=%Rrc\n",
     1493                  pVCpu->idCpu, pMsg->Header.CsSegment.Selector, pMsg->Header.Rip, nemHCWinExecStateToLogStr(&pMsg->Header),
     1494                  pMsg->PortNumber, pMsg->AccessInfo.AccessSize, uValue, VBOXSTRICTRC_VAL(rcStrict) ));
    14561495            if (IOM_SUCCESS(rcStrict))
    14571496            {
    … …  
    15021541# endif
    15031542
    1504         Log4(("IOExit/%u: %04x:%08RX64: %s%s %#x LB %u (emulating)\n",
    1505               pVCpu->idCpu, pMsg->Header.CsSegment.Selector, pMsg->Header.Rip,
     1543        Log4(("IOExit/%u: %04x:%08RX64/%s: %s%s %#x LB %u (emulating)\n",
     1544              pVCpu->idCpu, pMsg->Header.CsSegment.Selector, pMsg->Header.Rip, nemHCWinExecStateToLogStr(&pMsg->Header),
    15061545              pMsg->AccessInfo.RepPrefix ? "REP " : "",
    15071546              pMsg->Header.InterceptAccessType == HV_INTERCEPT_ACCESS_WRITE ? "OUTS" : "INS",
    … …  
    15521591     */
    15531592    nemHCWinCopyStateFromX64Header(pVCpu, pCtx, &pMsg->Header);
    1554     Log4(("IntWinExit/%u: %04x:%08RX64: %u IF=%d InterruptShadow=%d\n", pVCpu->idCpu, pMsg->Header.CsSegment.Selector,
    1555           pMsg->Header.Rip, pMsg->Type, RT_BOOL(pMsg->Header.Rflags & X86_EFL_IF), pMsg->Header.ExecutionState.InterruptShadow));
     1593    Log4(("IntWinExit/%u: %04x:%08RX64/%s: %u IF=%d InterruptShadow=%d\n",
     1594          pVCpu->idCpu, pMsg->Header.CsSegment.Selector, pMsg->Header.Rip,  nemHCWinExecStateToLogStr(&pMsg->Header),
     1595          pMsg->Type, RT_BOOL(pMsg->Header.Rflags & X86_EFL_IF), pMsg->Header.ExecutionState.InterruptShadow));
    15561596
    15571597    /** @todo call nemHCWinHandleInterruptFF   */
    … …  
    15931633    CPUMGetGuestCpuId(pVCpu, pCtx->eax, pCtx->ecx, &pCtx->eax, &pCtx->ebx, &pCtx->ecx, &pCtx->edx);
    15941634
    1595     Log4(("CpuIdExit/%u: %04x:%08RX64: rax=%08RX64 / rcx=%08RX64 / rdx=%08RX64 / rbx=%08RX64 -> %08RX32 / %08RX32 / %08RX32 / %08RX32 (hv: %08RX64 / %08RX64 / %08RX64 / %08RX64)\n",
    1596           pVCpu->idCpu, pMsg->Header.CsSegment.Selector, pMsg->Header.Rip,
     1635    Log4(("CpuIdExit/%u: %04x:%08RX64/%s: rax=%08RX64 / rcx=%08RX64 / rdx=%08RX64 / rbx=%08RX64 -> %08RX32 / %08RX32 / %08RX32 / %08RX32 (hv: %08RX64 / %08RX64 / %08RX64 / %08RX64)\n",
     1636          pVCpu->idCpu, pMsg->Header.CsSegment.Selector, pMsg->Header.Rip, nemHCWinExecStateToLogStr(&pMsg->Header),
    15971637          pMsg->Rax,                           pMsg->Rcx,              pMsg->Rdx,              pMsg->Rbx,
    15981638          pCtx->eax,                           pCtx->ecx,              pCtx->edx,              pCtx->ebx,
    … …  
    16371677        {
    16381678            rcStrict = CPUMSetGuestMsr(pVCpu, pMsg->MsrNummber, RT_MAKE_U64((uint32_t)pMsg->Rax, (uint32_t)pMsg->Rdx));
    1639             Log4(("MsrExit/%u: %04x:%08RX64: WRMSR %08x, %08x:%08x -> %Rrc\n",
    1640                   pVCpu->idCpu, pMsg->Header.CsSegment.Selector, pMsg->Header.Rip,
     1679            Log4(("MsrExit/%u: %04x:%08RX64/%s: WRMSR %08x, %08x:%08x -> %Rrc\n",
     1680                  pVCpu->idCpu, pMsg->Header.CsSegment.Selector, pMsg->Header.Rip, nemHCWinExecStateToLogStr(&pMsg->Header),
    16411681                  pMsg->MsrNummber, (uint32_t)pMsg->Rax, (uint32_t)pMsg->Rdx, VBOXSTRICTRC_VAL(rcStrict) ));
    16421682            if (rcStrict == VINF_SUCCESS)
    … …  
    16521692            return rcStrict;
    16531693#else
    1654             LogRel(("MsrExit/%u: %04x:%08RX64: WRMSR %08x, %08x:%08x -> %Rrc!\n",
    1655                     pVCpu->idCpu, pMsg->Header.CsSegment.Selector, pMsg->Header.Rip,
     1694            LogRel(("MsrExit/%u: %04x:%08RX64/%s: WRMSR %08x, %08x:%08x -> %Rrc!\n",
     1695                    pVCpu->idCpu, pMsg->Header.CsSegment.Selector, pMsg->Header.Rip, nemHCWinExecStateToLogStr(&pMsg->Header),
    16561696                    pMsg->MsrNummber, (uint32_t)pMsg->Rax, (uint32_t)pMsg->Rdx, VBOXSTRICTRC_VAL(rcStrict) ));
    16571697#endif
    … …  
    16641704            uint64_t uValue = 0;
    16651705            rcStrict = CPUMQueryGuestMsr(pVCpu, pMsg->MsrNummber, &uValue);
    1666             Log4(("MsrExit/%u: %04x:%08RX64: RDMSR %08x -> %08RX64 / %Rrc\n", pVCpu->idCpu, pMsg->Header.CsSegment.Selector,
    1667                   pMsg->Header.Rip, pMsg->MsrNummber, uValue, VBOXSTRICTRC_VAL(rcStrict) ));
     1706            Log4(("MsrExit/%u: %04x:%08RX64/%s: RDMSR %08x -> %08RX64 / %Rrc\n",
     1707                  pVCpu->idCpu, pMsg->Header.CsSegment.Selector, pMsg->Header.Rip, nemHCWinExecStateToLogStr(&pMsg->Header),
     1708                  pMsg->MsrNummber, uValue, VBOXSTRICTRC_VAL(rcStrict) ));
    16681709            if (rcStrict == VINF_SUCCESS)
    16691710            {
    … …  
    16781719            return rcStrict;
    16791720#else
    1680             LogRel(("MsrExit/%u: %04x:%08RX64: RDMSR %08x -> %08RX64 / %Rrc\n", pVCpu->idCpu, pMsg->Header.CsSegment.Selector,
    1681                     pMsg->Header.Rip, pMsg->MsrNummber, uValue, VBOXSTRICTRC_VAL(rcStrict) ));
     1721            LogRel(("MsrExit/%u: %04x:%08RX64/%s: RDMSR %08x -> %08RX64 / %Rrc\n",
     1722                    pVCpu->idCpu, pMsg->Header.CsSegment.Selector, pMsg->Header.Rip, nemHCWinExecStateToLogStr(&pMsg->Header),
     1723                    pMsg->MsrNummber, uValue, VBOXSTRICTRC_VAL(rcStrict) ));
    16821724#endif
    16831725        }
    16841726    }
    16851727    else if (pMsg->Header.InterceptAccessType == HV_INTERCEPT_ACCESS_WRITE)
    1686         Log4(("MsrExit/%u: CPL %u -> #GP(0); WRMSR %08x, %08x:%08x\n", pVCpu->idCpu,
     1728        Log4(("MsrExit/%u: %04x:%08RX64/%s: CPL %u -> #GP(0); WRMSR %08x, %08x:%08x\n",
     1729              pVCpu->idCpu, pMsg->Header.CsSegment.Selector, pMsg->Header.Rip, nemHCWinExecStateToLogStr(&pMsg->Header),
    16871730              pMsg->Header.CsSegment.DescriptorPrivilegeLevel, pMsg->MsrNummber, (uint32_t)pMsg->Rax, (uint32_t)pMsg->Rdx ));
    16881731    else
    1689         Log4(("MsrExit/%u: CPL %u -> #GP(0); RDMSR %08x\n",
    1690               pVCpu->idCpu, pMsg->Header.CsSegment.DescriptorPrivilegeLevel, pMsg->MsrNummber));
     1732        Log4(("MsrExit/%u: %04x:%08RX64/%s: CPL %u -> #GP(0); RDMSR %08x\n",
     1733              pVCpu->idCpu, pMsg->Header.CsSegment.Selector, pMsg->Header.Rip, nemHCWinExecStateToLogStr(&pMsg->Header),
     1734              pMsg->Header.CsSegment.DescriptorPrivilegeLevel, pMsg->MsrNummber));
    16911735
    16921736    /*
    … …  
    17351779     */
    17361780    nemHCWinCopyStateFromX64Header(pVCpu, pCtx, pMsgHdr);
    1737     Log(("TripleExit/%u: %04x:%08RX64: RFL=%#RX64 -> VINF_EM_TRIPLE_FAULT\n",
    1738          pVCpu->idCpu, pMsgHdr->CsSegment.Selector, pMsgHdr->Rip, pMsgHdr->Rflags));
     1781    Log(("TripleExit/%u: %04x:%08RX64/%s: RFL=%#RX64 -> VINF_EM_TRIPLE_FAULT\n",
     1782         pVCpu->idCpu, pMsgHdr->CsSegment.Selector, pMsgHdr->Rip, nemHCWinExecStateToLogStr(&pMsg->Header), pMsgHdr->Rflags));
    17391783    return VINF_EM_TRIPLE_FAULT;
    17401784#else
    … …  
    17501794        if (rcStrict == VINF_SUCCESS)
    17511795        {
    1752             Log(("UnrecovExit/%u: %04x:%08RX64: RFL=%#RX64 -> VINF_SUCCESS\n",
    1753                  pVCpu->idCpu, pMsgHdr->CsSegment.Selector, pMsgHdr->Rip, pMsgHdr->Rflags ));
     1796            Log(("UnrecovExit/%u: %04x:%08RX64/%s: RFL=%#RX64 -> VINF_SUCCESS\n", pVCpu->idCpu, pMsgHdr->CsSegment.Selector,
     1797                 pMsgHdr->Rip, nemHCWinExecStateToLogStr(pMsgHdr), pMsgHdr->Rflags ));
    17541798            return VINF_SUCCESS;
    17551799        }
    17561800        if (rcStrict == VINF_EM_TRIPLE_FAULT)
    1757             Log(("UnrecovExit/%u: %04x:%08RX64: RFL=%#RX64 -> VINF_EM_TRIPLE_FAULT!\n",
    1758                  pVCpu->idCpu, pMsgHdr->CsSegment.Selector, pMsgHdr->Rip, pMsgHdr->Rflags, VBOXSTRICTRC_VAL(rcStrict) ));
     1801            Log(("UnrecovExit/%u: %04x:%08RX64/%s: RFL=%#RX64 -> VINF_EM_TRIPLE_FAULT!\n", pVCpu->idCpu, pMsgHdr->CsSegment.Selector,
     1802                 pMsgHdr->Rip, nemHCWinExecStateToLogStr(pMsgHdr), pMsgHdr->Rflags, VBOXSTRICTRC_VAL(rcStrict) ));
    17591803        else
    1760             Log(("UnrecovExit/%u: %04x:%08RX64: RFL=%#RX64 -> %Rrc (IEMExecOne)\n",
    1761                  pVCpu->idCpu, pMsgHdr->CsSegment.Selector, pMsgHdr->Rip, pMsgHdr->Rflags, VBOXSTRICTRC_VAL(rcStrict) ));
     1804            Log(("UnrecovExit/%u: %04x:%08RX64/%s: RFL=%#RX64 -> %Rrc (IEMExecOne)\n", pVCpu->idCpu, pMsgHdr->CsSegment.Selector,
     1805                 pMsgHdr->Rip, nemHCWinExecStateToLogStr(pMsgHdr), pMsgHdr->Rflags, VBOXSTRICTRC_VAL(rcStrict) ));
    17621806    }
    17631807    else
    1764         Log(("UnrecovExit/%u: %04x:%08RX64: RFL=%#RX64 -> %Rrc (state import)\n",
    1765              pVCpu->idCpu, pMsgHdr->CsSegment.Selector, pMsgHdr->Rip, pMsgHdr->Rflags, VBOXSTRICTRC_VAL(rcStrict) ));
     1808        Log(("UnrecovExit/%u: %04x:%08RX64/%s: RFL=%#RX64 -> %Rrc (state import)\n", pVCpu->idCpu, pMsgHdr->CsSegment.Selector,
     1809             pMsgHdr->Rip, nemHCWinExecStateToLogStr(pMsgHdr), pMsgHdr->Rflags, VBOXSTRICTRC_VAL(rcStrict) ));
    17661810    return rcStrict;
    17671811#endif
Note: See TracChangeset for help on using the changeset viewer.

© 2024 Oracle Support Privacy / Do Not Sell My Info Terms of Use Trademark Policy Automated Access Etiquette