SerialPort.BaseStream.ReadAsync drops or scrambles bytes when reading from a USB Serial Port
Edit: I've added the sending code and an example of the received output I'm getting.
I am reading data from a USB "virtual" serial port connected to an embedded system. I have written two methods for receiving the data, one synchronous and one asynchronous. The synchronous one works, and the asynchronous one loses or scrambles a little bit of the incoming data. I cannot tell why the second one fails.
The method that works calls SerialPort.Read with a read timeout set to zero, and it requests everything in the receive buffer. I check the return value to see how many bytes were actually read and then put the data into a circular buffer for use elsewhere. This method is called by a timer interrupt, and it works perfectly to receive serial data (typically at rates above 1.6 Mbps with no data loss). However, the polling timer has become a problem for me and I would prefer to receive the data asynchronously wrt the rest of my code.
The method that loses data awaits ReadAsync on the serial port BaseStream and loops until cancelled. This approach sort of works, but it often returns the leading byte of a packet out of order, loses a single byte fairly frequently (approximately once every few thousand data bytes), and occasionally loses hundreds of sequential bytes from a packet.
It is possible that there are two completely different problems here, because the loss of larger chunks of data loss seem to be correlated with higher data rates and heavier system activity. That particular part of the problem could potentially be due to buffer overruns -- perhaps through a failure of USB handshaking when the USB scheduler encounters a delay -- but the example I am showing here has only a very small amount of data being transferred at 50 msec intervals, and the system is idle except for this test routine.
I have observed that ReadAsync frequently returns the first byte of a packet on one read, and the remainder of the packet on the next read. I believe this is expected behavior because MSDN says that if no data is available for some period of time, ReadAsync will return with the first byte it receives. However, I think this behavior is somehow related to my problem because when a single byte is missing or out of order, it is "always" that first byte, with the rest of the packet arriving normally.
When the packets are small, the "missing" byte from the front of the packet often (but not always) appears to be delivered in the next read after the remainder of the packet, and this just makes absolutely no sense to me. With larger packets this still happens occasionally, but more often the first byte is just missing when the packets are large.
I've searched far and wide, and have read every SO question I could find on this topic. I found other people with what appears to be a similar problem (ex: SerialPort.BaseStream.ReadAsync missing the first byte), but nobody with any accepted or even plausible solutions.
Ben Voigt (http://www.sparxeng.com/blog/software/must-use-net-system-io-ports-serialport) and others who really seem to know serial comms have recommended the use of ReadAsync on the basestream, and Microsoft's IOT team has also recommended this approach, so I have to believe the approach should work.
Question 1: Why is my code using ReadAsync on a USB Serial BaseStream dropping /scrambling bytes?
Question 2: If ReadAsync cannot be made to reliably return all the bytes received bytes in the correct order, can I just put an async wrapper around the traditional SerialPort.Read and await / loop it so I don't have to poll from a timer? I've read that this is a bad idea, but I've also read that the SerialPort class is internally asynchronous, so perhaps that makes it OK? Or is my only alternative to put this on a worker thread and just let it spend all its time waiting?
My code is below. I have set serialPort1.ReadTimeout = 0; and serialPort1.BaseStream.ReadTimeout = 0; (and I have tried other durations).
I have enabled RTS and DTR, and since this is a USB_serial port it should handle handshake internally, and it certainly appears to do so when I read synchronously -- but perhaps that's not true when I read from the BaseStream?
Here is the first method:
// this method works perfectly when called from a timer.
// SerialPort.ReadTimeout must be set to zero for this to work.
// It handles incoming bytes reliably at rates above 1.6 Mbps.
private void ReadSerialBytes()
{
if (!serialPort1.IsOpen)
return;
if (serialPort1.BytesToRead > 0)
{
var receiveBuffer = new byte[serialPort1.ReadBufferSize];
var numBytesRead = serialPort1.Read(receiveBuffer, 0, serialPort1.ReadBufferSize);
var bytesReceived = new byte[numBytesRead];
Array.Copy(receiveBuffer, bytesReceived, numBytesRead);
// Here is where I audit the received data.
// the NewSerialData event handler displays the
// data received (as hex bytes) and writes it to disk.
RaiseEventNewSerialData(bytesReceived);
// serialInBuffer is a "thread-safe" global circular byte buffer
// The data in serialInBuffer matches the data audited above.
serialInBuffer.Enqueue(bytesReceived, 0, numBytesRead);
}
}
Here is the second method, Edited to remove the tail recursion noted by @Lucero. Now I won't run out of memory :) but the original data loss problem, of course, remains.
// This method is called once after the serial port is opened,
// and it repeats until cancelled.
//
// This code "works" but periodically drops the first byte of a packet,
// or returns that byte in the wrong order.
// It occasionally drops several hundred bytes in a row.
private async Task ReadSerialBytesAsync(CancellationToken ct)
{
while((!ct.IsCancellationRequested) && (serialPort1.IsOpen))
{
try
{
serialPort1.BaseStream.ReadTimeout = 0;
var bytesToRead = 1024;
var receiveBuffer = new byte[bytesToRead];
var numBytesRead = await serialPort1.BaseStream.ReadAsync(receiveBuffer, 0, bytesToRead, ct);
var bytesReceived = new byte[numBytesRead];
Array.Copy(receiveBuffer, bytesReceived, numBytesRead);
// Here is where I audit the received data.
// the NewSerialData event handler displays the
// data received (as hex bytes) and writes it to disk.
RaiseEventNewSerialData(bytesReceived);
// serialInBuffer is a "thread-safe" global circular byte buffer
// The data in serialInBuffer matches the data audited above.
serialInBuffer.Enqueue(receiveBuffer, 0, numBytesRead);
}
catch (Exception ex)
{
MessageBox.Show("Error in ReadSerialBytesAsync: " + ex.ToString());
throw;
}
}
}
Here is C++ code from the sending system (teensy 3.2 with an ARM chip). It sends a sequence of bytes from 00 through FF, repeated every 50 msec.
void SendTestData()
{
byte asyncTestBuffer[256] = { 0 };
for (int i = 0; i < 256; i++)
asyncTestBuffer[i] = i;
while(true)
{
Serial.write(asyncTestBuffer, sizeof(asyncTestBuffer));
delay(50);
}
}
The traditional synchronous SerialPort.Read (called from a timer) receives each block completely exactly as expected, with no data loss. It looks like this, over and over:
=====
32 msec => Received 256 bytes
000102030405060708090A0B0C0D0E0F101112131415161718191A1B1C1D1E1F202122232425262728292A2B2C2D2E2F303132333435363738393A3B3C3D3E3F404142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F808182838485868788898A8B8C8D8E8F909192939495969798999A9B9C9D9E9FA0A1A2A3A4A5A6A7A8A9AAABACADAEAFB0B1B2B3B4B5B6B7B8B9BABBBCBDBEBFC0C1C2C3C4C5C6C7C8C9CACBCCCDCECFD0D1D2D3D4D5D6D7D8D9DADBDCDDDEDFE0E1E2E3E4E5E6E7E8E9EAEBECEDEEEFF0F1F2F3F4F5F6F7F8F9FAFBFCFDFEFF
=====
Now here is what SerialPort.BaseStream.ReadAsync receives. In another version I appended a terminal packet sequence number to prove that when I see a zero followed by another zero, there's not really an entire missing packet between them. Packet sequence numbers were all present, so the leading byte really does seem to be missing or delivered out of order.
7 msec => Received 255 bytes
0102030405060708090A0B0C0D0E0F101112131415161718191A1B1C1D1E1F202122232425262728292A2B2C2D2E2F303132333435363738393A3B3C3D3E3F404142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F808182838485868788898A8B8C8D8E8F909192939495969798999A9B9C9D9E9FA0A1A2A3A4A5A6A7A8A9AAABACADAEAFB0B1B2B3B4B5B6B7B8B9BABBBCBDBEBFC0C1C2C3C4C5C6C7C8C9CACBCCCDCECFD0D1D2D3D4D5D6D7D8D9DADBDCDDDEDFE0E1E2E3E4E5E6E7E8E9EAEBECEDEEEFF0F1F2F3F4F5F6F7F8F9FAFBFCFDFEFF
=====
5 msec => Received 1 bytes
00
=====
55 msec => Received 1 bytes
00
=====
4 msec => Received 255 bytes
0102030405060708090A0B0C0D0E0F101112131415161718191A1B1C1D1E1F202122232425262728292A2B2C2D2E2F303132333435363738393A3B3C3D3E3F404142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F808182838485868788898A8B8C8D8E8F909192939495969798999A9B9C9D9E9FA0A1A2A3A4A5A6A7A8A9AAABACADAEAFB0B1B2B3B4B5B6B7B8B9BABBBCBDBEBFC0C1C2C3C4C5C6C7C8C9CACBCCCDCECFD0D1D2D3D4D5D6D7D8D9DADBDCDDDEDFE0E1E2E3E4E5E6E7E8E9EAEBECEDEEEFF0F1F2F3F4F5F6F7F8F9FAFBFCFDFEFF
=====
42 msec => Received 1 bytes
00
=====
5 msec => Received 255 bytes
0102030405060708090A0B0C0D0E0F101112131415161718191A1B1C1D1E1F202122232425262728292A2B2C2D2E2F303132333435363738393A3B3C3D3E3F404142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F808182838485868788898A8B8C8D8E8F909192939495969798999A9B9C9D9E9FA0A1A2A3A4A5A6A7A8A9AAABACADAEAFB0B1B2B3B4B5B6B7B8B9BABBBCBDBEBFC0C1C2C3C4C5C6C7C8C9CACBCCCDCECFD0D1D2D3D4D5D6D7D8D9DADBDCDDDEDFE0E1E2E3E4E5E6E7E8E9EAEBECEDEEEFF0F1F2F3F4F5F6F7F8F9FAFBFCFDFEFF
=====
68 msec => Received 1 bytes
00
=====
7 msec => Received 255 bytes
0102030405060708090A0B0C0D0E0F101112131415161718191A1B1C1D1E1F202122232425262728292A2B2C2D2E2F303132333435363738393A3B3C3D3E3F404142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F808182838485868788898A8B8C8D8E8F909192939495969798999A9B9C9D9E9FA0A1A2A3A4A5A6A7A8A9AAABACADAEAFB0B1B2B3B4B5B6B7B8B9BABBBCBDBEBFC0C1C2C3C4C5C6C7C8C9CACBCCCDCECFD0D1D2D3D4D5D6D7D8D9DADBDCDDDEDFE0E1E2E3E4E5E6E7E8E9EAEBECEDEEEFF0F1F2F3F4F5F6F7F8F9FAFBFCFDFEFF
=====
31 msec => Received 255 bytes
0102030405060708090A0B0C0D0E0F101112131415161718191A1B1C1D1E1F202122232425262728292A2B2C2D2E2F303132333435363738393A3B3C3D3E3F404142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F808182838485868788898A8B8C8D8E8F909192939495969798999A9B9C9D9E9FA0A1A2A3A4A5A6A7A8A9AAABACADAEAFB0B1B2B3B4B5B6B7B8B9BABBBCBDBEBFC0C1C2C3C4C5C6C7C8C9CACBCCCDCECFD0D1D2D3D4D5D6D7D8D9DADBDCDDDEDFE0E1E2E3E4E5E6E7E8E9EAEBECEDEEEFF0F1F2F3F4F5F6F7F8F9FAFBFCFDFEFF
=====
9 msec => Received 1 bytes
00
=====
33 msec => Received 1 bytes
00
=====
10 msec => Received 255 bytes
0102030405060708090A0B0C0D0E0F101112131415161718191A1B1C1D1E1F202122232425262728292A2B2C2D2E2F303132333435363738393A3B3C3D3E3F404142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F808182838485868788898A8B8C8D8E8F909192939495969798999A9B9C9D9E9FA0A1A2A3A4A5A6A7A8A9AAABACADAEAFB0B1B2B3B4B5B6B7B8B9BABBBCBDBEBFC0C1C2C3C4C5C6C7C8C9CACBCCCDCECFD0D1D2D3D4D5D6D7D8D9DADBDCDDDEDFE0E1E2E3E4E5E6E7E8E9EAEBECEDEEEFF0F1F2F3F4F5F6F7F8F9FAFBFCFDFEFF
=====
55 msec => Received 255 bytes
0102030405060708090A0B0C0D0E0F101112131415161718191A1B1C1D1E1F202122232425262728292A2B2C2D2E2F303132333435363738393A3B3C3D3E3F404142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F808182838485868788898A8B8C8D8E8F909192939495969798999A9B9C9D9E9FA0A1A2A3A4A5A6A7A8A9AAABACADAEAFB0B1B2B3B4B5B6B7B8B9BABBBCBDBEBFC0C1C2C3C4C5C6C7C8C9CACBCCCDCECFD0D1D2D3D4D5D6D7D8D9DADBDCDDDEDFE0E1E2E3E4E5E6E7E8E9EAEBECEDEEEFF0F1F2F3F4F5F6F7F8F9FAFBFCFDFEFF
=====
12 msec => Received 1 bytes
00
=====
12 msec => Received 1 bytes
00
=====
15 msec => Received 255 bytes
0102030405060708090A0B0C0D0E0F101112131415161718191A1B1C1D1E1F202122232425262728292A2B2C2D2E2F303132333435363738393A3B3C3D3E3F404142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F808182838485868788898A8B8C8D8E8F909192939495969798999A9B9C9D9E9FA0A1A2A3A4A5A6A7A8A9AAABACADAEAFB0B1B2B3B4B5B6B7B8B9BABBBCBDBEBFC0C1C2C3C4C5C6C7C8C9CACBCCCDCECFD0D1D2D3D4D5D6D7D8D9DADBDCDDDEDFE0E1E2E3E4E5E6E7E8E9EAEBECEDEEEFF0F1F2F3F4F5F6F7F8F9FAFBFCFDFEFF
=====
68 msec => Received 255 bytes
0102030405060708090A0B0C0D0E0F101112131415161718191A1B1C1D1E1F202122232425262728292A2B2C2D2E2F303132333435363738393A3B3C3D3E3F404142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F808182838485868788898A8B8C8D8E8F909192939495969798999A9B9C9D9E9FA0A1A2A3A4A5A6A7A8A9AAABACADAEAFB0B1B2B3B4B5B6B7B8B9BABBBCBDBEBFC0C1C2C3C4C5C6C7C8C9CACBCCCDCECFD0D1D2D3D4D5D6D7D8D9DADBDCDDDEDFE0E1E2E3E4E5E6E7E8E9EAEBECEDEEEFF0F1F2F3F4F5F6F7F8F9FAFBFCFDFEFF
=====
16 msec => Received 1 bytes
00
=====
14 msec => Received 256 bytes
000102030405060708090A0B0C0D0E0F101112131415161718191A1B1C1D1E1F202122232425262728292A2B2C2D2E2F303132333435363738393A3B3C3D3E3F404142434445464748494A4B4C4D4E4F505152535455565758595A5B5C5D5E5F606162636465666768696A6B6C6D6E6F707172737475767778797A7B7C7D7E7F808182838485868788898A8B8C8D8E8F909192939495969798999A9B9C9D9E9FA0A1A2A3A4A5A6A7A8A9AAABACADAEAFB0B1B2B3B4B5B6B7B8B9BABBBCBDBEBFC0C1C2C3C4C5C6C7C8C9CACBCCCDCECFD0D1D2D3D4D5D6D7D8D9DADBDCDDDEDFE0E1E2E3E4E5E6E7E8E9EAEBECEDEEEFF0F1F2F3F4F5F6F7F8F9FAFBFCFDFEFF
=====
I've spent a couple of weeks tracking down this problem, which originally manifested itself in bizarre behavior from a product under development. I am pretty sure I must be doing something wrong, but I just can't see it, and at this point I am quite desperate for any thoughts or suggestions!
Answer
I finally came up with an answer after stepping through the decompiled source code for the .Net SerialPort class (with resharper installed just Rclick on SerialPort->Navigate->Decompiled Sources).
Answer #1: The bytes out of order problem was due to an error earlier in my program. I had canceled and restarted the readAsync loop, but I was using the wrong cancellation token so there were two copies of the loop both awaiting readAsync from the serial port. Both were issuing interrupts to return the received data, but of course it was a race condition as to which one got there first.
Answer #2: Note the way I am using the synchronous read method: I don't use the Received event (which doesn't work correctly) or check the number of bytes to read (which is unreliable) or anything like that. I merely set a timeout of zero, attempt to read with a large buffer, and check how many bytes I got back.
When called in this way, the synchronous SerialPort.Read first attempts to fulfill a read request from an internal cache[1024] of data bytes received. If it still doesn't have enough data to meet the request, it then issues a ReadAsync request against the underlying BaseStream using the exact same buffer, (adjusted)offset, and (adjusted)count.
Bottom line: When used the way I am using it, the synchronous SerialPort.Read method behaves exactly like SerialPort.ReadAsync. I conclude that it would probably be fine to put an async wrapper around the synchronous method, and just await it. However, I don't need to do that now that I can read from the basestream reliably.
Update: I now reliably receive more than 3Mbps from my serial port using a Task containing a loop that continuously awaits SerialPort.Basestream.ReadAsync and adds the results to a circular buffer.