Reading on Windows not working in 7.1.4
Summary of Problem
- What are you trying to do? I have a LinkUSB that uses a FTDI 232 USB to Serial converter that I need to talk to on Windows. I have the program working perfectly on MacOS.
- What happens? After removing the flush() commands (which seem to be broken according to some issues here) I am not getting back any data.
- What should have happened? I should get back data.
Code to Reproduce the Issue
const SerialPort = require('serialport')
const Readline = require('@serialport/parser-readline')
const port = new SerialPort('COM3', { baudRate: 9600 })
const parser = new Readline()
port.pipe(parser)
parser.on('data', line => console.log(`> ${line}`))
console.log("write")
port.write('r\n')
reduced it to this sample. This produces following debug output
> $env:DEBUG='serialport/*'; node test.js
serialport/bindings loading WindowsBinding +0ms
serialport/stream opening path: COM3 +0ms
serialport/binding-abstract open +0ms
write
serialport/stream _read queueing _read for after open +15ms
serialport/stream opened path: COM3 +18ms
serialport/stream _write 15 bytes of data +2ms
serialport/binding-abstract write 15 bytes +35ms
serialport/stream _read reading +5ms
serialport/binding-abstract read +4ms
serialport/stream binding.write write finished +11ms
PS C:\Users\admin\Documents\sdev> $env:DEBUG='serialport/*'; node test.js
serialport/bindings loading WindowsBinding +0ms
serialport/stream opening path: COM3 +0ms
serialport/binding-abstract open +0ms
write
serialport/stream _read queueing _read for after open +14ms
serialport/stream opened path: COM3 +30ms
serialport/stream _write 2 bytes of data +3ms
serialport/binding-abstract write 2 bytes +47ms
serialport/stream _read reading +5ms
serialport/binding-abstract read +5ms
serialport/stream binding.write write finished +
When using the Arduino IDE with the serial monitor I can properly talk to the device. So drivers seem to be OK. I already digged through a lot of the issues here but I was not able to find one with that specific case.
Versions, Operating System and Hardware
- [email protected]
- Node.js v10.15.3
- Windows 10 64bit
- Hardware and chipset? FTDI
Small update. Still not working, but I see some differences. I changed my test code to:
const SerialPort = require('serialport')
const port = new SerialPort('COM3', { baudRate: 9600 })
function myClose() {
console.log(port.read(1))
port.close()
}
port.open(() => {
port.on('data', line => console.log(`> ${line}`))
port.on('error', line => console.log(`ERROR > ${line}`))
port.on('close', line => console.log(`> Close`))
console.log("write")
port.write('r\n')
port.drain((err) => {
setTimeout(myClose, 1500);
})
})
When now running it, I get:
serialport/bindings loading WindowsBinding +0ms
serialport/stream opening path: COM3 +0ms
serialport/binding-abstract open +0ms
write
serialport/stream drain +12ms
serialport/stream drain queuing on port open +1ms
serialport/stream _read queueing _read for after open +2ms
serialport/stream opened path: COM3 +27ms
serialport/stream _write 2 bytes of data +4ms
serialport/binding-abstract write 2 bytes +44ms
serialport/stream drain +4ms
serialport/binding-abstract drain +4ms
serialport/stream _read reading +3ms
serialport/binding-abstract read +6ms
serialport/stream binding.write write finished +8ms
serialport/stream binding.drain finished +3ms
null
serialport/stream #close +2s
serialport/binding-abstract close +2s
serialport/stream binding.read error { [Error: Reading from COM port (ReadIOCompletion): Operation aborted] canceled: true } +7ms
serialport/stream _read queueing _read for after open +11ms
serialport/stream binding.close finished +94ms
> Close
so no data read or anything. But then I open the serial port via putty and suddenly the expected output appears in putty. That means it is sending the data, but it is not reading the buffer in node. Funny thing then is, when I go and close putty and start the sample again, then I suddenly get an output.
serialport/bindings loading WindowsBinding +0ms
serialport/stream opening path: COM3 +0ms
serialport/binding-abstract open +0ms
write
serialport/stream drain +10ms
serialport/stream drain queuing on port open +2ms
serialport/stream _read queueing _read for after open +2ms
serialport/stream opened path: COM3 +18ms
serialport/stream _write 2 bytes of data +6ms
serialport/binding-abstract write 2 bytes +38ms
serialport/stream drain +6ms
serialport/binding-abstract drain +6ms
serialport/stream _read reading +5ms
serialport/binding-abstract read +3ms
serialport/stream binding.write write finished +7ms
serialport/stream binding.drain finished +2ms
serialport/stream binding.read finished +14ms
> P
serialport/stream _read reading +8ms
serialport/binding-abstract read +30ms
null
serialport/stream #close +1s
serialport/binding-abstract close +1s
serialport/stream binding.read error { [Error: Reading from COM port (ReadIOCompletion): Operation aborted] canceled: true } +9ms
serialport/stream _read queueing _read for after open +8ms
serialport/stream binding.close finished +108ms
> Close
When comparing then the first to the second, the first one is missing following lines:
serialport/stream binding.read finished +15ms
> P
serialport/stream _read reading +7ms
serialport/binding-abstract read +30ms
I really could use the help of somebody on this one. Thanks.
I have a similar but different issue where reads fail on Windows 10 in version 7.15. maybe related?
the debug message indicating a problem is
serialport/stream binding.read Zero bytes read closing readable stream +0ms
in the windows binding code, during initialization the comm timeouts are all 0 so the reads will block until something is read. There is one spot in NAN_METHOD(read) where the comm timeout is set to MAXDWORD which can potentially return 0 bytes. (serial_win.cpp:482) then in stream.js there is a test for 0 bytes read and the reading stops when that happens.
this is a hack, but it fixes the problem for me: line 373 stream.js version 7.15
// the actual read.
debug('_read', `reading`)
this.binding.read(pool, start, toRead).then(
bytesRead => {
debug('binding.read', `finished`)
// zero bytes means read means we've hit EOF? Maybe this should be an error
if (bytesRead === 0) {
debug('binding.read', 'Zero bytes read closing readable stream')
//this.push(null)
//return
// don't quit, instead reprime to read more
this._read(bytesToRead) // prime to read more once we're reconnected
}
else {
pool.used += bytesRead
this.push(pool.slice(start, start + bytesRead))
}
},
err => {
debug('binding.read', `error`, err)
if (!err.canceled) {
this._disconnected(err)
}
this._read(bytesToRead) // prime to read more once we're reconnected
}
)
EDIT Additional Info: in the Windows API for ReadFile with overlapped, it says in the ReadFile the lpNumberofBytesRead parameter should be NULL, but in the code (lserialport_win.cpp:497) it looks like it would be a valid pointer. don't know if that really matters. I can't test the c++ code.
If hFile was opened with FILE_FLAG_OVERLAPPED, the following conditions are in effect:
The lpOverlapped parameter must point to a valid and unique OVERLAPPED structure, otherwise the function can incorrectly report that the read operation is complete. The lpNumberOfBytesRead parameter should be set to NULL. Use the GetOverlappedResult function to get the actual number of bytes read. If the hFile parameter is associated with an I/O completion port, you can also get the number of bytes read by calling the GetQueuedCompletionStatus function.
I've run into this bug too. I checked serialport 6.x which is working in another project, but it's not working here. It's worth noting that the other project creates a single readline parser, whereas this project switches between ReadLine mode and fixed-length binary mode.
Update on this: I tried explicitly unpipeing my parsers and this made things much worse. I've refactored code to go to great extents to avoid repiping, by writing a demultiplexer that I can switch which parser my data is going to, and that seems to help. I've also avoided too many uses of once in tight loops, which seems to improve reliability.
import { Writable, PassThrough } from 'stream';
export const TEXT_MODE = Symbol('text');
export const BINARY_MODE = Symbol('binary');
export default class Demultiplexer extends Writable {
constructor() {
super();
this.mode = TEXT_MODE;
this.textStream = PassThrough();
this.binaryStream = PassThrough();
}
setMode(mode) {
this.mode = mode;
}
_write(chunk, encoding, callback) {
switch (this.mode) {
case TEXT_MODE:
this.textStream.write(chunk, encoding, callback);
return;
case BINARY_MODE:
this.binaryStream.write(chunk, encoding, callback);
return;
default:
callback(new Error("Should not reach here"));
return;
}
}
_final(callback) {
console.warn("final() called");
callback();
}
}
@dmh2000 that is interesting
You're spot on about this part of the code: https://github.com/node-serialport/node-serialport/blob/1daa9191a7e47c4146ae3394cb705a92d8f8d28b/packages/bindings/src/serialport_win.cpp#L479-L483
But before this starts (when we kick off the initial read) https://github.com/node-serialport/node-serialport/blob/1daa9191a7e47c4146ae3394cb705a92d8f8d28b/packages/bindings/src/serialport_win.cpp#L533-L534
We do wait for at least one byte. Now why weren't you getting at least one byte? That I don't know.
I did notice from time to time what looked like a race between the first read finishing and when the write was actually finished.
I saw that in the C code it should always get the first character before trying to get the rest. so yes it doesn't look like a read of 0 should ever happen. I had a GPS device connected, which was continuously outputting data. I would always get the first buffer of data, from 100 to 500 bytes, but it would never get the second buffer. I'm going to try a bit more to figure out what is really happening.
On Wed, May 1, 2019 at 8:19 PM Danielle Madeley [email protected] wrote:
I did notice from time to time what looked like a race between the first read finishing and when the write was actually finished.
— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/node-serialport/node-serialport/issues/1836#issuecomment-488541311, or mute the thread https://github.com/notifications/unsubscribe-auth/AAAGCCX7RTPHWBPK6KXUP23PTJMU7ANCNFSM4HGB74AA .
-- david howard [email protected] dmh2000.github.io github.com/dmh2000
Is there already a possible solution for this? Would be nice to know that this works reliable also on windows.
This is blocking me also, same code working fine on Linux, not on Windows.
Regarding the possibility of the the initial 1 byte read in the serialport_win.cpp returning 0 bytes, when it should always return 1 byte. It appears to that it does returns 0 sometimes, even though the code is structured so it should not do that. serialport_win.cpp::line 468
if (!GetOverlappedResult(int2handle(baton->fd), ov, &bytesTransferred, TRUE)) {
lastError = GetLastError();
ErrorCodeToString("Reading from COM port (GetOverlappedResult)", lastError, baton->errorString);
baton->complete = true;
return;
}
// =====================================
// !!! bytesTransferred CAN be 0 here, for some reason
// needs a debug check here
// =====================================
if (bytesTransferred) {
baton->bytesToRead -= bytesTransferred;
baton->bytesRead += bytesTransferred;
baton->offset += bytesTransferred;
}
so when it's zero, stream.js halts reading and it all hangs (unless I patch stream.js as before). .
I created a gist where I created a stripped down version of serialport_win.cpp with only the open and read function and a simple main to run it. I attempted to keep it the same as the original code structure with the read thread, iocompletion etc, and when I run it, it sees the GetOverlappedResult return 0 frequently. I drive it with a serial GPS so there is a burst of data every 1 second then a pause until the next and i get several reads of 0 bytes in the pause.
https://gist.github.com/dmh2000/c776e6c5e27664008533c477427a2349
This issue has been automatically marked as stale because it has not had recent activity. It will be closed in a week no further activity occurs. Feel free continue the discussion or ask for a never-stale label to keep it open. If this is a support issue, consider sharing it on stack overflow to get more eyes on your problem.