usbser.sys: ReadFile reads 0 bytes

[faghio]

Hello everybody,

I am having trouble making Windows API ReadFile function working
properly with USB CDC (Communication Device Class) driver.
Specifically, I am using CDC drivers supplied with Windows XP:
usbser.sys 5.1.2600.5512
serenum.sys 5.1.2600.5512

In the sample code below, the first ReadFile in the loop (marked with (*))
sometimes exit with success and 0 bytes read (only after timeout elapses)
and then the subsequent ReadFile gets all the bytes correctly (9 bytes in
my test).
So this piece of software is working correctly and getting all responses to
sent serial commands, but sometimes there are timeout delays for the first
ReadFile going wrong and I want to avoid these.

Note that the second ReadFile is always working fine (no "(2) Read"
error).

I tried to tune the delay in the answering device between the first
character received and the response transmission, founding that there is
a peak of faulty ReadFiles at about 70 microseconds of delay (460 every
1,000,000 tests), while this number is going to about 50 per million at
minimum delay, and to zero per million (all OK) above 250 microseconds.

If I try to use some CDC demo driver found in the net (alternative to
usbser.sys), the faulty ReadFiles number is dramatically reduced, however
not null, being 1 per million with a 70 microseconds delay.

The device is using bulk mode with 512 bytes buffer (transmission is forced
after the last byte if the number of bytes is less than 512, like in my
test).

Have anyone already dealt with this problem?
Any solution other than waiting more than 250 microseconds before
answering?
Other ideas?

Thank you very much in advance.


//---------------------------------------------------------------------------

#include <windows.h>
#include <iostream.h>
#include <iomanip.h>
#include <string.h>

#pragma hdrstop

//---------------------------------------------------------------------------

int main()
{
   HANDLE         hSerial;
   DWORD         dwError;
   DCB            dcbSerialParams = {0};
   COMMTIMEOUTS   timeouts = {0};
   char         szRead[101] = {0};
   char         szWrite[101] = {0};
   DWORD         dwBytesToRead = 0;
   DWORD         dwBytesRead = 0;
   DWORD         dwBytesLeft = 0;
   DWORD         dwBytesToWrite = 0;
   DWORD         dwBytesWritten = 0;
   unsigned long   uTestIdx;
   unsigned long   uTestNum;
   unsigned long   uErrorNum;
   SYSTEMTIME      lt;
   char         sCOMport[7] = {0};
   char         sCOMportIdx[4] = {0};

   cout << "--- Test ReadFile ---" << endl;

   cout << "Enter COM port index: ";
   cin >> sCOMportIdx;
   if (sCOMportIdx == NULL)
   {
      cout << "Please specify a COM port." << endl;
      return -1;
   }
   sprintf(sCOMport, "COM%s", sCOMportIdx);

   cout << "Enter string to send (<CR> will be appended): ";
   cin >> szWrite;
   strcat(szWrite, "\015");
   dwBytesToWrite = strlen(szWrite);

   cout << "Enter bytes to read: ";
   cin >> dwBytesToRead;

   cout << "Enter number of tests: ";
   cin >> uTestNum;

   hSerial = CreateFile   (   sCOMport,
                        GENERIC_READ | GENERIC_WRITE,
                        0,
                        0,
                        OPEN_EXISTING,
                        FILE_ATTRIBUTE_NORMAL,
                        0   );

   if (hSerial == INVALID_HANDLE_VALUE)
   {
      dwError = GetLastError();
      if (dwError == ERROR_FILE_NOT_FOUND)
         cout << "Serial port " << sCOMport << " does not exist." << endl;
      else
         cout << "Error " << dwError;
      return -1;
   }

   cout << "Port open." << endl;

   dcbSerialParams.DCBlength = sizeof(dcbSerialParams);
   if (!GetCommState(hSerial, &dcbSerialParams))
         cout << "Error getting serial port state." << endl;
   dcbSerialParams.BaudRate = CBR_115200;
   dcbSerialParams.ByteSize = 8;
   dcbSerialParams.StopBits = ONESTOPBIT;
   dcbSerialParams.Parity = EVENPARITY;
   if (!SetCommState(hSerial, &dcbSerialParams))
         cout << "Error setting serial port state." << endl;

   timeouts.ReadIntervalTimeout = 0;
   timeouts.ReadTotalTimeoutMultiplier = 1;
   timeouts.ReadTotalTimeoutConstant = 350;
   timeouts.WriteTotalTimeoutConstant = 0;
   timeouts.WriteTotalTimeoutMultiplier = 0;
   if   (!SetCommTimeouts(hSerial, &timeouts))
         cout << "Error setting serial port timeouts." << endl;

   GetLocalTime(&lt);
   cout << "Time = " << setw(2) << setfill('0') << lt.wHour << ":" << setw(2) << setfill('0') <<  lt.wMinute << ":" << setw(2) << setfill('0') << lt.wSecond << endl;

   for (uTestIdx = 0, uErrorNum = 0; uTestIdx < uTestNum; uTestIdx++)
   {
      if (!WriteFile(hSerial, szWrite, dwBytesToWrite, &dwBytesWritten, NULL))
         cout << "WriteFile error " << GetLastError() << endl;

      if (!ReadFile(hSerial, szRead, dwBytesToRead, &dwBytesRead, NULL))            // (*) ReadFile success with 0 bytes read
         cout << "ReadFile error " << GetLastError() << endl;
      else
      {
         if (dwBytesRead < dwBytesToRead)
         {
            cout << "Error " << setw(10) << setfill(' ') << (++uErrorNum) << " - Read " << dwBytesRead << " bytes = "
               << ((dwBytesRead != 0) ? szRead : "")  << endl;
            dwBytesLeft = dwBytesToRead - dwBytesRead;
            if (!ReadFile(hSerial, szRead, dwBytesLeft, &dwBytesRead, NULL))
               cout << "ReadFile error " << GetLastError() << endl;
            if (dwBytesRead != dwBytesLeft)
               cout << "Error " << setw(10) << setfill(' ') << (++uErrorNum) << " - (2) Read " << dwBytesRead << " bytes = "
                  << ((dwBytesRead != 0) ? szRead : "") << endl;
         }
      }
   }
      
   GetLocalTime(&lt);
   cout << "Time = " << setw(2) << setfill('0') << lt.wHour << ":" << setw(2) << setfill('0') <<  lt.wMinute << ":" << setw(2) << setfill('0') << lt.wSecond << endl;

   CloseHandle(hSerial);
   
   cout << "Port closed." << endl;

   return 0;
}
//---------------------------------------------------------------------------

[Jan Axelson]

The host is sending data and reading responses from the device? And for each round of send/receive, the first request to read data sometimes times out? What does the device do on receiving the first IN token packet requesting data? Does it return NAKs until ready to return data? How long before the response is ready?

Jan

[faghio]

The host is sending data and reading responses from the device?
Yes, there is a command like "ABCDE<CR>" and a unique response like "012345678<CR>"
 And for each round of send/receive, the first request to read data sometimes times out?
Yes, it times out after 350 ms, with 0 bytes read (dwBytesRead = 0), but success (ReadFile = true). The following ReadFile (9 lines below) returnes correctly with the "012345678<CR>" response, however I would like not to waste 350 ms for nothing
What does the device do on receiving the first IN token packet requesting data? Does it return NAKs until ready to return data?
The only response is "012345678<CR>" sent once after the <CR> of "ABCDE<CR>"
How long before the response is ready?
I tried to artificially modify the delay between "A" of "ABCDE<CR>" and <CR> of "012345678<CR>" and found that the faulty ReadFiles have a peak when this delay is 70 us, while all ReadFiles go right if I modify the delay above 250 us

After posting, I found a way to avoid the problem by making a non-blocking ReadFile in the following way:

BOOL WINAPI ReadFileFix(
  HANDLE hFile,
  LPVOID lpBuffer,
  DWORD nNumberOfBytesToRead,
  LPDWORD lpNumberOfBytesRead,
  LPOVERLAPPED lpOverlapped
)
{
   DWORD   dwStartTime;
   BOOL   bRetVal;
   DWORD   dwTotalBytesRead = 0;
   DWORD   dwPartialBytesRead;

   dwStartTime = GetTickCount();

   do
   {
      dwPartialBytesRead = 0;
      bRetVal = ReadFile(hFile, (LPVOID)((char *) lpBuffer + dwTotalBytesRead), nNumberOfBytesToRead - dwPartialBytesRead, &dwPartialBytesRead, lpOverlapped);
      dwTotalBytesRead += dwPartialBytesRead;
      if (!bRetVal)
         break;
      if (dwTotalBytesRead == nNumberOfBytesToRead)
         break;
   } while (GetTickCount() - dwStartTime < 350);

   *lpNumberOfBytesRead = dwTotalBytesRead;

   return bRetVal;
}

after modifying timeouts like this:

   timeouts.ReadIntervalTimeout = MAXDWORD;      // was 0;
   timeouts.ReadTotalTimeoutMultiplier = 0;      // was 1;
   timeouts.ReadTotalTimeoutConstant = 0;      // was 350;

However it would be better to know why the problem is taking place with the first version.

[mdlayt]

I've seen a similar problem.  Simply put, often, after connecting, the first read from the USB device returns nothing.

So far I'm in an engineering setting, and I just try again.  This seems to always work.  So a somewhat reliable workaround is to make sure that the first communication with the device is just a "ping" and ping it until you get a response.  Then do "real" communication.

I don't think our driver guys have seen anything like this, but of course, that is very different code.