Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

WriteFileEx completion routine succeeds, but bytes transferred is incorrect

I'm communicating between two processes on different machines via a pipe, using IO completion routines.

Occasionally, when the completion routine for WriteFileEx gets called, the completion routine parameter dwErrorCode is 0 (i.e. no error), GetOverlappedResult returns true (i.e. no error), but dwNumberOfBytesTransfered does not match nNumberOfBytesToWrite in the call to WriteFileEx. I only see this on the client end of the pipe however.

If the number of bytes transferred does not match the number of bytes that was requested to transfer, how can this be deemed a success?

This is how the client's handle to the pipe is created:

mHPipe = CreateFile(pipeName,                 // pipe name 
                    GENERIC_READ |            // read and write access 
                    GENERIC_WRITE, 
                    0,                        // no sharing 
                    NULL,                     // default security attributes
                    OPEN_EXISTING,            // opens existing pipe 
                    FILE_FLAG_OVERLAPPED |    // overlapped
                    FILE_FLAG_WRITE_THROUGH,  // write through mode
                    NULL);                    // no template file 

// do some checking...

// The pipe connected; change to message-read mode. 
DWORD dwMode = PIPE_READMODE_MESSAGE; 
BOOL fSuccess = SetNamedPipeHandleState(mHPipe,   // pipe handle 
                                        &dwMode,  // new pipe mode 
                                        NULL,     // don't set maximum bytes 
                                        NULL);    // don't set maximum time 

Can anyone see why this would happen?

Thanks

EDIT:

The relevant WriteFileEx code is as follows:

void WINAPI CompletedWriteRoutine(DWORD dwErrorCode, DWORD dwNumberOfBytesTransfered, LPOVERLAPPED lpOverLap)
{
  BOOL fWrite = FALSE;
  LPPIPEINST lpPipeInst = (LPPIPEINST)lpOverLap;

  //
  // !  99.9% of the time, dwNumberOfBytesTransfered == lpPipeInst->cbDataSize
  //    but 0.1% of the time, they do not match
  //

  // Some stuff

  // Copy next message to send
  memcpy_s(lpPipeInst->chData, sizeof(lpPipeInst->chData), pMsg->msg, pMsg->size);
  lpPipeInst->cbDataSize = pMsg->size;

  // Some other stuff

  fWrite = WriteFileEx(lpPipeInst->hPipeInst,
                       lpPipeInst->chData,
                       lpPipeInst->cbDataSize,
                       (LPOVERLAPPED) lpPipeInst,
                       (LPOVERLAPPED_COMPLETION_ROUTINE)CompletedWriteRoutine);

  // Some other, other stuff
}

Where LPPIPEINST is declared as:

typedef struct 
{ 
  OVERLAPPED oOverlap;      // must remain first item
  HANDLE hPipeInst;
  TCHAR chData[BUFSIZE];
  DWORD cbDataSize;
} PIPEINST, *LPPIPEINST;

And the initial call to CompletedWriteRoutine is given the lpOverlap parameter declared thusly:

PIPEINST pipeInstWrite        = {0};
pipeInstWrite.hPipeInst       = client.getPipeHandle();
pipeInstWrite.oOverlap.hEvent = hEvent[eventWriteComplete];

EDIT:

After trying re-initializing the overlapped structure as Harry suggested, I noticed something peculiar. I memset the OVERLAPPED structure to zero before each WriteFileEx, and roughly 1/5000 completion routine callbacks, the cbWritten parameter and the OVERLAPPED structure's InternalHigh member was now set to the size of the previous message, instead of the most recent message. I added some logging to file on both the client and server ends of the pipe inside the completion routines, and the data sent and received at both ends was an exact match (and the correct, expected data). This then unveiled that in the time taken to write the data to a file, the InternalHigh member in the OVERLAPPED structure had changed to now reflect the size of the message I was expecting (cbWritten remains the old message size). I removed the file logging, and am now able to reproduce the issue like clockwork with this code:

void WINAPI CompletedWriteRoutine(DWORD dwErr, DWORD cbWritten, LPOVERLAPPED lpOverLap)
{
  LPPIPEINST lpPipeInst = (LPPIPEINST)lpOverLap;

  // Completion routine says it wrote the amount of data from the previous callback
  if (cbWritten != lpPipeInst->cbDataSize)
  {
    // Roughly 1 in 5000 callbacks ends up in here

    OVERLAPPED ovl1 = lpPipeInst->oOverlap; // Contains size of previous message, i.e. cbWritten
    Sleep(100);
    OVERLAPPED ovl2 = lpPipeInst->oOverlap; // Contains size of most recent message, i.e lpPipeInst->cbDataSize
  }
  ...
}

It seems that sometimes, the completion routine is being called before the OVERLAPPED structure and the completion routine input parameter is updated. I'm using MsgWaitForMultipleObjectsEx(eventLast, hEvent, INFINITE, QS_POSTMESSAGE, MWMO_ALERTABLE); for the completion routines to be called on Windows 7 64 bit.

This MSDN page says:

"The system does not use the OVERLAPPED structure after the completion routine is called, so the completion routine can deallocate the memory used by the overlapped structure."

...so apparently, what this code can reproduce should never happen?

Is this a WINAPI bug?

like image 388
parrowdice Avatar asked Nov 22 '12 18:11

parrowdice


1 Answers

Added FILE_FLAG_NO_BUFFERING to the CreateFile call - haven't seen the problem since. Thanks everyone who commented for your time.

like image 153
parrowdice Avatar answered Oct 23 '22 03:10

parrowdice