Asynchronous callbacks for reading and writing on Windows, attempt 2.

[dustmop]

Instead of ReadFile and WriteFile, which block and transfer data synchronously, use ReadFileEx and WriteFileEx, which both allow async callbacks. In addition, change how timeouts are used for ReadFile*, using an unlimited timeout for the first byte, and no timeout for the rest of the data in the input buffer. This removes the need to poll entirely, while still retrieving all data available in the input buffer. In both cases, the I/O operations happen in their own threads, since Windows requires IOCompletion callbacks to wait for their calling thread to be in an "alertable wait state".

Fixes #1221

[dustmop]

Verified this builds in 32-bit mode using:
node-gyp rebuild --msvs_version=2015 --arch=ia32

Ran tests using
TEST_PORT=COM3 npm test
and got:
233 passing (17s) 3 pending

Looks like the 3 pending tests are features that are disabled on Windows?

[noopkat]

👋 is this ready for me to test on my Windows box?

[noopkat]

running TEST_PORT=COM6 npm test on 64bit Surface Book gives me the following:

     #read
        √ errors asynchronously when not open
        1) doesn't throw if the port is open


  79 passing (7s)
  2 pending
  1 failing

  1) bindings/win32 instance method #read doesn't throw if the port is open:
     Error: Timeout of 2000ms exceeded. For async tests and hooks, ensure "done()" is called; if returning a Promise, ensure it resolves.

[reconbot]

@noopkat is that error consistent?

[reconbot]

@dustmop I pushed your commit to appveryor https://ci.appveyor.com/project/j5js/node-serialport/build/1.0.1581

[noopkat]

@reconbot it is consistent. I tried board resetting, repeated testing, and ran tests in both git-bash and powershell with the same results each time.

[dustmop]

On my machine:

bindings/win32
...
    instance method
...
      #read
        √ errors asynchronously when not open
        √ doesn't throw if the port is open (1582ms)
        √ returns at maximum the requested number of bytes (1579ms)

1582ms is pretty close-ish to 2000ms? Is there a way to try with an increased timeout?

[reconbot]

yeah, this.timeout(3000) does the trick (might have to switch away from an arrow function)

[noopkat]

1582ms is pretty close-ish to 2000ms? Is there a way to try with an increased timeout?

this machine is a good example of a 🐢 to test with, if that provides context around this at all

[reconbot]

I'm ok with adjusting the timeouts, we don't have any speed specific tests. However that test does seem really slow, all it's doing is opening the port and waiting for the first byte. Arduino's usually boot in around 300ms.

        it("doesn't throw if the port is open", () => {
          return binding.read(buffer, 0, buffer.length);
        });

However it IS slow everywhere so no worries. Eg on OSX.

        ✓ doesn't throw if the port is open (1613ms)
        ✓ returns at maximum the requested number of bytes (1608ms)

Appveyor passes!

[reconbot]

@noopkat if the extended timeout works for you let us know! you can use (npx mocha --no-timeouts if you have npm 5+)

[noopkat]

TEST_PORT=COM6 npx mocha --no-timeouts = 🆗 👌

[dustmop]

However that test does seem really slow, all it's doing is opening the port and waiting for the first byte

Small correction: this test (doesn't throw if the port is open) reads multiple bytes, equal to readyData.length. It's the test below (returns at maximum the requested number of bytes) that only reads a single byte. However, I agree it still seems to be on the slow side.

I want to make sure this isn't a regression. Was an increased timeout needed before this change? Also, is there a benchmark, or at least something that validates that cpu usage goes down? It seems good on my machine but would be nice to verify.

[noopkat]

weirdly trying from a master build will yield

   optional locking
          √ locks the port by default
          1) can unlock the port


  54 passing (372ms)
  2 pending
  1 failing

  1) bindings/win32 instance method #open optional locking can unlock the port:
     Error: Opening COM6: Access denied
      at Error (native)

verified the port:

node-serialport (master): avrgirl-arduino list
[ { comName: 'COM6',
    manufacturer: 'Arduino LLC (www.arduino.cc)',
    serialNumber: undefined,
    pnpId: 'USB\\VID_2341&PID_0043\\A4136373037351901241',
    locationId: 'Port_#0001.Hub_#0003',
    vendorId: '2341',
    productId: '0043',
    _standardPid: '0043' } ]

I do have to 😴 right now my apologies - early day in the city tomorrow. Will bring a board with me and can continue to debug if needed.

[reconbot]

You didn't need the extended timeout so I Don't think it's a regression. @noopkat could try master and report timings.

We don't have a perf test for large reads and writes, I've been using the repl TEST_PORT=COM3 npm run repl and writing Buffer.alloc(1024*1024, 'hi!') to the port. Anything less than 100% cpu is an improvement.

[reconbot]

@noopkat you can't unlock the port on windows, that's weird it would run that test.

[noopkat]

so this dummy here did not pull the latest master before building (it is late) 🤦‍♀️

I get the exact same doesn't throw if the port is open as earlier tonight. Doesn't seem like you caused a regression, @dustmop ?

[dustmop]

Ok! Thank you very much for helping, go get some rest! 👍

[reconbot]

Thank you @noopkat!

We're going to get finished builds from travis in anywhere between 0 and 6 hours. Their OSX backlock is quite long tonight.

I'm ok to merge with everything that's passing passing. We can bump the timeout in your pr (if you use an additional commit it will not cause the existing build jobs to fail) or master and cut a new beta release.

[reconbot]

That is to say if you're ok with this landing, I'm ok with this landing.

[dustmop]

Sure! Maybe wait until tomorrow, just in case?

[dustmop]

Looks like this should be good to go

[reconbot]

🎉

[vshymanskyy]

Hi all. I had a chance to try it out on our real-life application (Electron, Windows, x86 build).
It uses Modbus to communicate with a device. I use SerialPort v6.0.0-beta2.
It starts OK, I can connect to my device and exchange some packets. But after 5-10 seconds it seems to stop working. I'm investigating further

[vshymanskyy]

OK, this is what happens:

2017-09-07T10:12:34.021Z serialport:bindings write 8 bytes
2017-09-07T10:12:34.029Z serialport:main binding.write error Error: Writing to COM port (WriteFileEx): Unknown error code 87
2017-09-07T10:12:34.029Z serialport:main disconnected Error: Writing to COM port (WriteFileEx): Unknown error code 87
2017-09-07T10:12:34.029Z serialport:main #close
2017-09-07T10:12:34.033Z serialport:bindings close
2017-09-07T10:12:34.037Z modbus-serial Error:  Writing to COM port (WriteFileEx): Unknown error code 87
2017-09-07T10:12:34.037Z serialport:main binding.read error { Error: Reading from COM port (ReadIOCompletion): Operation aborted canceled: true } 2017-09-07T10:12:34.041Z serialport:main _read queueing _read for after open
2017-09-07T10:12:34.155Z serialport:main binding.close finished
2017-09-07T10:12:34.155Z modbus-serial Close:  { Error: Writing to COM port (WriteFileEx): Unknown error code 87 disconnected: true }

[dustmop]

Error code 87 is Windows' very unhelpful "ERROR_INVALID_PARAMETER", which doesn't say much. Could be the file handle is being invalidated, or the buffer is, somehow. Hard to figure out without a minimal repro case. This is 32-bit or 64-bit?

I haven't done any testing in electron, and won't be able to until I'm back home from travel (September 20th).

[reconbot]

I would bet this doesn't have anything to do with electron in particular. @vshymanskyy if you could try to reproduce this in node and open a new issue I can start debugging before @dustmop gets back. The new issue template has a section where you can talk about the hardware you're talking to. On windows the manufacture of the chipset of the USB serial device is very good to know. (FTDI etc)

[vshymanskyy]

Works fine with the latest version. Thank you!