"Crashes" after timeout.

SilasT commented 6 years ago

I would really like if this could get fixed, and i would like to contribute in any way i can. This plugin does exactly what i need, and nothing like it exists elsewhere. I'll try to explain myself, the plugin works flawlessly until a timeout occurs, which will inevitably happen at some point when working with esp8266. It then drops this { [Error: ETIMEDOUT] code: 'ETIMEDOUT', connect: true } in the homebridge command line, and afterwards everything looks to work fine, but only in the console, every device from the specific homebridge server is not reachable from the Home app. This is the configuration i run:

{
            "name": "Kitchen Blinds",
            "accessory": "MinimalisticHttpBlinds",

            "get_current_position_url": "http://192.168.1.109/getpos/",
            "set_target_position_url": "http://192.168.1.109/setpos/%position%",
            "get_current_state_url": "http://192.168.1.109/getstate/",

            "get_current_position_method": "GET",
            "set_target_position_method": "GET",
            "get_current_state_method": "GET",

            "get_current_position_expected_response_code": "200",
            "set_target_position_expected_response_code": "200",
            "get_current_state_expected_response_code": "200",

            "get_current_position_polling_millis": "1500",
            "get_current_state_polling_millis": "1500"
        }

Silas.

Nicnl commented 6 years ago

This is very problematic indeed.

I received a few feedbacks just like this one, and I've been searching for the root cause of the issue since.
No luck so far.

I have a few questions:

- Are you able to reproduce it?
You said your homebridge setup goes haywire when a timeout occurs.
But does it occurs at every timeout?
Or just when a timeout happens... after a while?

- You said that 'every device from the specific homebridge server is not reachable'
You actually mean all devices on the homebridge serve?
Even the accessories not using homebridge-minimal-http-blinds?

- Can you provide a logfile?
That would be really helpful.

Thank you!

SilasT commented 6 years ago

I can reproduce it, i thought that it might just be a problem with my raspberry pi, and or its configuration. So i tried installing it on mac using homebrew, on 10.13.6 . With only this plugin and nothing else installed, with the same results.
On my pi, it happens with every device, none of the devices are reachable (same with mac), and it happens pretty much instantaneously.
Nothing is out of order in the log file, or at least in the log files that i know of.

Nothing seems wrong in the console after, when i access the home app, it prints out all the devices that it is "updating". But nothing happens in the app.

Nicnl commented 6 years ago

I see...
I'll try to reproduce it on my end when I have a bit of free time
I'll let you know

SilasT commented 6 years ago

Let me know how i can help further when you find out.

naiello01 commented 6 years ago

I see this as well with my WeMos board (ESP8266 based). Let me know if there anything else I can do to help.

KnicKnic commented 5 years ago

I can reproduce it with the sample webserver and restarting it a few times (ctrl-c). Sample is running on same server as homebridge. https://github.com/Nicnl/homebridge-minimal-http-blinds/blob/HEAD/EXAMPLE.MD

jowa0007 commented 5 years ago

I have the same problem and would love to use this plugin! There seems to be no alternative currently, so please don‘t let us down ;)

KnicKnic commented 5 years ago

It seems that if the callback handler is not called when opening the app (that depending on the ordering iphone / homebridge is waiting for the initial states). My guess is there is some serialize queue for the rest of the devices that share the same bridge. Perhaps you could initialize to a fake state, and complete the callbacks on error with the stale results.

Also it would be nice if there was no input since the last poll(or 2) of data to just immediately complete the handlers as this would allow the other inputs to answer quicker, and not have to wait for a poll to load the remaining devices in homekit. Specifically if the user changes their poll settings to have something longer.

I did make a change for the first suggestion https://github.com/KnicKnic/homebridge-minimal-http-blinds/compare/master...KnicKnic:knic/stale_cache?expand=1 edit Let me know if I should submit a PR for it. THX

Nicnl commented 5 years ago

@KnicKnic Wow, thank you

Are the issues corrected with your fix?

If you don't mind removing the old lines with undefined (as yours with 100 and 2 do the work) and removing one of the two complete_get_current_state_callbacks (it's there two times apparently),
I'd be happy to merge it

KnicKnic commented 5 years ago

@KnicKnic Wow, thank you

Are the issues corrected with your fix?

If you don't mind removing the old lines with undefined (as yours with 100 and 2 do the work) and removing one of the two complete_get_current_state_callbacks (it's there two times apparently), I'd be happy to merge it

@Nicnl The issues I was experiencing are fixed. No known regressions. I made the changes you suggested, though I changed 100 to 0. Closed fits with my expected use case more (garage door), not sure which is best for blinds. I then implemented the feature to enable faster loads using cached data if there have been no app related changes recently.

You might wonder why I said garage door for blinds. Well Apple decided that I have to unlock my phone to say "Hey siri close the garage door" if garage door is a security device. I understand why its the default behavior, however they do not let me override it. However with blinds I can still say "Hey siri close the garage door" and I do not need to unlock my phone. The first thing I found that I could say close with that wasn't security device was blinds. I assume it can also then be used in geo fencing with a locked phone (although I use another solution) (again garage doors require me to unlock my phone for geofence), really annoying.

Nicnl commented 5 years ago

@SilasT @naiello01 @jowa0007 Version 0.0.17 has been published on NPM. I'd be grateful if you could test it and report if the stability issues are resolved.

Let's all thank @KnicKnic who found how to fix it!

jowa0007 commented 5 years ago

Hi guys. Thanks for your effort. I just tested the new version 0.0.17 and as long as I have only 1 window configured everything seems to work. When I have 2 Windows configured the Error/Timeout is coming back: ... Error when polling current state. [2018-12-30 13:04:00] [Rollo Esszimmer] { Error: ESOCKETTIMEDOUT at ClientRequest. (/usr/local/lib/node_modules/homebridge-minimal-http-blinds/node_modules/request/request.js:816:19) at Object.onceWrapper (events.js:272:13) at ClientRequest.emit (events.js:180:13) at Socket.emitTimeout (_http_client.js:702:34) at Object.onceWrapper (events.js:272:13) at Socket.emit (events.js:180:13) at Socket._onTimeout (net.js:396:8) at ontimeout (timers.js:466:11) at tryOnTimeout (timers.js:304:5) at Timer.listOnTimeout (timers.js:267:5) code: 'ESOCKETTIMEDOUT', connect: false }

KnicKnic commented 5 years ago

@jowa0007 I just tested with 2 blinds, are you sure you configured the urls correctly? Are you receiving the error immediately when starting homebridge? I am able to interact with both blinds. More info would help me understand.

Though I did test with my latest https://github.com/Nicnl/homebridge-minimal-http-blinds/pull/10

jowa0007 commented 5 years ago

Hi @KnicKnic The URLs should be correct since I tested them all by themself and they work fine. When I configure 2 blinds the error is thrown immediately after I open up the home-App. I just tested it with 0.0.18. Is there any kind of log I can give you that would help? Thats how my config looks like:

{
    "name": "Rollo Büro",
    "accessory": "MinimalisticHttpBlinds",

    "get_current_position_url": "http://192.168.178.33/api/?action=get&marker=M28",
    "set_target_position_url": "http://192.168.178.33/api/?action=set&marker=M19&value=%position%",
    "get_current_state_url": "http://192.168.178.33/api/?action=get&marker=M29",
    "set_target_position_method": "GET",
    "set_target_position_expected_response_code": "200"
},
{
    "name": "Rollo Esszimmer",
    "accessory": "MinimalisticHttpBlinds",

    "get_current_position_url": "http://192.168.178.33/api/?action=get&marker=M30",
    "set_target_position_url": "http://192.168.178.33/api/?action=set&marker=M21&value=%position%",
    "get_current_state_url": "http://192.168.178.33/api/?action=get&marker=M31",
    "set_target_position_method": "GET",
    "set_target_position_expected_response_code": "200"
}

KnicKnic commented 5 years ago

The error is stating cannot get state for "Rollo Esszimmer" what does

curl "http://192.168.178.33/api/?action=get&marker=M31"
- should return 2 (assuming blind is not moving)
curl -v -I "http://192.168.178.33/api/?action=get&marker=M31"
- should contain line HTTP/1.0 200 OK

jowa0007 commented 5 years ago

yes
its HTTP/1.1 200 OK

johanneswall@MacBook-Pro-2 ~ $ curl "http://192.168.178.33/api/?action=get&marker=M31"
2
johanneswall@MacBook-Pro-2 ~ $ curl -v -I "http://192.168.178.33/api/?action=get&marker=M31"
*   Trying 192.168.178.33...
* TCP_NODELAY set
* Connected to 192.168.178.33 (192.168.178.33) port 80 (#0)
> HEAD /api/?action=get&marker=M31 HTTP/1.1
> Host: 192.168.178.33
> User-Agent: curl/7.54.0
> Accept: */*
>
< HTTP/1.1 200 OK
HTTP/1.1 200 OK
< Set-Cookie: comexio_session_id=mgba3d90rejmu0kfh85iurnde1; expires=Fri, 11-Jan-2019 09:44:21 GMT; path=/
Set-Cookie: comexio_session_id=mgba3d90rejmu0kfh85iurnde1; expires=Fri, 11-Jan-2019 09:44:21 GMT; path=/
< Set-Cookie: comexio_session_id=mgba3d90rejmu0kfh85iurnde1; expires=Fri, 11-Jan-2019 09:44:21 GMT; path=/
Set-Cookie: comexio_session_id=mgba3d90rejmu0kfh85iurnde1; expires=Fri, 11-Jan-2019 09:44:21 GMT; path=/
< Cache-Control: no-cache, no-store, max-age=0, must-revalidate
Cache-Control: no-cache, no-store, max-age=0, must-revalidate
< Expires: Mon, 26 Jul 1997 05:00:00 GMT
Expires: Mon, 26 Jul 1997 05:00:00 GMT
< Pragma: no-cache
Pragma: no-cache
< Content-Type: text/plain; charset=utf-8
Content-Type: text/plain; charset=utf-8
< X-Powered-By: COMEXIO
X-Powered-By: COMEXIO
< Date: Fri, 04 Jan 2019 09:44:21 GMT
Date: Fri, 04 Jan 2019 09:44:21 GMT
< Server: comexio
Server: comexio

<
* Connection #0 to host 192.168.178.33 left intact

KnicKnic commented 5 years ago

@jowa0007 First I want to point out you gave the output for marker=30 instead of marker=31. I am going to assume they test both and they were 200. You could update the logging in the code so that it states what url it is attempting. On line https://github.com/Nicnl/homebridge-minimal-http-blinds/blob/48ee7c9f46c5e667bc4ba7456d23bd2d134e5b86/index.js#L191 before the requst add something like this.log('state url [' + this.get_current_state_url + ']');

Also it is just "Rollo Esszimmer" that is failing in the logs, or is "Rollo Büro" also failing.

jowa0007 commented 5 years ago

Sry about the wrong Marker. It is the same result with both of them but I updated my last comment. In my last tests it was always the "Rollo Esszimmer" failing but it was also always the second in the configuration. I will try to set "Rollo Büro" as second config and post my results with the new logging.

jowa0007 commented 5 years ago

I just tested 2 blinds with different orders. The error always occurs on the second configured blind. I could not manage to find out where the installed plugin is. So I can't make the change with the log-output. I am using the homebridge-App for iOS for managing all plugins and homebridge...

Nicnl / homebridge-minimal-http-blinds

"Crashes" after timeout. #5