node-serialport icon indicating copy to clipboard operation
node-serialport copied to clipboard

Reading on Windows not working in 7.1.4

Open lobermann opened this issue 6 years ago • 11 comments

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

lobermann avatar Apr 15 '19 17:04 lobermann

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.

lobermann avatar Apr 16 '19 15:04 lobermann

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.

dmh2000 avatar May 01 '19 01:05 dmh2000

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.

danni avatar May 01 '19 23:05 danni

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();
  }
}

danni avatar May 02 '19 01:05 danni

@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.

reconbot avatar May 02 '19 02:05 reconbot

I did notice from time to time what looked like a race between the first read finishing and when the write was actually finished.

danni avatar May 02 '19 03:05 danni

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

dmh2000 avatar May 02 '19 05:05 dmh2000

Is there already a possible solution for this? Would be nice to know that this works reliable also on windows.

lobermann avatar May 16 '19 06:05 lobermann

This is blocking me also, same code working fine on Linux, not on Windows.

wired8 avatar May 23 '19 02:05 wired8

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

dmh2000 avatar May 24 '19 00:05 dmh2000

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.

stale[bot] avatar Jul 23 '19 01:07 stale[bot]