Unhandled rejection Error: no response timeout

mwittig commented 7 years ago


2017-07-18T12:37:59.873Z Milight: bytesSent=27, buffer=[0x20,0x00,0x00,0x00,0x16,0x02,0x62,0x3A,0xD5,0xED,0xA3,0x01,0xAE,0x08,0x2D,0x46,0x61,0x41,0xA7,0xF6,0xDC,0xAF,0xD3,0xE6,0x00,0x00,0xC9]
Unhandled rejection Error: no response timeout
    at null._onTimeout (C:\Users\marcus\PIDEV\pimatic-xx\node_modules\pimatic-milight-reloaded\node_modules\node-milight-promise\src\milight-v6-mixin.js:123:26)
    at Timer.listOnTimeout (timers.js:92:15)

pauleec commented 6 years ago

@mwittig Hi Marcus, Happy New Year! I've updated all my node/homebridge/milight/alexa components and am getting this error

Unhandled rejection Error: no response timeout at Timeout._onTimeout (/usr/local/lib/node_modules/homebridge-milight/node_modules/node-milight-promise/src/milight-v6-mixin.js:125:26) at ontimeout (timers.js:478:11) at tryOnTimeout (timers.js:302:5) at Timer.listOnTimeout (timers.js:262:5)

Is this resolved by supporting the keepalive function @markg85 references has been implemented here: https://github.com/JasperG/bilight/blob/master/bilight/src/main/java/com/jaspergoes/bilight/milight/Controller.java#L774 ?

I use the homebridge-milight plugin to control my 8 zones of RGB-CCT lights with my Amazon Echo Dot via the homebridge-alexa plugin. I'm running the Echo Dot with version 597465220 of their echo dot software.

mwittig commented 6 years ago

@pauleec Happy new year!

The "no response timeout" error is not related and it is not resolved by implementing the keep-alive generally. Regarding the state of homebrige integration see https://github.com/dotsam/homebridge-milight/issues/39

fzmemon commented 6 years ago

Any updates on this bug? Seems this pops up when you send a few commands in quick succession to the same zone. The execution just hangs and if you kill the process and start again, it doesnt help either. Only after passage of certain amount of time, the script works again.

This is the code which I am using for turning off the lights. The turnOn code is similar:

function turnOff(zone) {
    light.ready().then(function() {
        light.sendCommands(commands.white.off(zone)).then(function() {
            light.close().then(function () {
                console.log("Turn off command executed...");
              }).catch(function(error) {
                console.log(error);
            });
        });
    }).catch(function(error) {
        console.log(error);
    });
}

Please let me know if I am doing something wrong which is causing this error.

mwittig commented 6 years ago

Well, yes and no. Yes, as I analyzed the "unhandled rejection" and found this is design glitch rather than a bug. The problem is that different to earlier the sendCommands() function now returns a promise which needs to be handled. No, as the underlying problem is not fully analysed. As you say the problem occurs in particular if commands are send in quick succession to the same zone. That's also what I noticed. I am not sure yet, however, what is causing the problem. It might be network congestion (UDP packets simply dropped on the network). To verify this I need to create more packet captures. I'll also check your code snippet as I did notice the code "hanging". Do you at which point it hangs? Is it light.ready()? A recovery strategy might be to create a new session in case.

fzmemon commented 6 years ago

Hi Markus, I have some updates. I think this might not even be a bug at all. I found out that this comes up if you have several connections open to the milight ibox.

In my case, this happened because I was not handling the promises correctly in wrapper script which I have written around milight-promise. This caused the node processes to hang which in turn probably left the connections to the ibox open. Once I cleaned up my code and each call to my wrapper script exited correctly, I did not have this problem anymore.

The wrapper that I have written is an adapter for the ha-bridge which I plan to publish soon as well.

Thanks for the info.

CliffS commented 6 years ago

I am seeing this too. I have only one routine talking to the controller and all calls are wrapped in a .then() followed by a .catch(). I use await inside the .then() but this should throw and be caught by the .catch() if there's an error.

What I'm seeing is

Unhandled rejection Error: no response timeout
    at Timeout._onTimeout (/home/cliff/src/git/house/node_modules/node-milight-promise/src/milight-v6-mixin.js:128:26)
    at ontimeout (timers.js:466:11)
    at tryOnTimeout (timers.js:304:5)
    at Timer.listOnTimeout (timers.js:267:5)

Does this help at all?

Incidentally, is there any way to get the current state from the controller?

mwittig commented 6 years ago

@fzmemon Thanks for the update!

@CliffS Do you have your code on github?

CliffS commented 6 years ago

The code is part of a private repository. I've posted the relevant module (the only one that calls milight) to a gist. Is that sufficient?

It's in coffeescript. Let me know if you need the javascript version.

[Edit] Actually, it probably isn't enough because you need to see that each promise has a .catch(). Should I simply add you to my repository?

mwittig commented 6 years ago

Thanks you very much for providing me with code samples and your efforts in investigating the problem!

Minor update: I spent some time to further analyze the problem around the "unhandled exception" and have a solution for it which I'll push later. This solves the "unhandled exception", however, it does not solve the "request timeout problem". This occurs when the WiFi controller did not ack a command after it had been resent three times. It might be a congestion issue if you have multiple MilightController instance s, for example, doing commands at the same time (note, however, it is possible to enable full synchronization between all those instances!). However, some users reported it also occurs in a single instance uses case and I have also sporadically seen this.

mwittig commented 6 years ago

@CliffS Thanks again for your efforts in investigating the "unhandled exception" problem and your code work to fix the problem. I'll write a summary of the changes in more detail asap.

fzmemon commented 6 years ago

@mwittig I think you are right in saying that the problem seems to be congestion related.

I have stitched Alexa up with your scripts and ha-bridge in between. In Alexa I have defined some scenes and each scene triggers multiple zones in parallel. For example, the scene "Good night" turns off all the zones. Whenever I trigger this scene, 4 node instances are started and every now and then at least one of these instances gets stuck with the "no response timeout" error. Once this error shows up, further instances keep failing until I have a list of node instances which are stuck. Now killing all these instances does not seem to help. Restarting the bridge also does not seem to help. Only thing that helps is restarting the my router.

Could the issue be related to TTL of the UDP commands? How long is the TTL?
Is the sync between multiple instances enabled by default?
I think you wanted to look into establishing a TCP connection to the bridge. Any infos on that? Is there some documentation available which describes this? I could not find any.

Addition

For testing purposes I stopped using Alexa scenes. The setup ran without any issues for 9 days.

Steiger04 commented 5 years ago

@mwittig Gibt es für das Problem schon eine Lösung? Bei mir hilft auch nur den Router neu zu starten, dann ist das Antwortverhalten wieder eine Zeit lang ok. Mit dem Problem ist es so gut wie unmöglich einen Slider zu implementieren, da durch die Verzögerungen die Farbe ständig "nachläuft".

normen commented 5 years ago

I have this error too, latest version of the homebridge plugin, only since I have a new v6 base station. Funny thing is that no light was switched when this error occurred:

Apr 01 07:25:25 homebridge homebridge[23709]: Unhandled rejection Error: no response timeout
Apr 01 07:25:25 homebridge homebridge[23709]: at Timeout._onTimeout (/usr/lib/node_modules/homebridge-milight/node_modules/node-milight-promise/src/milight-v6-mixin.js:128:26)
Apr 01 07:25:25 homebridge homebridge[23709]: at ontimeout (timers.js:498:11)
Apr 01 07:25:25 homebridge homebridge[23709]: at tryOnTimeout (timers.js:323:5)
Apr 01 07:25:25 homebridge homebridge[23709]: at Timer.listOnTimeout (timers.js:290:5)

CliffS commented 5 years ago

Hi @mwittig. Did you get any further with this?

The issue seems to be that the pattern you are using in milight-v6-mixin.js on line 124 is not a patten that works well with promises. You start a setTimeout() inside the Promise constructor but, by the time it calls reject, it is outside the Promise and therefore cannot be caught.

A better way to do it would probably be to use Promise.race() with the main promise and a separate timer promise racing for completion.

Is this something you think you will get to in the near future?

Cliff.

CliffS commented 5 years ago

OK, I think I have fixed this by in my PR. https://github.com/mwittig/node-milight-promise/pull/67 At least it's now working for me.

mwittig commented 5 years ago

@CliffS Thanks for your PR. I'll look into this asap.

CliffS commented 5 years ago

@mwittig I think I have finally got to the bottom of this. My PR fails because of a race condition: it is possible for the reject() to hit before the Promise.reflect() masks it.

In any case, as far as I can see, the effect of the Promise.reflect() is to ignore the result of the original Promise. Thus in my latest version, I simply resolve() the promise rather than reject()ing it after a no response timeout.

If you're happy with this solution, I will update my PR to reflect it.

Cliff.

mwittig / node-milight-promise

Unhandled rejection Error: no response timeout #26

Addition