Changeset 90956 in vbox
- Timestamp:
- Aug 27, 2021 1:30:51 PM (4 years ago)
- svn:sync-xref-src-repo-rev:
- 146595
- Location:
- trunk/src/VBox/VMM
- Files:
-
- 3 edited
-
VMMR0/VMMR0.cpp (modified) (6 diffs)
-
VMMR3/VMM.cpp (modified) (7 diffs)
-
include/VMMInternal.h (modified) (4 diffs)
Legend:
- Unmodified
- Added
- Removed
-
trunk/src/VBox/VMM/VMMR0/VMMR0.cpp
r90953 r90956 2988 2988 pGVM->vmmr0.s.LogFlusher.idxRingHead = (idxHead + 1) % RT_ELEMENTS(pGVM->vmmr0.s.LogFlusher.aRing); 2989 2989 2990 /* Do the waking up. */2991 if ( idCpu < pGVM->cCpus2990 /* Do the accounting and waking up. */ 2991 if ( idCpu < pGVM->cCpus 2992 2992 && idxLogger < VMMLOGGER_IDX_MAX 2993 && idxBuffer < 1) 2994 { 2995 PGVMCPU pGVCpu = &pGVM->aCpus[idCpu]; 2996 PVMMR0PERVCPULOGGER pR0Log = &pGVCpu->vmmr0.s.u.aLoggers[idxLogger]; 2993 && idxBuffer < VMMLOGGER_BUFFER_COUNT) 2994 { 2995 PGVMCPU pGVCpu = &pGVM->aCpus[idCpu]; 2996 PVMMR0PERVCPULOGGER pR0Log = &pGVCpu->vmmr0.s.u.aLoggers[idxLogger]; 2997 PVMMR3CPULOGGER pShared = &pGVCpu->vmm.s.u.aLoggers[idxLogger]; 2998 2997 2999 pR0Log->fFlushDone = true; 3000 3001 uint32_t cFlushing = pR0Log->cFlushing - 1; 3002 if (RT_LIKELY(cFlushing < VMMLOGGER_BUFFER_COUNT)) 3003 { /*likely*/ } 3004 else 3005 cFlushing = 0; 3006 pR0Log->cFlushing = cFlushing; 3007 ASMAtomicWriteU32(&pShared->cFlushing, cFlushing); 2998 3008 2999 3009 RTSpinlockRelease(pGVM->vmmr0.s.LogFlusher.hSpinlock); … … 3105 3115 && RT_VALID_PTR(pGVM)) 3106 3116 { 3107 PVMMR0PERVCPULOGGER const pR0Log = &pGVCpu->vmmr0.s.u.aLoggers[idxLogger]; 3108 PVMMR3CPULOGGER const pShared = &pGVCpu->vmm.s.u.aLoggers[idxLogger]; 3109 3110 /* 3111 * Can we wait on the log flusher to do the work? 3112 */ 3113 if (VMMRZCallRing3IsEnabled(pGVCpu)) 3117 PVMMR0PERVCPULOGGER const pR0Log = &pGVCpu->vmmr0.s.u.aLoggers[idxLogger]; 3118 PVMMR3CPULOGGER const pShared = &pGVCpu->vmm.s.u.aLoggers[idxLogger]; 3119 size_t const idxBuffer = pBufDesc - &pR0Log->aBufDescs[0]; 3120 if (idxBuffer < RT_ELEMENTS(pR0Log->aBufDescs)) 3114 3121 { 3115 3122 /* 3116 * Make sure we don't recurse forever here should something in the 3117 * following code trigger logging or an assertion. 3123 * Can we wait on the log flusher to do the work? 3118 3124 */ 3119 if ( !pR0Log->fFlushing)3125 if (VMMRZCallRing3IsEnabled(pGVCpu)) 3120 3126 { 3121 pR0Log->fFlushing = true;3122 3123 3127 /* 3124 * Prepare to block waiting for the flusher thread. 3128 * Make sure we don't recurse forever here should something in the 3129 * following code trigger logging or an assertion. 3125 3130 */ 3126 VMMR0EMTBLOCKCTX Ctx; 3127 int rc = VMMR0EmtPrepareToBlock(pGVCpu, VINF_SUCCESS, "vmmR0LoggerFlushCommon", 3128 pR0Log->hEventFlushWait, &Ctx); 3129 if (RT_SUCCESS(rc)) 3131 if (!pR0Log->fFlushing) 3130 3132 { 3133 pR0Log->fFlushing = true; 3134 3131 3135 /* 3132 * Queue the flush job.3136 * Prepare to block waiting for the flusher thread. 3133 3137 */ 3134 RTSpinlockAcquire(pGVM->vmmr0.s.LogFlusher.hSpinlock); 3135 if (pGVM->vmmr0.s.LogFlusher.fThreadRunning) 3138 VMMR0EMTBLOCKCTX Ctx; 3139 int rc = VMMR0EmtPrepareToBlock(pGVCpu, VINF_SUCCESS, "vmmR0LoggerFlushCommon", 3140 pR0Log->hEventFlushWait, &Ctx); 3141 if (RT_SUCCESS(rc)) 3136 3142 { 3137 uint32_t const idxHead = pGVM->vmmr0.s.LogFlusher.idxRingHead 3138 % RT_ELEMENTS(pGVM->vmmr0.s.LogFlusher.aRing); 3139 uint32_t const idxTail = pGVM->vmmr0.s.LogFlusher.idxRingTail 3140 % RT_ELEMENTS(pGVM->vmmr0.s.LogFlusher.aRing); 3141 uint32_t const idxNewTail = (idxTail + 1) 3142 % RT_ELEMENTS(pGVM->vmmr0.s.LogFlusher.aRing); 3143 if (idxNewTail != idxHead) 3143 /* 3144 * Queue the flush job. 3145 */ 3146 RTSpinlockAcquire(pGVM->vmmr0.s.LogFlusher.hSpinlock); 3147 if (pGVM->vmmr0.s.LogFlusher.fThreadRunning) 3144 3148 { 3145 pGVM->vmmr0.s.LogFlusher.aRing[idxTail].s.idCpu = pGVCpu->idCpu; 3146 pGVM->vmmr0.s.LogFlusher.aRing[idxTail].s.idxLogger = idxLogger; 3147 pGVM->vmmr0.s.LogFlusher.aRing[idxTail].s.idxBuffer = 0; 3148 pGVM->vmmr0.s.LogFlusher.aRing[idxTail].s.fProcessing = 0; 3149 pGVM->vmmr0.s.LogFlusher.idxRingTail = idxNewTail; 3150 3151 if (pGVM->vmmr0.s.LogFlusher.fThreadWaiting) 3149 uint32_t const idxHead = pGVM->vmmr0.s.LogFlusher.idxRingHead 3150 % RT_ELEMENTS(pGVM->vmmr0.s.LogFlusher.aRing); 3151 uint32_t const idxTail = pGVM->vmmr0.s.LogFlusher.idxRingTail 3152 % RT_ELEMENTS(pGVM->vmmr0.s.LogFlusher.aRing); 3153 uint32_t const idxNewTail = (idxTail + 1) 3154 % RT_ELEMENTS(pGVM->vmmr0.s.LogFlusher.aRing); 3155 if (idxNewTail != idxHead) 3156 { 3157 pGVM->vmmr0.s.LogFlusher.aRing[idxTail].s.idCpu = pGVCpu->idCpu; 3158 pGVM->vmmr0.s.LogFlusher.aRing[idxTail].s.idxLogger = idxLogger; 3159 pGVM->vmmr0.s.LogFlusher.aRing[idxTail].s.idxBuffer = (uint32_t)idxBuffer; 3160 pGVM->vmmr0.s.LogFlusher.aRing[idxTail].s.fProcessing = 0; 3161 pGVM->vmmr0.s.LogFlusher.idxRingTail = idxNewTail; 3162 3163 pShared->cFlushing = pR0Log->cFlushing = RT_MIN(pR0Log->cFlushing + 1, 3164 VMMLOGGER_BUFFER_COUNT); 3165 3166 if (pGVM->vmmr0.s.LogFlusher.fThreadWaiting) 3167 { 3168 RTSpinlockRelease(pGVM->vmmr0.s.LogFlusher.hSpinlock); 3169 RTSemEventSignal(pGVM->vmmr0.s.LogFlusher.hEvent); 3170 } 3171 else 3172 RTSpinlockRelease(pGVM->vmmr0.s.LogFlusher.hSpinlock); 3173 3174 /* 3175 * Wait for it to complete. 3176 */ 3177 VMMR0EmtWaitEventInner(pGVCpu, VMMR0EMTWAIT_F_TRY_SUPPRESS_INTERRUPTED, 3178 pR0Log->hEventFlushWait, RT_INDEFINITE_WAIT); 3179 } 3180 else 3152 3181 { 3153 3182 RTSpinlockRelease(pGVM->vmmr0.s.LogFlusher.hSpinlock); 3154 RTSemEventSignal(pGVM->vmmr0.s.LogFlusher.hEvent);3183 SUP_DPRINTF(("vmmR0LoggerFlush: ring buffer is full!\n")); 3155 3184 } 3156 else3157 RTSpinlockRelease(pGVM->vmmr0.s.LogFlusher.hSpinlock);3158 3159 /*3160 * Wait for it to complete.3161 */3162 VMMR0EmtWaitEventInner(pGVCpu, VMMR0EMTWAIT_F_TRY_SUPPRESS_INTERRUPTED,3163 pR0Log->hEventFlushWait, RT_INDEFINITE_WAIT);3164 3185 } 3165 3186 else 3166 3187 { 3167 3188 RTSpinlockRelease(pGVM->vmmr0.s.LogFlusher.hSpinlock); 3168 SUP_DPRINTF(("vmmR0LoggerFlush: ring buffer is full!\n")); 3189 SUP_DPRINTF(("vmmR0LoggerFlush: flusher not active - dropping %u bytes\n", 3190 pBufDesc->offBuf)); 3169 3191 } 3192 VMMR0EmtResumeAfterBlocking(pGVCpu, &Ctx); 3170 3193 } 3171 3194 else 3172 { 3173 RTSpinlockRelease(pGVM->vmmr0.s.LogFlusher.hSpinlock); 3174 SUP_DPRINTF(("vmmR0LoggerFlush: flusher not active - dropping %u bytes\n", 3175 pBufDesc->offBuf)); 3176 } 3177 VMMR0EmtResumeAfterBlocking(pGVCpu, &Ctx); 3195 SUP_DPRINTF(("vmmR0LoggerFlush: VMMR0EmtPrepareToBlock failed! rc=%d\n", rc)); 3196 pR0Log->fFlushing = false; 3178 3197 } 3179 3198 else 3180 SUP_DPRINTF(("vmmR0LoggerFlush: VMMR0EmtPrepareToBlock failed! rc=%d\n", rc)); 3181 pR0Log->fFlushing = false; 3199 SUP_DPRINTF(("vmmR0LoggerFlush: Recursive flushing!\n")); 3182 3200 } 3183 3201 else 3184 SUP_DPRINTF(("vmmR0LoggerFlush: Recursive flushing!\n")); 3202 { 3203 #if defined(RT_OS_LINUX) 3204 SUP_DPRINTF(("vmmR0LoggerFlush: EMT blocking disabled! (%u bytes)\n", pBufDesc->offBuf)); 3205 #endif 3206 pShared->cbDropped += pBufDesc->offBuf; 3207 } 3185 3208 } 3186 3209 else 3187 { 3188 #if defined(RT_OS_LINUX) 3189 SUP_DPRINTF(("vmmR0LoggerFlush: EMT blocking disabled! (%u bytes)\n", pBufDesc->offBuf)); 3190 #endif 3191 pShared->cbDropped += pBufDesc->offBuf; 3192 } 3210 SUP_DPRINTF(("vmmR0LoggerFlush: pLogger=%p pGVCpu=%p: idxBuffer=%#zx\n", pLogger, pGVCpu, idxBuffer)); 3193 3211 } 3194 3212 else … … 3307 3325 * Create and configure the logger. 3308 3326 */ 3309 pR0Log->BufDesc.u32Magic = RTLOGBUFFERDESC_MAGIC; 3310 pR0Log->BufDesc.uReserved = 0; 3311 pR0Log->BufDesc.cbBuf = cbBuf; 3312 pR0Log->BufDesc.offBuf = 0; 3313 pR0Log->BufDesc.pchBuf = pchBuf; 3314 pR0Log->BufDesc.pAux = &pShared->AuxDesc; 3315 3316 pShared->AuxDesc.fFlushedIndicator = false; 3317 pShared->AuxDesc.afPadding[0] = 0; 3318 pShared->AuxDesc.afPadding[1] = 0; 3319 pShared->AuxDesc.afPadding[2] = 0; 3320 pShared->AuxDesc.offBuf = 0; 3321 pShared->pchBufR3 = pchBufR3; 3322 pShared->cbBuf = cbBuf; 3327 for (size_t i = 0; i < VMMLOGGER_BUFFER_COUNT; i++) 3328 { 3329 pR0Log->aBufDescs[i].u32Magic = RTLOGBUFFERDESC_MAGIC; 3330 pR0Log->aBufDescs[i].uReserved = 0; 3331 pR0Log->aBufDescs[i].cbBuf = cbBuf; 3332 pR0Log->aBufDescs[i].offBuf = 0; 3333 pR0Log->aBufDescs[i].pchBuf = pchBuf + i * cbBuf; 3334 pR0Log->aBufDescs[i].pAux = &pShared->aBufs[i].AuxDesc; 3335 3336 pShared->aBufs[i].AuxDesc.fFlushedIndicator = false; 3337 pShared->aBufs[i].AuxDesc.afPadding[0] = 0; 3338 pShared->aBufs[i].AuxDesc.afPadding[1] = 0; 3339 pShared->aBufs[i].AuxDesc.afPadding[2] = 0; 3340 pShared->aBufs[i].AuxDesc.offBuf = 0; 3341 pShared->aBufs[i].pchBufR3 = pchBufR3 + i * cbBuf; 3342 } 3343 pShared->cbBuf = cbBuf; 3323 3344 3324 3345 static const char * const s_apszGroups[] = VBOX_LOGGROUP_NAMES; 3325 3346 int rc = RTLogCreateEx(&pR0Log->pLogger, fRelease ? "VBOX_RELEASE_LOG" : "VBOX_LOG", RTLOG_F_NO_LOCKING | RTLOGFLAGS_BUFFERED, 3326 3347 "all", RT_ELEMENTS(s_apszGroups), s_apszGroups, UINT32_MAX, 3327 1 /*cBufDescs*/, &pR0Log->BufDesc, RTLOGDEST_DUMMY,3348 VMMLOGGER_BUFFER_COUNT, pR0Log->aBufDescs, RTLOGDEST_DUMMY, 3328 3349 NULL /*pfnPhase*/, 0 /*cHistory*/, 0 /*cbHistoryFileMax*/, 0 /*cSecsHistoryTimeSlot*/, 3329 3350 NULL /*pErrInfo*/, NULL /*pszFilenameFmt*/); … … 3361 3382 { 3362 3383 RTLogDestroy(pR0Log->pLogger); 3363 pR0Log->pLogger = NULL; 3364 pShared->pchBufR3 = NIL_RTR3PTR; 3384 pR0Log->pLogger = NULL; 3385 3386 for (size_t i = 0; i < VMMLOGGER_BUFFER_COUNT; i++) 3387 pShared->aBufs[i].pchBufR3 = NIL_RTR3PTR; 3365 3388 3366 3389 RTSemEventDestroy(pR0Log->hEventFlushWait); … … 3375 3398 { 3376 3399 /* Allocate buffers first. */ 3377 int rc = RTR0MemObjAllocPage(phMemObj, cbBuf * pGVM->cCpus , false /*fExecutable*/);3400 int rc = RTR0MemObjAllocPage(phMemObj, cbBuf * pGVM->cCpus * VMMLOGGER_BUFFER_COUNT, false /*fExecutable*/); 3378 3401 if (RT_SUCCESS(rc)) 3379 3402 { … … 3394 3417 PVMMR3CPULOGGER pShared = &pGVCpu->vmm.s.u.aLoggers[idxLogger]; 3395 3418 rc = vmmR0InitLoggerOne(pGVCpu, idxLogger == VMMLOGGER_IDX_RELEASE, pR0Log, pShared, cbBuf, 3396 pchBuf + i * cbBuf, pchBufR3 + i * cbBuf); 3419 pchBuf + i * cbBuf * VMMLOGGER_BUFFER_COUNT, 3420 pchBufR3 + i * cbBuf * VMMLOGGER_BUFFER_COUNT); 3397 3421 if (RT_FAILURE(rc)) 3398 3422 { 3399 pR0Log->pLogger = NULL; 3400 pShared->pchBufR3 = NIL_RTR3PTR; 3423 vmmR0TermLoggerOne(pR0Log, pShared); 3401 3424 while (i-- > 0) 3402 3425 { -
trunk/src/VBox/VMM/VMMR3/VMM.cpp
r90952 r90956 153 153 #define VMM_FLUSH_R0_LOG(a_pLogger, a_pR3Logger) \ 154 154 do { \ 155 if ((a_pLogger)->AuxDesc.offBuf == 0 || (a_pLogger)->AuxDesc.fFlushedIndicator) \ 155 size_t const idxBuf = (a_pLogger)->idxBuf % VMMLOGGER_BUFFER_COUNT; \ 156 if ( (a_pLogger)->aBufs[idxBuf].AuxDesc.offBuf == 0 \ 157 || (a_pLogger)->aBufs[idxBuf].AuxDesc.fFlushedIndicator) \ 156 158 { /* likely? */ } \ 157 159 else \ 158 { \ 159 RTLogBulkWrite(a_pR3Logger, (a_pLogger)->pchBufR3, (a_pLogger)->AuxDesc.offBuf); \ 160 (a_pLogger)->AuxDesc.fFlushedIndicator = true; \ 161 } \ 160 vmmR3LogReturnFlush(a_pLogger, idxBuf, a_pR3Logger); \ 162 161 } while (0) 163 162 … … 177 176 static int vmmR3ServiceCallRing3Request(PVM pVM, PVMCPU pVCpu); 178 177 static FNRTTHREAD vmmR3LogFlusher; 178 static void vmmR3LogReturnFlush(PVMMR3CPULOGGER pShared, size_t idxBuf, PRTLOGGER pDstLogger); 179 179 static DECLCALLBACK(void) vmmR3InfoFF(PVM pVM, PCDBGFINFOHLP pHlp, const char *pszArgs); 180 180 181 181 182 … … 829 830 VMMLOGFLUSHERENTRY Item; 830 831 Item.u32 = pVM->vmm.s.LogFlusherItem.u32; 831 if ( Item.s.idCpu < 832 && Item.s.idxLogger < 833 && Item.s.idxBuffer < = 1)832 if ( Item.s.idCpu < pVM->cCpus 833 && Item.s.idxLogger < VMMLOGGER_IDX_MAX 834 && Item.s.idxBuffer < VMMLOGGER_BUFFER_COUNT) 834 835 { 835 836 /* … … 838 839 PVMCPU const pVCpu = pVM->apCpusR3[Item.s.idCpu]; 839 840 PVMMR3CPULOGGER const pShared = &pVCpu->vmm.s.u.aLoggers[Item.s.idxLogger]; 840 uint32_t const cbToFlush = pShared-> AuxDesc.offBuf;841 uint32_t const cbToFlush = pShared->aBufs[Item.s.idxBuffer].AuxDesc.offBuf; 841 842 if (cbToFlush > 0) 842 843 { 843 844 if (cbToFlush <= pShared->cbBuf) 844 845 { 845 char * const pchBufR3 = pShared-> pchBufR3;846 char * const pchBufR3 = pShared->aBufs[Item.s.idxBuffer].pchBufR3; 846 847 if (pchBufR3) 847 848 { … … 851 852 LogAlways(("*FLUSH* idCpu=%u idxLogger=%u idxBuffer=%u cbToFlush=%#x fFlushed=%RTbool cbDropped=%#x\n", 852 853 Item.s.idCpu, Item.s.idxLogger, Item.s.idxBuffer, cbToFlush, 853 pShared-> AuxDesc.fFlushedIndicator, pShared->cbDropped));854 pShared->aBufs[Item.s.idxBuffer].AuxDesc.fFlushedIndicator, pShared->cbDropped)); 854 855 PRTLOGGER const pLogger = Item.s.idxLogger == VMMLOGGER_IDX_REGULAR 855 856 ? RTLogGetDefaultInstance() : RTLogRelGetDefaultInstance(); … … 873 874 * Mark the descriptor as flushed and set the request flag for same. 874 875 */ 875 pShared-> AuxDesc.fFlushedIndicator = true;876 pShared->aBufs[Item.s.idxBuffer].AuxDesc.fFlushedIndicator = true; 876 877 } 877 878 else … … 909 910 } 910 911 } 912 } 913 914 915 /** 916 * Helper for VMM_FLUSH_R0_LOG that does the flushing. 917 * 918 * @param pShared The shared logger data. 919 * @param idxBuf The buffer to flush. 920 * @param pDstLogger The destination IPRT logger. 921 */ 922 static void vmmR3LogReturnFlush(PVMMR3CPULOGGER pShared, size_t idxBuf, PRTLOGGER pDstLogger) 923 { 924 #if VMMLOGGER_BUFFER_COUNT > 1 925 /* Yield if other log buffers are being flushed already, so we try 926 avoid totally mixing things up... */ 927 if (pShared->cFlushing > 0) 928 RTThreadYield(); 929 #endif 930 RTLogBulkWrite(pDstLogger, pShared->aBufs[idxBuf].pchBufR3, pShared->aBufs[idxBuf].AuxDesc.offBuf); 931 pShared->aBufs[idxBuf].AuxDesc.fFlushedIndicator = true; 911 932 } 912 933 -
trunk/src/VBox/VMM/include/VMMInternal.h
r90953 r90956 66 66 #endif 67 67 68 69 /** Number of buffers per logger. */ 70 #define VMMLOGGER_BUFFER_COUNT 1 68 71 69 72 /** … … 79 82 /** Log buffer descriptor. 80 83 * The buffer is allocated in a common block for all VCpus, see VMMR0PERVM. */ 81 RTLOGBUFFERDESC BufDesc;84 RTLOGBUFFERDESC aBufDescs[VMMLOGGER_BUFFER_COUNT]; 82 85 /** Flag indicating whether we've registered the instance already. */ 83 86 bool fRegistered; … … 86 89 /** Set while we're inside vmmR0LoggerFlushCommon to prevent recursion. */ 87 90 bool fFlushing; 88 bool afPadding[5]; 91 bool afPadding[1]; 92 /** Number of buffers currently queued for flushing. */ 93 uint32_t cFlushing; 89 94 /** The event semaphore the EMT waits on while the buffer is being flushed. */ 90 95 RTSEMEVENT hEventFlushWait; … … 99 104 typedef struct VMMR3CPULOGGER 100 105 { 101 /** Auxiliary buffer descriptor. */ 102 RTLOGBUFFERAUXDESC AuxDesc; 103 /** Ring-3 mapping of the logging buffer. */ 104 R3PTRTYPE(char *) pchBufR3; 106 /** Buffer info. */ 107 struct 108 { 109 /** Auxiliary buffer descriptor. */ 110 RTLOGBUFFERAUXDESC AuxDesc; 111 /** Ring-3 mapping of the logging buffer. */ 112 R3PTRTYPE(char *) pchBufR3; 113 } aBufs[VMMLOGGER_BUFFER_COUNT]; 114 /** The current buffer. */ 115 uint32_t idxBuf; 116 /** Number of buffers currently queued for flushing (copy of 117 * VMMR0PERVCPULOGGER::cFlushing). */ 118 uint32_t volatile cFlushing; 105 119 /** The buffer size. */ 106 120 uint32_t cbBuf;
Note:
See TracChangeset
for help on using the changeset viewer.
