Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Do open sockets have a defined timeout? #25

Closed
thorito opened this issue Nov 7, 2019 · 16 comments
Closed

Do open sockets have a defined timeout? #25

thorito opened this issue Nov 7, 2019 · 16 comments
Labels
bug Something isn't working enhancement New feature or request

Comments

@thorito
Copy link

thorito commented Nov 7, 2019

Do open sockets have a defined timeout?

After a time in execution, it stops receiving events, some idea ?

Note: I'm using version 1.8.0

Thank you

Originally posted by @thorito in #5 (comment)

@ttz642
Copy link
Contributor

ttz642 commented Nov 12, 2019

Using 1.8.1 I've tried:

async function main () {
const login = await connection.login(account);//login to server
// call openWebSocket method with a callback as argument
socket = await connection.openWebSocket(async data => {
// data is the message from eWeLink
console.log(data)
});
}

NEVER stays open for more than 2 minutes and 42-44 seconds, sometimes much less.

@foulek57
Copy link

Have that same problem

@ttz642
Copy link
Contributor

ttz642 commented Nov 15, 2019

Same in 1.8.2 . . .

@skydiver
Copy link
Owner

Hey guys:

This is the library used for websocket https://github.com/vitalets/websocket-as-promised

I didn't see anything related to timeout.

Maybe the service needs to be pinged every x minutes to keep connection open?

@foulek57
Copy link

Hello have search today, the websocket as promised have the timeout 0 sa default, have add a onClose to my script and the result are "Connections closed: Connection dropped by remote peer." but find no result on google ... Any idea guys ?

@foulek57
Copy link

I have read on the web that the connection are close beacause we need to ping it, have try to send a switchDevice command every 15 sec and the server not close the conection.
Any idea how to do the ping ?
I have try socket.send('ping'); seem to work but have a error
pong
^
SyntaxError: Unexpected token p in JSON at position 0
at JSON.parse ()
at /var/www/html/plugins/ewejee/core/js/node_modules/ewelink-api/mixins/websocket/openWebSocketMixin.js:26:25
at Timeout._onTimeout (/var/www/html/plugins/ewejee/core/js/node_modules/websocket-as-promised/dist/index.js:1240:38)
at listOnTimeout (internal/timers.js:531:17)
at processTimers (internal/timers.js:475:7)

@skydiver
Copy link
Owner

skydiver commented Nov 16, 2019

Guys, this worked for me:

First, update openWebSocketMixin.js, and replace:

    wsp.onMessage.addListener(message => {
      const data = JSON.parse(message);
      callback(data);
    });

with:

    wsp.onMessage.addListener(message => {
      try {
        const data = JSON.parse(message);
        callback(data);
      } catch (error) {
        callback(message);
      }
    });


Then on your script, add this code:

(async () => {

  const connection = new ewelink({
    email: '<your email>',
    password: '<your password>',
    region: '<your region>'
  });

  await connection.login();

  const socket = await connection.openWebSocket(async data => {
    // data is the message from eWeLink
    console.log(data);
  });

  const interval = setInterval(async () => {
    await socket.send('ping');
  }, 90000);

})();

If this work for you, i will move the ping command inside the openWebSocket method so nobody needs to worry about sending the heartbeat to the server.

@foulek57
Copy link

Hi, yesterday I have tried to ping with interval of 60000ms this have work all the night.

I have detect the "pong" before the json.parse so I have no error.

I will try your change and confirm if this work by me.

@foulek57
Copy link

Hello,

Have tryed your code, but have an error :

(node:14130) UnhandledPromiseRejectionWarning: Error: Can't send data because WebSocket is not opened.
at exports.throwIf (/var/www/html/plugins/ewejee/core/js/node_modules/websocket-as-promised/dist/index.js:3470:11)
at WebSocketAsPromised.send (/var/www/html/plugins/ewejee/core/js/node_modules/websocket-as-promised/dist/index.js:554:7)
at Timeout._onTimeout (/var/www/html/plugins/ewejee/core/js/newserver.js:62:20)
at listOnTimeout (internal/timers.js:531:17)
at processTimers (internal/timers.js:475:7)
(node:14130) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 5)

@foulek57
Copy link

Hello,

Sorry, was not your code, have no error with your code, work nice !!
You can add it to the openWebSocket.

I take this opportunity to say congratulations for your work!

@ttz642
Copy link
Contributor

ttz642 commented Nov 17, 2019

Hi, yesterday I have tried to ping with interval of 60000ms this have work all the night.

I have detect the "pong" before the json.parse so I have no error.

I will try your change and confirm if this work by me.

Perhaps 120s (120000ms) to reduce traffic as it appears the time out is 160s.

@skydiver skydiver added bug Something isn't working enhancement New feature or request labels Nov 20, 2019
@ttz642
Copy link
Contributor

ttz642 commented Nov 21, 2019

Using release_1.10.0

Left an event monitor running overnight, looks like it crashed. I'm guessing the socket closed and the ping then fails:

    at ontimeout (timers.js:482:11)
    at tryOnTimeout (timers.js:317:5)
    at Timer.listOnTimeout (timers.js:277:5)
(node:21254) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 235)
(node:21254) UnhandledPromiseRejectionWarning: Error: Can't send data because WebSocket is not opened.
    at exports.throwIf (~/node_modules/websocket-as-promised/dist/index.js:3470:11)
    at WebSocketAsPromised.send (~/node_modules/websocket-as-promised/dist/index.js:554:7)
    at Timeout.setInterval [as _onTimeout] (~/node_modules/ewelink-api/mixins/websocket/openWebSocketMixin.js:38:17)

Need to detect the socket closes and re-open it.
I've restarted and date stamped the output to see how long it goes before it crashes.

I'll leave it till tomorrow to see if it drops itself before I disable access to coolkit.cc which will simulate dropping the connection.

@ttz642
Copy link
Contributor

ttz642 commented Nov 27, 2019

Make sure .close() is called before application terminates otherwise restarting application may not connect 1st time.

In main application I have:

var socket;	//define outside of asyn function to allow access as required
process.on("SIGINT", () => {
	console.log(" - Caught SIGINT. Exiting in 3 seconds.");
	console.log("Closing WebSocket...");
	var cls = socket.close();
	setTimeout(() => {
		process.exit(0);
	}, 3000);
});

So if the process is terminated it will close the web socket. Since adding this the app has gracefully closed the socket every time and always restarts 1st time.

@ttz642
Copy link
Contributor

ttz642 commented Nov 27, 2019

Martin,

In order to keep the pong reply I return a sonoff type structure with the action being socket, eg:

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

In the calling code I now use:

    socket = await connection.openWebSocket(async data => {
        try{
            if (data.action == "socket"){
                date = new Date().toUTCString();
                switch (data.message) {
                case "opened":  console.log("### Socket opened at:",date);
                                break;
                case "pong":    //console.log("### keepalive received at:",date);
                                break;
                case "error":
                case "closed":  console.log("### Socket closed at",date,"\n\tgracefully close and re-open socket...");
                                break;
                default:        console.log("### socket action not supported at",date,"Invalid 
                }
            }else{
                console.log("data::",JSON.stringify(data,null,4));  //if(DEBUG) when coded !
            }
        } catch (error) {
            console.log("Invalid data::",JSON.stringify(data,null,4));  //if(DEBUG) when coded !
        }

I've also returned other states, eg socket opened, closed or error, I'll do a little more testing and then post the changes.

@foulek57
Copy link

Hi dear,

This is a good idea, the pong message are for me important, so I can detect that all is ok.

Thanks for your job !

@ttz642
Copy link
Contributor

ttz642 commented Nov 27, 2019

Once the events listener starts it is likely to hang up at some point due to lost socket connection. I've made changes to the library to catch some of the conditions that result in the connection failing and the code just hanging up.

Changes to openWebSocketMixin.js to catch communication errors more gracefully.

Changed heartbeat to 6s just to speed up debug.

Event loop (main):

    socket = await connection.openWebSocket(async data => {
        try{
            if (data.action == "socket"){
                date = new Date().toUTCString();
                switch (data.message) {
                case "opened":  console.log("### Socket opened at:",date);
                                break;
                case "pong":    console.log("### keepalive received at:",date);
                                break;
                case "timeout": console.log("### Socket timed out at",date);
                case "closed":  console.log("### Socket closed at",date);
                                console.log("gracefully close and re-open socket...");
                case "error":   throw new Error("timeout...");
                                break;
                default:        console.log("### socket action not supported at",date,"Invalid data::",JSON.stringify(data,null,4));
                                throw new Error("unknown...");
                }
            }else{
                console.log("data::",JSON.stringify(data,null,4));
            }
        } catch (error) {
			console.log("Error returned:",error);
            console.log(JSON.stringify(data,null,4));
			process.exit(2);
        }
    })

Changes to openWebSocketMixin.js, replace:

    wsp.onMessage.addListener(message => {
      try {
        const data = JSON.parse(message);
        callback(data);
      } catch (error) {
        callback(message);
      }
    });

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

with:

    wsp.onMessage.addListener(message => {
      if(message == "pong"){//eat pong...
        tsin =  Math.floor(Date.now()/1000);
        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 () => {
      var tsdelta = tsout - tsin;
      console.log("tsdelta",tsdelta);
      if(wsp.isClosed){
        callback({"action": "socket" , "message" : "closed"});
      }
      if(tsdelta >= (period*5)){
        //if we haven't had a reply to one of the three outstanding ping's
        //in last 5 heartbeats were probably not connected anymore, thus timeout
        callback({"action": "socket" , "message" : "timeout"});
      }
      tsout =  Math.floor(Date.now()/1000);
      if(tsdelta < (3 * period)){
        wsp.send('ping');//await
        var date = new Date().toUTCString();
        console.log("### keepalive sent at:",date);
      }
    }, heartbeat);

Running the code:

$ bin/events.js
openWebSocketMixin...
heartbeat period in seconds: 6
### Socket opened at: Wed, 27 Nov 2019 11:55:34 GMT
data:: {
    "error": 0,
    "apikey": "45b2b2ba-037e-4819-8ee5-09553a6f2119",
    "config": {
        "hb": 1,
        "hbInterval": 145
    },
    "sequence": "1574855733875"
}
tsdelta 0
### keepalive sent at: Wed, 27 Nov 2019 11:55:40 GMT
### keepalive received at: Wed, 27 Nov 2019 11:55:40 GMT  <<== last pong received

**INTERNET CONNECTION DISABLED**

tsdelta 0
### keepalive sent at: Wed, 27 Nov 2019 11:55:46 GMT  <<== 1st ping after lost connection
tsdelta 6
### keepalive sent at: Wed, 27 Nov 2019 11:55:52 GMT  <<== 2nd ping after lost connection
tsdelta 12
### keepalive sent at: Wed, 27 Nov 2019 11:55:58 GMT  <<== 3rd ping after lost connection
tsdelta 18
tsdelta 24
tsdelta 30  <<== 5th pong missing, signal timeout
### Socket timed out at Wed, 27 Nov 2019 11:56:16 GMT
### Socket closed at Wed, 27 Nov 2019 11:56:16 GMT
gracefully close and re-open socket...
Error returned: Error: timeout...
    at connection.openWebSocket (/home/steve/ewelink-api/bin/events.js:56:39)
    at Timeout.setInterval [as _onTimeout] (/home/steve/ewelink-api/node_modules/ewelink-api/mixins/websocket/openWebSocketMixin.js:77:9)
    at ontimeout (timers.js:482:11)
    at tryOnTimeout (timers.js:317:5)
    at Timer.listOnTimeout (timers.js:277:5)
{
    "action": "socket",
    "message": "timeout"
}

I'll use PM2 to handle restarting the process...

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working enhancement New feature or request
Projects
None yet
Development

No branches or pull requests

4 participants