WebSocket closed error

[viktorbk]

When the hearbeat interval function runs it does not check if the websocket is open and that often creates error like this one: (node:914) UnhandledPromiseRejectionWarning: Error: Can't send data because WebSocket is not opened. at exports.throwIf (/root/nodejs/ewelink-sserver/node_modules/websocket-as-promised/dist/index.js:3470:11) at WebSocketAsPromised.send (/root/nodejs/ewelink-sserver/node_modules/websocket-as-promised/dist/index.js:554:7) at Timeout._onTimeout (/root/nodejs/ewelink-sserver/node_modules/ewelink-api/mixins/websocket/openWebSocketMixin.js:38:17) at listOnTimeout (internal/timers.js:531:17) at processTimers (internal/timers.js:475:7)

Please add the check "if (wsp.isOpened)" to the interval function (line 37 in openWebSocketMixin):

   setInterval(async () => {
      if (wsp.isOpened) {
        await wsp.send('ping');
      }
    }, heartbeat);

[foulek57]

Hi have the same problem, will be nice if you can change this

[ttz642]

See #25 for some other suggestions on how to trap errors.

If the socket isn't open then it should return an error allowing the application to re-open the socket.

[ttz642]

NOTE: Currently testing on 3.1.0-ws, had to make a couple of additional changes, will post once fully tested.

I've added extra code to detect and report this issue back and terminate the app allowing the process manager to re-start.

pm2 logs

0|events     | 2020-02-03T12:44:06.670Z | Socket closed...
0|events     | 2020-02-03T12:44:06.670Z | Gracefully close and re-start...
PM2          | App [events:0] exited with code [1] via signal [SIGINT]
PM2          | App [events:0] starting in -fork mode-
PM2          | App [events:0] online
0|events     | 2020-02-03T12:44:08.358Z | Started event monitor...
0|events     | 2020-02-03T12:44:10.379Z | openWebSocketMixin:: heartbeat period in seconds: 120
0|events     | 2020-02-03T12:44:10.667Z | Socket opened...

The events loop catches the socket closure and aborts the app, the process manager (pm2) catches this and re-starts:

$ pm2 ls
┌─────┬──────────────┬─────────────┬─────────┬─────────┬──────────┬────────┬──────┬───────────┬──────────┬──────────┬──────────┬──────────┐
│ id  │ name         │ namespace   │ version │ mode    │ pid      │ uptime │ ↺    │ status    │ cpu      │ mem      │ user     │ watching │
├─────┼──────────────┼─────────────┼─────────┼─────────┼──────────┼────────┼──────┼───────────┼──────────┼──────────┼──────────┼──────────┤
│ 0   │ events       │ default     │ 1.0.0   │ fork    │ 8650     │ 30h    │ 2    │ online    │ 0.5%     │ 82.7mb   │ sonoff   │ disabled │
│ 2   │ scheduler    │ default     │ 1.0.0   │ fork    │ 3892     │ 2D     │ 0    │ online    │ 0.5%     │ 66.0mb   │ sonoff   │ disabled │
│ 1   │ www          │ default     │ 1.0.0   │ fork    │ 3876     │ 2D     │ 0    │ online    │ 0.5%     │ 60.6mb   │ sonoff   │ disabled │
└─────┴──────────────┴─────────────┴─────────┴─────────┴──────────┴────────┴──────┴───────────┴──────────┴──────────┴──────────┴──────────┘

Here you can see the event listener has been restarted twice because the connection was closed.

core event handler

    socket = await connection.openWebSocket(async data => {
        try{
            if (data.action == "socket"){
                switch (data.message) {
                case "opened":  console.log(new Date().toISOString(),'| Socket opened...');
                                break;
                case "pong":    //console.log(new Date().toISOString(),'| Keepalive received...');
                                break;
                case "timeout": console.log(new Date().toISOString(),'| Socket timed out...');
                case "closed":  console.log(new Date().toISOString(),'| Socket closed...');
                                console.log(new Date().toISOString(),'| Gracefully close and re-start...');
                case "error":   socket.removeAllListeners();
                                socket.close();
                                process.exit(1);
                                throw new Error("timeout, closed or error...");
                                break;
                default:        console.log(new Date().toISOString(),'| socket action not supported,',"Invalid data::",JSON.stringify(data,null,4));
                                throw new Error("unknown...");
                }
            }else{
                try {
                    if(data.action == "update"){
                        if((data.deviceid != null)&&(data.params.switch != null)){
                            console.log(new Date().toISOString(),'| device',data.deviceid,'alias',soo.localcache[data.deviceid].alias,'switch',data.params.switch);
                            post(www+'switch/'+data.deviceid+'/'+data.params.switch,'');
                        }
                    }
                } catch (error) {
                    console.log(new Date().toISOString(),'| Caught error:',JSON.stringify(error));
                }
            }
        } catch (error) {
            console.log(new Date().toISOString(),'| Error returned:',error);
            console.log(JSON.stringify(data,null,4));
            socket.removeAllListeners();
            socket.close();
            process.exit(1);
            throw new Error(error.message);
        }
    }).catch((error) => {
        // Handle the error!
        console.log(new Date().toISOString(),'| Final catch of Error returned:',error);
        socket.removeAllListeners();
        socket.close();
        process.exit(1);
        throw new Error(error.message);
    });

ewelink-api/mixins/websocket/openWebSocketMixin.js enhancements to catch and report errors. I've simplified after testing with 3.1.0-ws.

const W3CWebSocket = require('websocket').w3cwebsocket;
const WebSocketAsPromised = require('websocket-as-promised');

const wssLoginPayload = require('../payloads/wssLoginPayload');

module.exports = {
  /**
   * Open a socket connection to eWeLink
   * and execute callback function with server message as argument
   *
   * @param callback
   * @param heartbeat
   * @returns {Promise<WebSocketAsPromised>}
   */
  async openWebSocket(callback, ...{ heartbeat = 120000 }) {
    const payloadLogin = wssLoginPayload({
      at: this.at,
      apiKey: this.apiKey,
      appid: this.APP_ID,
    });

    const wsp = new WebSocketAsPromised(this.getApiWebSocket(), {
      createWebSocket: wss => new W3CWebSocket(wss),
    });

    wsp.onMessage.addListener(message => {
      if(message == "pong"){//eat pong...
        callback({"action" : "socket" , "message" : "pong"});
      }else{
        try {
          const data = JSON.parse(message);
          callback(data);
        } catch (error) {
          callback(message);
        }
      }
    });

    wsp.onOpen.addListener(() => {
      callback({"action": "socket" , "message" : "opened"});
    });
    wsp.onClose.addListener(event => {
      callback({"action": "socket" , "message" : "closed"});
    });
    wsp.onError.addListener(event => {
      callback({"action": "socket" , "message" : "error"});
    });
    await wsp.open();
    await wsp.send(payloadLogin);

    setInterval(async () => {
      if(wsp.isClosed || wsp.isClosing){
        console.log(new Date().toISOString(),"wsp.isClosed || wsp.isClosing");
        callback({"action": "socket" , "message" : "closed"});
      }
      //console.log(new Date().toISOString(),"ping sent...");
      wsp.send('ping');//await
    }, heartbeat);
    return wsp;
  },
};

This code now catches errors and passes them up to the calling code to deal with. The way I've delt with it is to just restart my event monitor, very simple and reliable.

When a ping is sent every 2min the socket stays open.

20|events      | 2020-06-16T12:47:51.995Z | Started event monitor...
20|events      | 2020-06-16T12:47:54.229Z | Socket opened...
20|events      | 2020-06-16T12:49:54.228Z ping sent...
20|events      | 2020-06-16T12:51:54.229Z ping sent...
20|events      | 2020-06-16T12:53:54.231Z ping sent...
20|events      | 2020-06-16T12:55:54.234Z ping sent...
20|events      | 2020-06-16T12:57:54.235Z ping sent...

If I comment out sending the ping the code catches the socket timeout:

19|events      | 2020-06-16T12:39:56.754Z | Started event monitor...
19|events      | 2020-06-16T12:39:59.154Z | Socket opened...
19|events      | 2020-06-16T12:41:59.155Z ping not sent...
19|events      | 2020-06-16T12:42:39.246Z | Socket closed...
19|events      | 2020-06-16T12:42:39.247Z | Gracefully close and re-start...
PM2            | App [events:19] exited with code [1] via signal [SIGINT]
PM2            | App [events:19] starting in -fork mode-
PM2            | App [events:19] online
19|events      | 2020-06-16T12:42:40.857Z | Started event monitor...
19|events      | 2020-06-16T12:42:43.103Z | Socket opened...
19|events      | 2020-06-16T12:44:43.104Z ping not sent...
19|events      | 2020-06-16T12:45:23.192Z | Socket closed...
19|events      | 2020-06-16T12:45:23.193Z | Gracefully close and re-start...

[saqib-ahmed]

Any update on this issue?

[pierred510]

Hi I still have this problem with the last version; Impossible to listen ewelink events with a long time fix possible ?

[LiYuanBr]

Hi. I solve this issue by creating an auto restart mode in the openWebSocket.js when it closes the connection.

The ewelink-api/src/mixins/openWebSocket.js in this repository: https://github.com/skydiver/ewelink-api/blob/5a07f6b6152d603c71266012177cc4b47d533bf9/src/mixins/openWebSocket.js#L38-L40

I changed to get credentials and try to restart the WebSocket:

setInterval(async () => {
      try {
        await wsp.send('ping');
      } catch (error) {
        console.error(`openWebSocket.js: ${error}`);
        console.log(`openWebSocket.js: Reconnecting...`);
        const auth = await this.getCredentials();
        const payloadLogin = wssLoginPayload({
          at: auth.at,
          apiKey: auth.user.apikey,
          appid: this.APP_ID,
        });
        await wsp.open();
        await wsp.send(payloadLogin);
      }
    }, heartbeat);

This way it closes the connection but doesn't close the process. It tries to connect again.

I'm still learning about JavaScript and I know that this code is very primitive, however, it solved my connection problem. Feel free to make some changes.