Hello All, I am writing streaming driver which i think is taking too much time to respond of any synchronous request. I want to know how much time actually it took to process it further from executing the processing till return to APP.I am using simple DebugPrint msgs in my driver.Does Windows support any such function which i can use for this purpose?
Also i am setting timeouts for these IO but that does not return in that specific time.
Following is the code for IOCTLs code: (sorry for not trimming it up)
FTMDBG is just a macro for DbgPrint();
VOID
FTMEvtIoDeviceControl(
WDFQUEUE Queue,
WDFREQUEST Request,
size_t OutputBufferLength,
size_t InputBufferLength,
ULONG IoControlCode
)
{
NTSTATUS status = STATUS_SUCCESS;
WDFDEVICE device = WdfIoQueueGetDevice(Queue);
PBTFTM_DEVICE_CONTEXT deviceContext;
WDF_REQUEST_SEND_OPTIONS wdfOptions;
WDF_MEMORY_DESCRIPTOR wdfMemoryDescriptorIn, *tmpIn, *tmpOut;
WDF_MEMORY_DESCRIPTOR wdfMemoryDescriptorOut;
ULONG_PTR bytesReturned = 0;
size_t BufferSize = 0;
WDFMEMORY INreqMemory = NULL,OUTreqMemory = NULL;
WDFMEMORY TotalMem;
UCHAR *pInData;
PUCHAR pOutdata = NULL;
#ifdef DEBUG_FTM
UINT32 i= 0;
#endif
FTMDBG((“FTM::FTMEvtIoDeviceControl++\n”));
ASSERT(device != NULL);
deviceContext = GetDeviceContext(device);
ASSERT(deviceContext != NULL);
WDF_REQUEST_SEND_OPTIONS_INIT(&wdfOptions, WDF_REQUEST_SEND_OPTION_SYNCHRONOUS);
switch (IoControlCode)
{
case IOCTL_BTFTM_SOC_INIT:
break;
case IOCTL_BTFTM_HCI_OPEN:
FTMDBG((“ftmdriver.SYS: IOCTL_BTFTM_HCI_OPEN\n”));
if (!NT_SUCCESS(status)) {
DbgPrint(“ftmdriver.SYS: IOCTL IOCTL_BTFTM_HCI_OPEN Failed\n”);
}
break;
case IOCTL_BTFTM_HCI_CLOSE:
break;
case IOCTL_BTFTM_HCI_READ:
{
//#ifdef DEBUG_FTM
UINT32 j= 0;
//#endif
FTMDBG((“btftmdriver.SYS:IOCTL_BTFTM_HCI_READ :OutBufferlngth=%d and InputBufferlength=%d\n”,OutputBufferLength , InputBufferLength));
WDF_REQUEST_SEND_OPTIONS_SET_TIMEOUT(&wdfOptions, WDF_REL_TIMEOUT_IN_SEC(MAX_FTM_READ_TIMEOUT_IN_SEC));
// Get Input memory.
status = WdfRequestRetrieveInputMemory(Request,&INreqMemory);
if(!NT_SUCCESS(status)){
goto Exit;
}
pInData = (UCHAR*)WdfMemoryGetBuffer(INreqMemory, &BufferSize);
if (pInData == NULL)
{
DbgPrint(“btftmdriver.sys READ IOCTL:WdfMemoryGetBuffer of Input buffer returned NULL\n”);
goto Exit;
}
FTMDBG((“btftmdriver.sys :READ IOCTL :WdfMemoryGetBuffer of Input buffer returned BufferSize = %d\n”, BufferSize));
// Get Output memory.
status = WdfRequestRetrieveOutputMemory(Request,&OUTreqMemory);
if(!NT_SUCCESS(status)){
goto Exit;
}
pOutdata = (UCHAR*)WdfMemoryGetBuffer(OUTreqMemory, &BufferSize);
if (pOutdata == NULL)
{
DbgPrint(“ftmdriver.sys:READ IOCTL :WdfMemoryGetBuffer of Output buffer returned NULL\n”);
goto Exit;
}
FTMDBG((“ftmdriver.sys :READ IOCTL :WdfMemoryGetBuffer of Output buffer returned BufferSize = %d and addres=%X\n”, BufferSize,pOutdata));
//initialize the Input buffer Descriptor
WDF_MEMORY_DESCRIPTOR_INIT_BUFFER(&wdfMemoryDescriptorIn,
pInData,
InputBufferLength);
if((InputBufferLength == 0) || (pInData == NULL)) {
tmpIn = NULL;
DbgPrint(“btftmdriver.SYS :READ_IOCTL:Error: input descriptor is NULL\n”);
}else {
tmpIn = &wdfMemoryDescriptorIn;
}
//initialize the Output buffer Descriptor
WDF_MEMORY_DESCRIPTOR_INIT_BUFFER(&wdfMemoryDescriptorOut,
pOutdata,
OutputBufferLength);
if((OutputBufferLength == 0) || (pOutdata == NULL)) {
tmpOut = NULL;
DbgPrint(“btftmdriver.SYS :READ_IOCTL:Error: Output descriptor is NULL\n”);
}else {
tmpOut = &wdfMemoryDescriptorOut;
}
status = WdfIoTargetSendIoctlSynchronously(deviceContext->ioTarget,
NULL,
IOCTL_BTHX_READ_HCI,
tmpIn, // InputBuffer
tmpOut, // OutputBuffer
&wdfOptions, // RequestOptions
&bytesReturned // BytesReturned
);
//#ifdef DEBUG_FTM
DbgPrint(“ftmdriver.sys: Read IOCTL: bytes Returned = %d\n”, bytesReturned);
FTMDBG((“ftmdriver.sys: Read IOCTL: bytes Returned = %d\n”, bytesReturned)) ;
for(j= 0 ; j {
DbgPrint("*******ftmdriver.sys: Read IOCTL: Byte[%d] = %X\n",j,pOutdata[j]);
}
//#endif
break;
}
case IOCTL_BTFTM_HCI_WRITE:
{
DWORD j= 0;
PBTHX_HCI_READ_WRITE_CONTEXT pHCIContextIn = NULL;
PBTHX_HCI_READ_WRITE_CONTEXT pftm1;
DbgPrint(“ftmdriver.sys :Write IOCTL :Write IOCTL :Length of Inputput buffer = %d\n”, InputBufferLength);
FTMDBG((“ftmdriver.sys :Write IOCTL :Write IOCTL :Length of Inputput buffer = %d\n”, InputBufferLength));
FTMDBG((“ftmdriver.sys :Write IOCTL :Length of Output buffer = %d\n”, OutputBufferLength));
WDF_REQUEST_SEND_OPTIONS_SET_TIMEOUT(&wdfOptions, WDF_REL_TIMEOUT_IN_SEC(MAX_FTM_WRITE_TIMEOUT_IN_SEC));
//Get Output memory
CHECK_STATUS_EXIT(WdfRequestRetrieveOutputMemory(Request,&OUTreqMemory));
CHECK_NULL(pOutdata = (UCHAR)WdfMemoryGetBuffer(OUTreqMemory, &BufferSize));
FTMDBG((“ftmdriver.sys :Write IOCTL :WdfMemoryGetBuffer of Output buffer returned BufferSize = %d\n”, BufferSize));
// Get input memory.
CHECK_STATUS_EXIT(WdfRequestRetrieveInputMemory(Request,&INreqMemory));
CHECK_NULL(pInData = (UCHAR)WdfMemoryGetBuffer(INreqMemory, &BufferSize));
FTMDBG((“ftmdriver.sys :Write IOCTL:WdfMemoryGetBuffer of Input buffer returned BufferSize = %d\n”, BufferSize));
#ifdef DEBUG_FTM
for(i= 0; i< (BufferSize) ; i++){
DbgPrint(“ftmdriver.sys :Bytes of Input buffer from app = %X\n”, pInData[i]);
}
#endif
//TODO : Re use the created buffer by creating the buffers in deviceadd
//Create the Memory required for packet
CHECK_STATUS_EXIT(WdfMemoryCreate(
NULL,
NonPagedPool,
0,
(sizeof(BTHX_HCI_READ_WRITE_CONTEXT)+InputBufferLength), //size in bytes
&TotalMem,
NULL));
//Get the context of the Memory handle
CHECK_NULL(pHCIContextIn = (PBTHX_HCI_READ_WRITE_CONTEXT) WdfMemoryGetBuffer(TotalMem, &BufferSize));
FTMDBG((“ftmdriver.sys :Write IOCTL:Length of Final buffer = %d\n”, BufferSize));
if(BufferSize != 0) {
// Transfer data to Request’s output buffer
pHCIContextIn->Type = HciPacketCommand;
pHCIContextIn->DataLen = InputBufferLength;
RtlCopyMemory(&pHCIContextIn->Data, pInData, InputBufferLength);
FTMDBG((“ftmdriver.sys:Write IOCTL : Address of Final buffer->data = %d\n”, &pHCIContextIn->Data));
}
#ifdef DEBUG_FTM
for(i = 0 ; i {
DbgPrint(“*****ftmdriver.SyS : pHCIContext->Data[%d] = %x\n”,i, pHCIContextIn->Data[i]);
}
#endif
//INIT INPUT BUFFER
WDF_MEMORY_DESCRIPTOR_INIT_BUFFER(&wdfMemoryDescriptorIn,
pHCIContextIn,
(sizeof(BTHX_HCI_READ_WRITE_CONTEXT)+InputBufferLength));
if((InputBufferLength == 0) || (pHCIContextIn == NULL)) {
tmpIn = NULL;
DbgPrint(“ftmdriver.SyS : Write IOCTL:ERROR: Input descriptor value is NULL\n”);
}else {
tmpIn = &wdfMemoryDescriptorIn;
}
//INIT OUTPUT BUFFER
WDF_MEMORY_DESCRIPTOR_INIT_BUFFER(&wdfMemoryDescriptorOut,
pOutdata,
OutputBufferLength);
if((OutputBufferLength == 0) || (pOutdata == NULL)) {
tmpOut = NULL;
DbgPrint(“ftmdriver.SyS : Write IOCTL:ERROR: output descriptor value is NULL\n”);
}else {
tmpOut = &wdfMemoryDescriptorOut;
}
pftm1 = (PBTHX_HCI_READ_WRITE_CONTEXT)(tmpIn->u.BufferType.Buffer);
DbgPrint(“ftmdriver.SyS : Bytes to write=\n”);
for(j= 0 ;j<(sizeof(BTHX_HCI_READ_WRITE_CONTEXT)+InputBufferLength);j++)
{
DbgPrint(" ftmdriver.SyS **** : Bytes to write=0x%X\n",(pftm1+j) );
}
CHECK_STATUS_EXIT(WdfIoTargetSendIoctlSynchronously(deviceContext->ioTarget,
NULL,
IOCTL_BTHX_WRITE_HCI,
tmpIn, // InputBuffer
tmpOut, // OutputBuffer
&wdfOptions, // RequestOptions
&bytesReturned // BytesReturned
));
FTMDBG((“ftmdriver.sys: Write IOCTL :bytes returned=%d\n”, bytesReturned)) ;
#ifdef DEBUG_FTM
for(i = 0; i {
DbgPrint(“ftmdriver.sys: bytes returned[%d]=%x\n”, i, pOutdata[i]) ;
}
#endif
if(TotalMem){
WdfObjectDelete(TotalMem);
}
break;
}
case IOCTL_BTFTM_PIN_CONNECTIVITY:
DbgPrint(“btftmdriver::Not implemented at present\n”);
break;
default:
DbgPrint(“btftmdriver::Error:unknown IOCTL\n”);
break;
}
Exit:
//Delete common objects
WdfObjectDelete(INreqMemory);
WdfObjectDelete(OUTreqMemory);
WdfRequestCompleteWithInformation(Request,
status,
bytesReturned);
FTMDBG((“FTM::FTMEvtIoDeviceControl–\n”));
return; // no pending ops, return status
}
Thanks,
Ajay