Add short delay when shutting event test server down

[cgewecke]

(Apologies in advance for the length of this explanation)

PR adds a short delay when shutting down the server in test/event.js.

Background
I'm helping out at Web3.js. One of the project's goals is to improve stability by expanding its test suites. With that in mind, have added ganache-core's unit tests as an E2E which Web3 can sanity check its latest state against.

Motive
In a PR which rewrites the WS provider to support auto-reconnect, am seeing a failure in a single event test, originating here.
https://github.com/trufflesuite/ganache-core/blob/9d50099b08e630650e11fe7ccfcf66cf5d9789bf/test/events.js#L63

It's a little mysterious but the TLDR is:

• The Web3 PR adds logic to trigger an error on unanticipated disconnections
• connection.close is either being run non-sequentially for EventEmitter reasons or failing to complete because interrupted by the server close.
• the close event is dirty instead of clean.

Introducing a short delay before server shutdown allows disconnect to execute as expected.

By making this change, Web3 will (probably) install without test failures if you upgrade to a forth-coming patch version.

[cgewecke]

Unfortunately, zero isn't enough. Idk.

[coveralls]

Coverage remained the same at 82.114% when pulling 04f3528 on cgewecke:test/delay-server-shutdown into 9d50099 on trufflesuite:develop.

[davidmurdoch]

@cgewecke

From your description it sounds like this could be a bug in the close logic. Once the Web3WsProvider's close method is called and the shutdown process has started (sending a close frame and then ending the socket connection) should a disconnect from the other side be treated as an error? Not sure.

Anyway, it seems the reason our server.close() isn't gracefully shutting down the connection on web3's side is because we call destroy() on the direct socket instead of close() on the websocket.

I've hacked together some changes in a branch (https://github.com/trufflesuite/ganache-core/tree/fix/websocket-close) and published a new temporary npm tag ganache-core@websocket-close (https://www.npmjs.com/package/ganache-core/v/2.10.2-websocket-close.0). Could you let me know if it fixes the issue in web3?

[cgewecke]

@davidmurdoch Thanks so much for looking into this. Really appreciate it.

In my experiments with fix/websocket-close everything looks right.

There's one caveat - at the moment Web3 treats 1001 as an error because it's a unilateral disconnection issued by a network we assume is always available. (Or a browser nav away maybe)

Is that incorrect from your point of view?

To get the tests to pass it was still necessary to call web3.currentProvider.disconnect() right before server.close.

This is what things look like in Travis when running Web3's websocket rewrite within ganache's fix/websocket-close. (The messages are all logged from within Web3)

Without disconnect(): fails

     ✓ ensures topics are respected in past events, using `event.get()` (exclusive) (275ms)
     ✓ will not fire if logs are requested when fromBlock doesn't exist (285ms)
  Forking
hearing WebSocketProvider _onClose --> 1001 Remote peer is going away
hearing RequestManager --> 1001
    1) should handle events properly via the data event handler
    ✓ should get the id of the forked chain

With disconnect(): succeeds

      ✓ ensures topics are respected in past events, using `event.get()` (exclusive) (274ms)
      ✓ will not fire if logs are requested when fromBlock doesn't exist (288ms)
at top of WebsocketProvider.prototype.disconnect 
  Forking
hearing WebSocketProvider ._onClose --> 1000 Normal connection closure
hearing RequestManager close event --> 1000
    ✓ should get the id of the forked chain

(Please close this at will - probably should have been an issue and not a PR).

[davidmurdoch]

Thanks for following up so quickly!

1001 is correct in this case and signals to the websocket clients that they should NOT attempt to reconnect to this server again. I think in this test's case, web3 is correct, in that this is an unrecoverable error for web3 and web3 shouldn't attempt to reconnect.

All that to say: I do think you are right; I need to add the websocket close call on the web3 provider back in to our tests (and need to wait for it to finish closing) before calling our own server.close().

Thanks again!

Note: I'm about to hop on a plane and probably won't have time to test or update anything else for a few days.

[cgewecke]

@davidmurdoch Sounds good. There's no urgency about this on Web3's side - was just investigating and trying to make sure the package will install for people correctly.

Thanks again!

(Am closing since there's a little more to this than a timeout).