Index: /trunk/include/VBox/scsi.h =================================================================== --- /trunk/include/VBox/scsi.h (revision 80595) +++ /trunk/include/VBox/scsi.h (revision 80596) @@ -238,4 +238,5 @@ #define SCSI_ASCQ_UNKNOWN_FORMAT 0x01 #define SCSI_ASCQ_INCOMPATIBLE_FORMAT 0x02 +#define SCSI_ASCQ_COPY_TARGET_DEVICE_DATA_OVERRUN 0x0d /** @name SCSI_INQUIRY Index: /trunk/src/VBox/Devices/Storage/DevVirtioSCSI.cpp =================================================================== --- /trunk/src/VBox/Devices/Storage/DevVirtioSCSI.cpp (revision 80595) +++ /trunk/src/VBox/Devices/Storage/DevVirtioSCSI.cpp (revision 80596) @@ -106,4 +106,5 @@ #define CBQUEUENAME(qIdx) RTStrNLen(QUEUENAME(qIdx), sizeof(QUEUENAME(qIdx))) + #define IS_REQ_QUEUE(qIdx) (qIdx >= VIRTQ_REQ_BASE && qIdx < VIRTIOSCSI_QUEUE_CNT) /** @@ -463,4 +464,5 @@ /** * Request structure for IMediaEx (Associated Interfaces implemented by DrvSCSI) + * (NOTE: cbIn, cbOUt, cbDataOut mostly for debugging) */ typedef struct VIRTIOSCSIREQ @@ -469,7 +471,10 @@ PVIRTIOSCSITARGET pTarget; /**< Target */ uint16_t qIdx; /**< Index of queue this request arrived on */ + size_t cbIn; /**< Size of input descriptor chain */ + size_t cbOut; /**< Size of output descriptor chain */ size_t cbPiOut; /**< Size of T10 pi in buffer */ uint8_t *pbPiOut; /**< Address of pi out buffer */ uint8_t *pbDataOut; /**< dataout */ + size_t cbDataOut; /**< size of dataout buffer */ size_t cbPiIn; /**< Size of T10 pi buffer */ uint8_t *pbPiIn; /**< Address of pi in buffer */ @@ -477,5 +482,7 @@ uint8_t *pbDataIn; /**< datain */ size_t cbSense; /**< Size of sense buffer */ + size_t uSenseLen; /**< Receives # bytes written into sense buffer */ uint8_t *pbSense; /**< Pointer to R3 sense buffer */ + PDMMEDIAEXIOREQSCSITXDIR enmTxDir; /**< Receives transfer direction of I/O req */ uint8_t uStatus; /**< SCSI status code */ PRTSGBUF pInSgBuf; /**< Buf vector to return PDM result to VirtIO Guest */ @@ -487,4 +494,25 @@ #define SET_LUN_BUF(target, lun, out) \ out[0] = 0x01; out[1] = target; out[2] = (lun >> 8) & 0x40; out[3] = lun & 0xff; *((uint16_t *)out + 4) = 0; + + +DECLINLINE(bool) isBufZero(uint8_t *pv, size_t cb) +{ + for (uint32_t i = 0; i < cb; i++) + if (pv[i]) + return false; + return true; +} + +DECLINLINE(const char *) virtioGetTxDirText(uint32_t enmTxDir) +{ + switch (enmTxDir) + { + case PDMMEDIAEXIOREQSCSITXDIR_UNKNOWN: return ""; + case PDMMEDIAEXIOREQSCSITXDIR_FROM_DEVICE: return ""; + case PDMMEDIAEXIOREQSCSITXDIR_TO_DEVICE: return ""; + case PDMMEDIAEXIOREQSCSITXDIR_NONE: return ""; + default: return ""; + } +} @@ -610,5 +638,9 @@ } - +#define VIRTIO_IN_DIRECTION(pMediaExTxDirEnumValue) \ + pMediaExTxDirEnumValue == PDMMEDIAEXIOREQSCSITXDIR_FROM_DEVICE + +#define VIRTIO_OUT_DIRECTION(pMediaExTxDirEnumValue) \ + pMediaExTxDirEnumValue == PDMMEDIAEXIOREQSCSITXDIR_TO_DEVICE typedef struct VIRTIOSCSIREQ *PVIRTIOSCSIREQ; @@ -765,6 +797,48 @@ return VINF_SUCCESS; - -} +} + +/** + * This is called to complete a request immediately + * + * @param pThis - PDM driver instance state + * @param qIdx - Queue index + * @param pRespHdr - Response header + * @param pbSense - Pointer to sense buffer or NULL if none. + * + * @returns virtual box status code + */ +static int virtioScsiReqErr(PVIRTIOSCSI pThis, uint16_t qIdx, struct REQ_RESP_HDR *pRespHdr, uint8_t *pbSense) +{ + uint8_t *abSenseBuf = (uint8_t *)RTMemAllocZ(pThis->virtioScsiConfig.uSenseSize); + AssertReturn(abSenseBuf, VERR_NO_MEMORY); + + Log2Func((" status: %s response: %s\n", + SCSIStatusText(pRespHdr->uStatus), virtioGetReqRespText(pRespHdr->uResponse))); + + RTSGSEG aReqSegs[2]; + aReqSegs[0].cbSeg = sizeof(pRespHdr); + aReqSegs[0].pvSeg = pRespHdr; + aReqSegs[1].cbSeg = pThis->virtioScsiConfig.uSenseSize; + aReqSegs[1].pvSeg = abSenseBuf; + + if (pbSense && pRespHdr->uSenseLen) + memcpy(abSenseBuf, pbSense, pRespHdr->uSenseLen); + else + pRespHdr->uSenseLen = 0; + + RTSGBUF reqSegBuf; + RTSgBufInit(&reqSegBuf, aReqSegs, RT_ELEMENTS(aReqSegs)); + + virtioQueuePut(pThis->hVirtio, qIdx, &reqSegBuf, true /* fFence */); + virtioQueueSync(pThis->hVirtio, qIdx); + + RTMemFree(abSenseBuf); + + Log(("---------------------------------------------------------------------------------\n")); + + return VINF_SUCCESS; +} + /** TBD: VirtIO 1.0 spec 5.6.6.1.1 requires some request actions on reset that are * not implemented. Specifically either canceling outstanding I/O or @@ -795,5 +869,5 @@ #define SHOULD_FIX_VSCSI_TO_RETURN_SENSE_LEN 32 struct REQ_RESP_HDR respHdr = { 0 }; - respHdr.uSenseLen = pReq->uStatus == SCSI_STATUS_CHECK_CONDITION ? SHOULD_FIX_VSCSI_TO_RETURN_SENSE_LEN : 0; + respHdr.uSenseLen = pReq->pbSense[2] == SCSI_SENSE_NONE ? 0 : pReq->uSenseLen; respHdr.uResidual = cbResidual; respHdr.uStatus = pReq->uStatus; @@ -810,14 +884,4 @@ break; } - /* fallthrough */ - case SCSI_STATUS_BUSY: - respHdr.uResponse = VIRTIOSCSI_S_BUSY; - break; - case SCSI_STATUS_DATA_UNDEROVER_RUN: - respHdr.uResponse = VIRTIOSCSI_S_OVERRUN; - break; - case SCSI_STATUS_TASK_ABORTED: - respHdr.uResponse = VIRTIOSCSI_S_ABORTED; - break; case SCSI_STATUS_CHECK_CONDITION: { @@ -838,5 +902,5 @@ break; case SCSI_SENSE_NOT_READY: - respHdr.uResponse = VIRTIOSCSI_S_BUSY; /* e.g. try again */ + respHdr.uResponse = VIRTIOSCSI_S_BUSY; /* e.g. re-tryable */ break; default: @@ -852,65 +916,102 @@ } - Log2Func(("status: %s, response: (%x) %s\n", - SCSIStatusText(pReq->uStatus), respHdr.uResponse, virtioGetReqRespText(respHdr.uResponse))); + Log2Func(("status: (%d) %s, response: (%d) %s\n", + pReq->uStatus, SCSIStatusText(pReq->uStatus), respHdr.uResponse, virtioGetReqRespText(respHdr.uResponse))); if (RT_FAILURE(rcReq)) Log2Func(("rcReq: %s\n", RTErrGetDefine(rcReq))); - Log3Func(("status:%02x/resp:%02x, xfer=%d, residual: %u, sense (len=%d, alloc=%d)\n", - pReq->uStatus, respHdr.uResponse, cbXfer, cbResidual, - respHdr.uSenseLen, pThis->virtioScsiConfig.uSenseSize)); + if (LogIs3Enabled()) + { + LogFunc(("cbDataIn = %u, cbDataOut = %u (cbIn = %u, cbOut = %u)\n", + pReq->cbDataIn, pReq->cbDataOut, pReq->cbIn, pReq->cbOut)); + LogFunc(("xfer = %d, residual = %u\n", cbXfer, cbResidual)); + LogFunc(("xfer direction: %s, sense written = %d, sense size = %d\n", + virtioGetTxDirText(pReq->enmTxDir), respHdr.uSenseLen, pThis->virtioScsiConfig.uSenseSize)); + } if (respHdr.uSenseLen && LogIs2Enabled()) { - Log2Func(("Sense: %s\n", SCSISenseText(pReq->pbSense[2]))); - Log2Func(("Sense Ext3: %s\n", SCSISenseExtText(pReq->pbSense[12], pReq->pbSense[13]))); + LogFunc(("Sense: %s\n", SCSISenseText(pReq->pbSense[2]))); + LogFunc(("Sense Ext3: %s\n", SCSISenseExtText(pReq->pbSense[12], pReq->pbSense[13]))); + } + + if (LogIsItEnabled(RTLOGGRPFLAGS_LEVEL_12, LOG_GROUP)) + { + size_t cb = RT_MIN(cbXfer, 256); + if (VIRTIO_IN_DIRECTION(pReq->enmTxDir)) + { + Log(("datain[256 of %d total bytes xferred]:\n", cbXfer)); + if (!isBufZero(pReq->pbDataIn, cb)) + VIRTIO_HEX_DUMP(RTLOGGRPFLAGS_LEVEL_12, pReq->pbDataIn, cb, 0, 0); + else + Log12(("-- %d zeroes --\n", cb)); + } + else + if (VIRTIO_OUT_DIRECTION(pReq->enmTxDir)) + { + Log(("dataout[256 of %d total bytes xferred]:\n", cbXfer)); + if (!isBufZero(pReq->pbDataOut, cb)) + VIRTIO_HEX_DUMP(RTLOGGRPFLAGS_LEVEL_12, pReq->pbDataOut, cb, 0, 0); + else + Log12(("-- %d zeroes --\n", cb)); + } } int cSegs = 0; - -// Assert(pReq->cbDataIn >= cbXfer); - Assert(pReq->pbSense != NULL); - - RTSGSEG aReqSegs[4]; - aReqSegs[cSegs].pvSeg = &respHdr; - aReqSegs[cSegs++].cbSeg = sizeof(respHdr); - - aReqSegs[cSegs].pvSeg = pReq->pbSense; - aReqSegs[cSegs++].cbSeg = pReq->cbSense; /* VirtIO 1.0 spec 5.6.4/5.6.6.1 */ - - if (pReq->cbPiIn) - { - aReqSegs[cSegs].pvSeg = pReq->pbPiIn; - aReqSegs[cSegs++].cbSeg = pReq->cbPiIn; - } - if (pReq->cbDataIn) - { - aReqSegs[cSegs].pvSeg = pReq->pbDataIn; - aReqSegs[cSegs++].cbSeg = cbXfer; - } - RTSGBUF reqSegBuf; - RTSgBufInit(&reqSegBuf, aReqSegs, cSegs); - - /** - * Fill in the request queue current descriptor chain's IN queue entry/entries - * (phys. memory) with the Req response data in virtual memory. - */ - size_t cbReqSgBuf = RTSgBufCalcTotalLength(&reqSegBuf); - size_t cbInSgBuf = RTSgBufCalcTotalLength(pReq->pInSgBuf); - AssertMsgReturn(cbReqSgBuf <= cbInSgBuf, - ("Guest expected less req data (space needed: %d, avail: %d)\n", cbReqSgBuf, cbInSgBuf), - VERR_BUFFER_OVERFLOW); - - /** - * Following doesn't put up memory barrier (fence). - * VirtIO 1.0 Spec requires mem. barrier for ctrl cmds - * but doesn't mention fences in regard to requests. */ - virtioQueuePut(pThis->hVirtio, pReq->qIdx, &reqSegBuf, true /* fFence TBD */); - virtioQueueSync(pThis->hVirtio, pReq->qIdx); - - Log(("-----------------------------------------------------------------------------------------\n")); - + if ( (VIRTIO_IN_DIRECTION(pReq->enmTxDir) && cbXfer > pReq->cbDataIn) + || (VIRTIO_OUT_DIRECTION(pReq->enmTxDir) && cbXfer > pReq->cbDataOut)) + { + /** TBD try to figure out optimal sense info to send back besides response of VIRTIOSCSI_S_OVERRUN */ + Log2Func((" * * * * Data overrun, returning sense\n")); + uint8_t abSense[] = { RT_BIT(7) | SCSI_SENSE_RESPONSE_CODE_CURR_FIXED, + 0, SCSI_SENSE_ILLEGAL_REQUEST, 0, 0, 0, 0, 10, 0, 0, 0 }; + respHdr.uSenseLen = sizeof(abSense); + respHdr.uStatus = SCSI_STATUS_CHECK_CONDITION; + respHdr.uResponse = VIRTIOSCSI_S_OVERRUN; + respHdr.uResidual = pReq->cbDataIn; + virtioScsiReqErr(pThis, pReq->qIdx, &respHdr, abSense); + } + else + { + Assert(pReq->pbSense != NULL); + + RTSGSEG aReqSegs[4]; + aReqSegs[cSegs].pvSeg = &respHdr; + aReqSegs[cSegs++].cbSeg = sizeof(respHdr); + + aReqSegs[cSegs].pvSeg = pReq->pbSense; + aReqSegs[cSegs++].cbSeg = pReq->cbSense; /* VirtIO 1.0 spec 5.6.4/5.6.6.1 */ + + if (pReq->cbPiIn) + { + aReqSegs[cSegs].pvSeg = pReq->pbPiIn; + aReqSegs[cSegs++].cbSeg = pReq->cbPiIn; + } + if (pReq->cbDataIn) + { + aReqSegs[cSegs].pvSeg = pReq->pbDataIn; + aReqSegs[cSegs++].cbSeg = cbXfer; + } + RTSGBUF reqSegBuf; + RTSgBufInit(&reqSegBuf, aReqSegs, cSegs); + + /** + * Fill in the request queue current descriptor chain's IN queue entry/entries + * (phys. memory) with the Req response data in virtual memory. + */ + size_t cbReqSgBuf = RTSgBufCalcTotalLength(&reqSegBuf); + size_t cbInSgBuf = RTSgBufCalcTotalLength(pReq->pInSgBuf); + AssertMsgReturn(cbReqSgBuf <= cbInSgBuf, + ("Guest expected less req data (space needed: %d, avail: %d)\n", cbReqSgBuf, cbInSgBuf), + VERR_BUFFER_OVERFLOW); + + virtioQueuePut(pThis->hVirtio, pReq->qIdx, &reqSegBuf, true /* fFence TBD */); + virtioQueueSync(pThis->hVirtio, pReq->qIdx); + + Log(("-----------------------------------------------------------------------------------------\n")); + + } RTMemFree(pReq->pbSense); RTMemFree(pReq->pbDataIn); @@ -926,46 +1027,4 @@ } -/** - * This is called to complete a request immediately - * - * @param pThis - PDM driver instance state - * @param qIdx - Queue index - * @param pRespHdr - Response header - * @param pbSense - Pointer to sense buffer or NULL if none. - * - * @returns virtual box status code - */ -static int virtioScsiReqFinish(PVIRTIOSCSI pThis, uint16_t qIdx, struct REQ_RESP_HDR *pRespHdr, uint8_t *pbSense) -{ - uint8_t *abSenseBuf = (uint8_t *)RTMemAllocZ(pThis->virtioScsiConfig.uSenseSize); - AssertReturn(abSenseBuf, VERR_NO_MEMORY); - - Log2Func(("status: %s response: %s\n", - SCSIStatusText(pRespHdr->uStatus), virtioGetReqRespText(pRespHdr->uResponse))); - - RTSGSEG aReqSegs[2]; - aReqSegs[0].cbSeg = sizeof(pRespHdr); - aReqSegs[0].pvSeg = pRespHdr; - aReqSegs[1].cbSeg = pThis->virtioScsiConfig.uSenseSize; - aReqSegs[1].pvSeg = abSenseBuf; - - if (pbSense && pRespHdr->uSenseLen) - memcpy(abSenseBuf, pbSense, pRespHdr->uSenseLen); - else - pRespHdr->uSenseLen = 0; - - RTSGBUF reqSegBuf; - RTSgBufInit(&reqSegBuf, aReqSegs, RT_ELEMENTS(aReqSegs)); - - virtioQueuePut(pThis->hVirtio, qIdx, &reqSegBuf, true /* fFence */); - virtioQueueSync(pThis->hVirtio, qIdx); - - RTMemFree(abSenseBuf); - - Log(("---------------------------------------------------------------------------------\n")); - - return VINF_SUCCESS; -} - static int virtioScsiReqSubmit(PVIRTIOSCSI pThis, uint16_t qIdx, PRTSGBUF pInSgBuf, PRTSGBUF pOutSgBuf) { @@ -975,8 +1034,6 @@ size_t cbIn = RTSgBufCalcTotalLength(pInSgBuf); - AssertMsgReturn(cbOut >= sizeof(REQ_CMD_HDR) + pThis->virtioScsiConfig.uCdbSize, - ("Req too short"), VERR_BUFFER_UNDERFLOW); - - PVIRTIOSCSI_REQ_CMD_T pVirtqReq = (PVIRTIOSCSI_REQ_CMD_T)RTMemAlloc(cbOut); + /** MAKE THIS NON-ZERO MALLOCING AFTER DEBUG */ + PVIRTIOSCSI_REQ_CMD_T pVirtqReq = (PVIRTIOSCSI_REQ_CMD_T)RTMemAllocZ(cbOut); AssertReturn(pVirtqReq, VERR_NO_MEMORY); @@ -992,4 +1049,6 @@ } +// VIRTIO_HEX_DUMP(RTLOGGRPFLAGS_LEVEL_12, (uint8_t *)pVirtqReq, cbOut, 0, "\npVirtqReq"); + uint8_t uTarget = pVirtqReq->cmdHdr.uLUN[1]; uint32_t uLUN = (pVirtqReq->cmdHdr.uLUN[2] << 8 | pVirtqReq->cmdHdr.uLUN[3]) & 0x3fff; @@ -997,7 +1056,8 @@ LogFunc(("[%s] (Target: %d LUN: %d) CDB: %.*Rhxs\n", SCSICmdText(pVirtqReq->uCdb[0]), uTarget, uLUN, - virtioScsiEstimateCdbLen(pVirtqReq->uCdb[0], pThis->virtioScsiConfig.uCdbSize), pVirtqReq->uCdb)); - - Log3Func((" id: %RX64, attr: %x, prio: %d, crn: %x\n", + virtioScsiEstimateCdbLen(pVirtqReq->uCdb[0], + pThis->virtioScsiConfig.uCdbSize), pVirtqReq->uCdb)); + + Log3Func(("id: %RX64, attr: %x, prio: %d, crn: %x\n", pVirtqReq->cmdHdr.uId, pVirtqReq->cmdHdr.uTaskAttr, pVirtqReq->cmdHdr.uPrio, pVirtqReq->cmdHdr.uCrn)); @@ -1016,5 +1076,5 @@ } - off_t uDataOutOff = sizeof(REQ_CMD_HDR) + pThis->virtioScsiConfig.uCdbSize + cbPiHdr; + off_t uDataOutOff = sizeof(REQ_CMD_HDR) + pThis->virtioScsiConfig.uCdbSize + cbPiHdr; off_t uDataInOff = sizeof(REQ_RESP_HDR) + pThis->virtioScsiConfig.uSenseSize + cbPiIn; uint8_t *pbDataOut = (uint8_t *)((uint64_t)pVirtqReq + uDataOutOff); @@ -1032,5 +1092,5 @@ respHdr.uResponse = (uTarget > pThis->cTargets) ? VIRTIOSCSI_S_BAD_TARGET : VIRTIOSCSI_S_OK; respHdr.uResidual = cbDataOut + cbDataIn; - virtioScsiReqFinish(pThis, qIdx, &respHdr, abSense); + virtioScsiReqErr(pThis, qIdx, &respHdr, abSense); return VINF_SUCCESS; } @@ -1048,5 +1108,5 @@ respHdr.uResponse = VIRTIOSCSI_S_TARGET_FAILURE; respHdr.uResidual = cbDataIn + cbDataOut; - virtioScsiReqFinish(pThis, qIdx, &respHdr, abSense); + virtioScsiReqErr(pThis, qIdx, &respHdr, abSense); RTMemFree(pVirtqReq); return VINF_SUCCESS; @@ -1074,5 +1134,8 @@ pReq->pTarget = pTarget; pReq->qIdx = qIdx; + pReq->cbIn = cbIn; + pReq->cbOut = cbOut; pReq->pbDataOut = pbDataOut; + pReq->cbDataOut = cbDataOut; pReq->pVirtqReq = pVirtqReq; pReq->pInSgBuf = pInSgBuf; @@ -1092,6 +1155,6 @@ rc = pIMediaEx->pfnIoReqSendScsiCmd(pIMediaEx, pReq->hIoReq, uLUN, pVirtqReq->uCdb, pThis->virtioScsiConfig.uCdbSize, - PDMMEDIAEXIOREQSCSITXDIR_UNKNOWN, NULL, cbDataIn, - pReq->pbSense, pReq->cbSense, NULL, + PDMMEDIAEXIOREQSCSITXDIR_UNKNOWN, &pReq->enmTxDir, cbDataIn, + pReq->pbSense, pReq->cbSense, &pReq->uSenseLen, &pReq->uStatus, 30 * RT_MS_1SEC); @@ -1124,5 +1187,5 @@ respHdr.uResponse = VIRTIOSCSI_S_FAILURE; respHdr.uResidual = cbDataIn + cbDataOut; - virtioScsiReqFinish(pThis, qIdx, &respHdr, abSense); + virtioScsiReqErr(pThis, qIdx, &respHdr, abSense); RTMemFree(pReq->pbSense); RTMemFree(pReq->pbDataIn); @@ -1336,5 +1399,5 @@ if (!fNotificationSent) { - Log3Func(("%s worker sleeping...\n", QUEUENAME(qIdx))); + Log6Func(("%s worker sleeping...\n", QUEUENAME(qIdx))); Assert(ASMAtomicReadBool(&pWorker->fSleeping)); rc = SUPSemEventWaitNoResume(pThis->pSupDrvSession, pWorker->hEvtProcess, RT_INDEFINITE_WAIT); @@ -1342,10 +1405,10 @@ if (RT_UNLIKELY(pThread->enmState != PDMTHREADSTATE_RUNNING)) break; - Log3Func(("%s worker woken\n", QUEUENAME(qIdx))); + Log6Func(("%s worker woken\n", QUEUENAME(qIdx))); ASMAtomicWriteBool(&pWorker->fNotified, false); } ASMAtomicWriteBool(&pWorker->fSleeping, false); } - Log3Func(("fetching next descriptor chain from %s\n", QUEUENAME(qIdx))); + Log6Func(("fetching next descriptor chain from %s\n", QUEUENAME(qIdx))); rc = virtioQueueGet(pThis->hVirtio, qIdx, true, &pInSgBuf, &pOutSgBuf); if (rc == VERR_NOT_AVAILABLE) @@ -1576,5 +1639,5 @@ if (qIdx == CONTROLQ_IDX || IS_REQ_QUEUE(qIdx)) { - Log3Func(("%s has available data\n", QUEUENAME(qIdx))); + Log6Func(("%s has available data\n", QUEUENAME(qIdx))); /** Wake queue's worker thread up if sleeping */ if (!ASMAtomicXchgBool(&pWorker->fNotified, true)) @@ -1582,5 +1645,5 @@ if (ASMAtomicReadBool(&pWorker->fSleeping)) { - Log3Func(("waking %s worker.\n", QUEUENAME(qIdx))); + Log6Func(("waking %s worker.\n", QUEUENAME(qIdx))); int rc = SUPSemEventSignal(pThis->pSupDrvSession, pWorker->hEvtProcess); AssertRC(rc); @@ -2145,5 +2208,4 @@ return PDMDEV_SET_ERROR(pDevIns, rc, N_("virtio-scsi: failed to initialize VirtIO")); - RTStrCopy((char *)pThis->szQueueNames[CONTROLQ_IDX], VIRTIO_MAX_QUEUE_NAME_SIZE, "controlq"); RTStrCopy((char *)pThis->szQueueNames[EVENTQ_IDX], VIRTIO_MAX_QUEUE_NAME_SIZE, "eventq"); @@ -2152,13 +2214,4 @@ "requestq<%d>", qIdx - VIRTQ_REQ_BASE); - /** - * Create one worker per incoming-work-related queue (eventq is outgoing status to guest, - * wherein guest is supposed to keep the queue loaded-up with buffer vectors the host - * can quickly fill-in send back). Should be light-duty and fast enough to be handled on - * requestq or controlq thread. The Linux virtio_scsi driver limits the number of request - * queues to MIN(<# Guest CPUs>, ), so queue count is ultimately - * constrained from host side at negotiation time and initialization and later through - * bounds-checking. - */ for (uint16_t qIdx = 0; qIdx < VIRTIOSCSI_QUEUE_CNT; qIdx++) { Index: /trunk/src/VBox/Devices/VirtIO/Virtio_1_0.cpp =================================================================== --- /trunk/src/VBox/Devices/VirtIO/Virtio_1_0.cpp (revision 80595) +++ /trunk/src/VBox/Devices/VirtIO/Virtio_1_0.cpp (revision 80596) @@ -81,10 +81,10 @@ if (pszDepiction[i] == ' ' && first++) pszDepiction[i] = '.'; - Log3Func(("%s: Guest %s %s 0x%s\n", + Log6Func(("%s: Guest %s %s 0x%s\n", pszFunc, fWrite ? "wrote" : "read ", pszDepiction, pszFormattedVal)); } else /* odd number or oversized access, ... log inline hex-dump style */ { - Log3Func(("%s: Guest %s %s%s[%d:%d]: %.*Rhxs\n", + Log6Func(("%s: Guest %s %s%s[%d:%d]: %.*Rhxs\n", pszFunc, fWrite ? "wrote" : "read ", pszMember, pszIdx, uOffset, uOffset + cb, cb, pv)); @@ -199,5 +199,5 @@ uint16_t uDescIdx = pDescChain->uHeadIdx; - Log3Func(("%s DESC CHAIN: (head) desc_idx=%u [avail_idx=%u]\n", + Log6Func(("%s DESC CHAIN: (head) desc_idx=%u [avail_idx=%u]\n", pVirtqProxy->szVirtqName, pDescChain->uHeadIdx, pVirtqProxy->uAvailIdx)); @@ -238,5 +238,5 @@ if (desc.fFlags & VIRTQ_DESC_F_WRITE) { - Log3Func(("%s IN desc_idx=%u seg=%u addr=%RGp cb=%u\n", + Log6Func(("%s IN desc_idx=%u seg=%u addr=%RGp cb=%u\n", QUEUENAME(qIdx), uDescIdx, pDescChain->cSegsIn, desc.pGcPhysBuf, desc.cb)); cbIn += desc.cb; @@ -245,5 +245,5 @@ else { - Log3Func(("%s OUT desc_idx=%u seg=%u addr=%RGp cb=%u\n", + Log6Func(("%s OUT desc_idx=%u seg=%u addr=%RGp cb=%u\n", QUEUENAME(qIdx), uDescIdx, pDescChain->cSegsOut, desc.pGcPhysBuf, desc.cb)); cbOut += desc.cb; @@ -261,10 +261,10 @@ if (ppInSegs) - *ppInSegs = &pVirtqProxy->inSgBuf; + *ppInSegs = &pVirtqProxy->inSgBuf; if (ppOutSegs) *ppOutSegs = &pVirtqProxy->outSgBuf; - Log3Func(("%s -- segs OUT: %u (%u bytes) IN: %u (%u bytes) --\n", + Log6Func(("%s -- segs OUT: %u (%u bytes) IN: %u (%u bytes) --\n", pVirtqProxy->szVirtqName, pDescChain->cSegsOut, cbOut, pDescChain->cSegsIn, cbIn)); @@ -292,5 +292,5 @@ size_t cbRemain = RTSgBufCalcTotalLength(pBufSrc); uint16_t uUsedIdx = virtioReadUsedRingIdx(pVirtio, qIdx); - Log3Func(("Copying client data to %s, desc chain (head desc_idx %d)\n", + Log6Func(("Copying client data to %s, desc chain (head desc_idx %d)\n", QUEUENAME(qIdx), uUsedIdx)); @@ -328,8 +328,8 @@ size_t cbInSgBuf = RTSgBufCalcTotalLength(pBufDst); size_t cbWritten = cbInSgBuf - RTSgBufCalcLengthLeft(pBufDst); - Log2Func(("Copied %u bytes to %u byte buffer, residual=%d\n", + Log2Func((".... Copied %u bytes to %u byte buffer, residual=%d\n", cbWritten, cbInSgBuf, cbInSgBuf - cbWritten)); } - Log3Func(("Write ahead used_idx=%d, %s used_idx=%d\n", + Log6Func(("Write ahead used_idx=%d, %s used_idx=%d\n", pVirtqProxy->uUsedIdx, QUEUENAME(qIdx), uUsedIdx)); @@ -351,5 +351,5 @@ uint16_t uIdx = virtioReadUsedRingIdx(pVirtio, qIdx); - Log3Func(("Updating %s used_idx from %u to %u\n", + Log6Func(("Updating %s used_idx from %u to %u\n", QUEUENAME(qIdx), uIdx, pVirtqProxy->uUsedIdx)); @@ -368,5 +368,5 @@ PVIRTQ_PROXY_T pVirtqProxy = &pVirtio->virtqProxy[qIdx]; - Log3Func(("%s\n", pVirtqProxy->szVirtqName)); + Log6Func(("%s\n", pVirtqProxy->szVirtqName)); @@ -398,5 +398,5 @@ return; } - Log3Func(("...skipping interrupt: VIRTIO_F_EVENT_IDX set but threshold not reached\n")); + Log6Func(("...skipping interrupt: VIRTIO_F_EVENT_IDX set but threshold not reached\n")); } else @@ -408,5 +408,5 @@ return; } - Log3Func(("...skipping interrupt. Guest flagged VIRTQ_AVAIL_F_NO_INTERRUPT for queue\n")); + Log6Func(("...skipping interrupt. Guest flagged VIRTQ_AVAIL_F_NO_INTERRUPT for queue\n")); } @@ -456,8 +456,8 @@ { if (uCause == VIRTIO_ISR_VIRTQ_INTERRUPT) - Log3Func(("reason: buffer added to 'used' ring.\n")); + Log6Func(("reason: buffer added to 'used' ring.\n")); else if (uCause == VIRTIO_ISR_DEVICE_CONFIG) - Log3Func(("reason: device config change\n")); + Log6Func(("reason: device config change\n")); pVirtio->uISR |= uCause; @@ -642,7 +642,7 @@ { pVirtio->uDeviceStatus = *(uint8_t *)pv; - Log3Func(("Guest wrote uDeviceStatus ................ (")); + Log6Func(("Guest wrote uDeviceStatus ................ (")); virtioLogDeviceStatus(pVirtio->uDeviceStatus); - Log3((")\n")); + Log6((")\n")); if (pVirtio->uDeviceStatus == 0) virtioGuestResetted(pVirtio); @@ -659,8 +659,8 @@ else /* Guest READ pCommonCfg->uDeviceStatus */ { - Log3Func(("Guest read uDeviceStatus ................ (")); + Log6Func(("Guest read uDeviceStatus ................ (")); *(uint32_t *)pv = pVirtio->uDeviceStatus; virtioLogDeviceStatus(pVirtio->uDeviceStatus); - Log3((")\n")); + Log6((")\n")); } } @@ -764,5 +764,5 @@ { ++pVirtio->uConfigGeneration; - Log3Func(("Bumped cfg. generation to %d because %s%s\n", + Log6Func(("Bumped cfg. generation to %d because %s%s\n", pVirtio->uConfigGeneration, fDevSpecificFieldChanged ? " " : "", @@ -781,5 +781,5 @@ { *(uint8_t *)pv = pVirtio->uISR; - Log3Func(("Read and clear ISR\n")); + Log6Func(("Read and clear ISR\n")); pVirtio->uISR = 0; /** VirtIO specification requires reads of ISR to clear it */ virtioLowerInterrupt(pVirtio); @@ -832,5 +832,5 @@ { pVirtio->uISR = *(uint8_t *)pv; - Log3Func(("Setting uISR = 0x%02x (virtq interrupt: %d, dev confg interrupt: %d)\n", + Log6Func(("Setting uISR = 0x%02x (virtq interrupt: %d, dev confg interrupt: %d)\n", pVirtio->uISR & 0xff, pVirtio->uISR & VIRTIO_ISR_VIRTQ_INTERRUPT, @@ -1045,5 +1045,4 @@ int rc = VINF_SUCCESS; - PVIRTIOSTATE pVirtio = (PVIRTIOSTATE)RTMemAllocZ(sizeof(VIRTIOSTATE)); @@ -1463,4 +1462,43 @@ } + /** + * Do a hex dump of a buffer. + * + * @param pv Pointer to array to dump + * @param cb Number of characters to dump + * @param uBase Base address of offset addresses displayed + * @param pszTitle Header line/title for the dump + * + */ + void virtioHexDump(uint8_t *pv, size_t cb, uint32_t uBase, const char *pszTitle) + { + if (pszTitle) + Log(("%s [%d bytes]:\n", pszTitle, cb)); + for (uint32_t row = 0; row < RT_MAX(1, (cb / 16) + 1); row++) + { + uint32_t uAddr = row * 16 + uBase; + Log(("%x%x%x%x: ", (uAddr >> 12) & 0xf, (uAddr >> 8) & 0xf, (uAddr >> 4) & 0xf, uAddr & 0xf)); + for (int col = 0; col < 16; col++) + { + uint32_t idx = row * 16 + col; + uint8_t u8 = pv[idx]; + if (idx >= cb) + Log(("-- %s", (col + 1) % 8 ? "" : " ")); + else + Log(("%x%x %s", u8 >> 4 & 0xf, u8 & 0xf, (col + 1) % 8 ? "" : " ")); + } + for (int col = 0; col < 16; col++) + { + uint32_t idx = row * 16 + col; + uint8_t u8 = pv[idx]; + if (idx >= cb) + Log((" ")); + else + Log(("%c", u8 >= 0x20 && u8 <= 0x7e ? u8 : '.')); + } + Log(("\n")); + } + Log(("\n")); + } #endif /* IN_RING3 */ Index: /trunk/src/VBox/Devices/VirtIO/Virtio_1_0.h =================================================================== --- /trunk/src/VBox/Devices/VirtIO/Virtio_1_0.h (revision 80595) +++ /trunk/src/VBox/Devices/VirtIO/Virtio_1_0.h (revision 80596) @@ -41,4 +41,10 @@ #define VIRTIOSCSI_REGION_PORT_IO 1 /**< BAR for PORT I/O (impl specific) */ #define VIRTIOSCSI_REGION_PCI_CAP 2 /**< BAR for VirtIO Cap. MMIO (impl specific) */ + +#define VIRTIO_HEX_DUMP(logLevel, pv, cb, base, title) \ + do { \ + if (LogIsItEnabled(logLevel, LOG_GROUP)) \ + virtioHexDump((pv), (cb), (base), (title)); \ + } while (0) /** @@ -320,4 +326,15 @@ bool fWrite, bool fHasIndex, uint32_t idx); +/** + * Does a formatted hex dump using Log(()), recommend using VIRTIO_HEX_DUMP() macro to + * control enabling of logging efficiently. + * + * @param pv - pointer to buffer to dump contents of + * @param cb - count of characters to dump from buffer + * @param uBase - base address of per-row address prefixing of hex output + * @param pszTitle - Optional title. If present displays title that lists + * provided text with value of cb to indicate size next to it. + */ +void virtioHexDump(uint8_t *pv, size_t cb, uint32_t uBase, const char *pszTitle); #endif /* !VBOX_INCLUDED_SRC_VirtIO_Virtio_1_0_h */ Index: /trunk/src/VBox/Devices/VirtIO/Virtio_1_0_impl.h =================================================================== --- /trunk/src/VBox/Devices/VirtIO/Virtio_1_0_impl.h (revision 80595) +++ /trunk/src/VBox/Devices/VirtIO/Virtio_1_0_impl.h (revision 80596) @@ -409,5 +409,4 @@ pVirtio->pGcPhysQueueAvail[qIdx] + RT_UOFFSETOF(VIRTQ_AVAIL_T, uIdx), &uIdx, sizeof(uIdx)); - Log3Func(("%s actual avail_idx=%d\n", pVirtio->virtqProxy[qIdx].szVirtqName, uIdx)); return uIdx; } @@ -512,20 +511,20 @@ { if (status == 0) - Log3(("RESET")); + Log6(("RESET")); else { int primed = 0; if (status & VIRTIO_STATUS_ACKNOWLEDGE) - Log3(("ACKNOWLEDGE", primed++)); + Log6(("ACKNOWLEDGE", primed++)); if (status & VIRTIO_STATUS_DRIVER) - Log3(("%sDRIVER", primed++ ? " | " : "")); + Log6(("%sDRIVER", primed++ ? " | " : "")); if (status & VIRTIO_STATUS_FEATURES_OK) - Log3(("%sFEATURES_OK", primed++ ? " | " : "")); + Log6(("%sFEATURES_OK", primed++ ? " | " : "")); if (status & VIRTIO_STATUS_DRIVER_OK) - Log3(("%sDRIVER_OK", primed++ ? " | " : "")); + Log6(("%sDRIVER_OK", primed++ ? " | " : "")); if (status & VIRTIO_STATUS_FAILED) - Log3(("%sFAILED", primed++ ? " | " : "")); + Log6(("%sFAILED", primed++ ? " | " : "")); if (status & VIRTIO_STATUS_DEVICE_NEEDS_RESET) - Log3(("%sNEEDS_RESET", primed++ ? " | " : "")); + Log6(("%sNEEDS_RESET", primed++ ? " | " : "")); } }