Websocket causes process to crash

sharafian commented 6 years ago

Error [ERR_UNHANDLED_ERROR]: Unhandled error. (websocket)
    at RippleAPI.emit (events.js:141:19)
    at RestrictedConnection.<anonymous> (/Users/sharafian/Documents/prog/moneyd/node_modules/ripple-lib/dist/npm/api.js:101:16)
    at RestrictedConnection.emit (events.js:160:13)
    at WebSocket.<anonymous> (/Users/sharafian/Documents/prog/moneyd/node_modules/ripple-lib/dist/npm/common/connection.js:225:18)
    at WebSocket.emit (events.js:160:13)
    at WebSocket.finalize (/Users/sharafian/Documents/prog/moneyd/node_modules/ws/lib/WebSocket.js:182:41)
    at TLSSocket.emit (events.js:160:13)
    at emitErrorNT (internal/streams/destroy.js:64:8)
    at process._tickCallback (internal/process/next_tick.js:152:19)

intelliot commented 6 years ago

@sharafian How can I reproduce this error?

Looking at ripple-lib 0.21.0 -

at RestrictedConnection.<anonymous> (/Users/sharafian/Documents/prog/moneyd/node_modules/ripple-lib/dist/npm/api.js:101:16) Line 101 looks like: this.getAccountInfo = accountinfo_1.default;

at WebSocket.<anonymous> (/Users/sharafian/Documents/prog/moneyd/node_modules/ripple-lib/dist/npm/common/connection.js:225:18) Lines 224-226 are:

            if (!this._url) {
                reject(new errors_1.ConnectionError('Cannot connect because no server was specified'));
            }

at WebSocket.finalize (/Users/sharafian/Documents/prog/moneyd/node_modules/ws/lib/WebSocket.js:182:41) Lines 170-182 are:

  /**
   * Clean up and release internal resources.
   *
   * @param {(Boolean|Error)} error Indicates whether or not an error occurred
   * @private
   */
  finalize (error) {
    if (this._finalized) return;

    this.readyState = WebSocket.CLOSING;
    this._finalized = true;

    if (typeof error === 'object') this.emit('error', error);

I'm not sure what's happening here.

sharafian commented 6 years ago

@sharafian How can I reproduce this error?

After leaving any ripple-lib application open for a while, the socket emits the error. Would this happen if the connection drops?

intelliot commented 6 years ago

I've been running a ripple-lib app for about a day now, and I haven't seen this error yet.

Here's the boilerplate for handling disconnects:

api.on('disconnected', (code) => {
  // code - [close code](https://developer.mozilla.org/en-US/docs/Web/API/CloseEvent) sent by the server
  // will be 1000 if this was normal closure
  console.log('disconnected, code:', code);
});

When the rippled server is closed normally (control+c to kill rippled with signal SIGINT), I get code 1000. When I use kill -9 [pid], I get code 1006.

intelliot commented 6 years ago

I kept moneyd running for about 4 days and did a few example SPSP payments. The process did not appear to crash.

tuloski commented 6 years ago

@intelliot did you play quake III for 4 days? :)

sublimator commented 6 years ago

Haha

sharafian commented 6 years ago

@intelliot: I put in a log line to see what the error is. It looks like in the connection class, the websocket is timing out but the error is being re-emitted all the way out of the module. I think if it encounters such an error it should just retry the connection.

ERROR { Error: read ETIMEDOUT
    at _errnoException (util.js:1003:13)
    at TLSWrap.onread (net.js:620:25) errno: 'ETIMEDOUT', code: 'ETIMEDOUT', syscall: 'read' }
THROWING ERROR
Error [ERR_UNHANDLED_ERROR]: Unhandled error. (websocket)
    at RippleAPI.emit (events.js:141:19)
    at RestrictedConnection.RippleAPI.connection.on (/Users/sharafian/Documents/prog/moneyd/node_modules/ripple-lib/src/api.ts:129:14)
    at RestrictedConnection.emit (events.js:160:13)
    at WebSocket._ws.on.error (/Users/sharafian/Documents/prog/moneyd/node_modules/ripple-lib/src/common/connection.ts:226:14)
    at WebSocket.emit (events.js:160:13)
    at WebSocket.finalize (/Users/sharafian/Documents/prog/moneyd/node_modules/ws/lib/WebSocket.js:182:41)
    at TLSSocket.emit (events.js:160:13)
    at emitErrorNT (internal/streams/destroy.js:64:8)
    at process._tickCallback (internal/process/next_tick.js:152:19)

Maybe your process isn't crashing because your computer hasn't gone to sleep, or the internet has never had to reconnect? I still haven't been able to isolate when exactly this error is triggered, but now we know it's a timeout, at least.

SolsticeLLC commented 5 years ago

I've encountered this error recently in a seemingly random event. To give a fuller explanation of my environment, I will describe my configuration.

I am running an ILP connector in a docker container, newly compiled image on the latest releases of all ILP plugins, including moneyd-gui on the recently patched Alpine Linux base image.

At the time of the error, I had 9 peer connections up, with 4 peer connections down or awaiting the client end to connect to my peer's 'server-side' connection to my ILSP 'g.aurora'. The ILP connector and moneyd-gui processes are running via PM2, with process 0 being the ILP connector, and process 1 being Moneyd-gui.

If this is a timeout issue, it is very possible that the 4 connections that are not 'up' could have caused this, as they have been sitting in this 'down' state for a number of days since last bouncing my connector to add a new peer.

My errors below came without any interaction with the connector at the time. I noticed that the connector had restarted due to my monitoring of statistics I am pulling from the connector admin port via prometheus. Via my stat collection and graphing of those stats, I noticed that stat counters had reset - indicating that the process had restarted on its own.

These errors below were pulled via PM2 with command 'PM2 logs 0'

Feel free to contact me with any further questions you may have!

intelliot commented 5 years ago

Thanks for the info. Is there a way to catch the error and retry the connection?

SolsticeLLC commented 5 years ago

Not sure of how to accomplish that. Frankly, these 3 connections that I have as the "server side" of a peer connection have been in a "down" state for a couple weeks - but I have restarted my connector more than a few times during that span of time. When the errors occurred, it was seemingly without any action on my part. Nothing seemed to have caused them - at least administratively from my part - at the time.

Is it possible that something occurred with s2.ripple.com? I believe that is the rippled server that all of my peer connections utilize. I should probably make some changes to the config to load balance them across s1 and s2.

intelliot commented 5 years ago

The servers were updated to rippled 1.1.0 around 2018-09-21. Any rippled server will need to be restarted from time to time for updates; our apps and scripts should gracefully reconnect as necessary.

SolsticeLLC commented 5 years ago

Interesting .... I reported my errors first in the interledger/connector.land Gitter room at Sep 21 16:10 ....

That time stamp is US Central time zone ... The errors came just a few minutes before my post there.

intelliot commented 5 years ago

Those who are seeing this error, could you check if you've added an error listener?

api.on('error', (errorCode, errorMessage) => {
  console.log(errorCode + ': ' + errorMessage);
});

https://github.com/ripple/ripple-lib/blob/develop/docs/index.md#boilerplate

alexkvak commented 5 years ago

Any news with this issue? I found issue for ws https://github.com/websockets/ws/issues/1256 and it seems that ws version should be bumped up to 6 (for now it is 3).

dmitryrn commented 5 years ago

Same error here, it appear when my local pc with running server lost connection (reboot, changing network).

I've tried this https://github.com/ripple/ripple-lib/blob/develop/docs/index.md#example-70 But it does not logs anything before it crashes

Error [ERR_UNHANDLED_ERROR]: Unhandled error. (websocket)
    at RippleAPI.emit (events.js:169:17)
    at RippleAPI.emit (domain.js:422:20)
    at Connection.RippleAPI.connection.on (/Users/dmitry/projects/my-api/node_modules/ripple-lib/src/api.ts:133:14)
    at Connection.emit (events.js:185:15)
    at Connection.emit (domain.js:422:20)
    at WebSocket._ws.on.error (/Users/dmitry/projects/my-api/node_modules/ripple-lib/src/common/connection.ts:209:14)
    at WebSocket.emit (events.js:180:13)
    at WebSocket.emit (domain.js:422:20)
    at WebSocket.finalize (/Users/dmitry/projects/my-api/node_modules/ripple-lib/node_modules/ws/lib/WebSocket.js:182:41)
    at Socket.emit (events.js:180:13)
    at Socket.emit (domain.js:422:20)
    at emitErrorNT (internal/streams/destroy.js:64:8)
    at process._tickCallback (internal/process/next_tick.js:178:19)

asielgil88 commented 5 years ago

Same error happening for me, in my case it happens when the server recover connectivity after a short time offline,

1-Server lose connection 2-Server recover connection 3-Execute a request to RippleApi


    throw err; // Unhandled 'error' event
    ^

Error [ERR_UNHANDLED_ERROR]: Unhandled error. (websocket)
    at RippleAPI.emit (events.js:171:17)```

intelliot commented 5 years ago

@asielgil88 Can you confirm whether you've added an error handler?

api.on('error', (errorCode, errorMessage) => {
  console.log(errorCode + ': ' + errorMessage);
});

https://github.com/ripple/ripple-lib/blob/develop/docs/index.md#boilerplate

asielgil88 commented 5 years ago

Its hard for me to get logs, im running a node server instance inside an iOS app container using https://github.com/JaneaSystems/nodejs-mobile

intelliot commented 5 years ago

@asielgil88 Can you post example code (or an example project)? Does your integration have an error handler on the RippleAPI instance?

asielgil88 commented 5 years ago

@intelliot hey thanks for the response, I already isolate the problem it wasn't ripple-lib, my node server runs inside an iOS device, what happens is every time the user lock down the device, iOS close all ports in use.

So the solution I found in the meantime is every time the device is unlocked I open the ports

nhandl3 commented 5 years ago

@intelliot I found this line of code in connection.ts https://github.com/ripple/ripple-lib/blob/229360d1b9ef9be18567b7341bb3dc90ed9cf3e8/src/common/connection.ts#L355

It will cause Promise rejection was handled asynchronously as discussed in https://stackoverflow.com/questions/40920179/should-i-refrain-from-handling-promise-rejection-asynchronously/40921505 if provided promise is rejected before any late binding catch handler.

One workaround is add an empty catch like this:

promise.catch(() => {});

You can re-produce this by simulate an idling connection, for example, create connection to ripple server as normal then block that connection by firewall.

intelliot commented 5 years ago

@nhandl3 Cool. Would you like to open a PR?

nickewansmith commented 4 years ago

This may help. This PR aims to solve the issue described by @nhandl3 . https://github.com/ripple/ripple-lib/pull/1092/commits/d8dbeedcc2bf42350ba2da86d164fc0273225484

intelliot commented 4 years ago

Fixed in ripple-lib 1.4.2.

XRPLF / xrpl.js

Websocket causes process to crash #885