chendo / lifx-http

A HTTP API for controlling LIFX devices.
MIT License
91 stars 13 forks source link

ERROR Timeout::Error occurs after idle for a while - more frequently with 1.5 bulb firmware! #16

Open Bluebie opened 10 years ago

Bluebie commented 10 years ago
- -> /lights/tag:Cyberspace/color?duration=2&hue=0&saturation=0.80&brightness=0.20&_method=put
[2014-09-09 23:43:54] ERROR Timeout::Error: Timeout::Error
    /Library/Ruby/Gems/2.0.0/gems/lifx-0.4.5/lib/lifx/utilities.rb:27:in `rescue in try_until'
    /Library/Ruby/Gems/2.0.0/gems/lifx-0.4.5/lib/lifx/utilities.rb:9:in `try_until'
    /Library/Ruby/Gems/2.0.0/gems/lifx-0.4.5/lib/lifx/network_context.rb:104:in `sync'
    /Library/Ruby/Gems/2.0.0/gems/lifx-0.4.5/lib/lifx/client.rb:90:in `sync'
    /Library/Ruby/Gems/2.0.0/gems/lifx-http-0.2.3/lib/lifx-http.rb:156:in `block (3 levels) in <class:API>'
    /Library/Ruby/Gems/2.0.0/gems/grape-0.9.0/lib/grape/endpoint.rb:45:in `call'
    /Library/Ruby/Gems/2.0.0/gems/grape-0.9.0/lib/grape/endpoint.rb:45:in `block in generate_api_method'
    /Library/Ruby/Gems/2.0.0/gems/grape-0.9.0/lib/grape/endpoint.rb:220:in `call'
    /Library/Ruby/Gems/2.0.0/gems/grape-0.9.0/lib/grape/endpoint.rb:220:in `run'
    /Library/Ruby/Gems/2.0.0/gems/grape-0.9.0/lib/grape/endpoint.rb:171:in `block in call!'
    /Library/Ruby/Gems/2.0.0/gems/grape-0.9.0/lib/grape/middleware/base.rb:24:in `call'
    /Library/Ruby/Gems/2.0.0/gems/grape-0.9.0/lib/grape/middleware/base.rb:24:in `call!'
    /Library/Ruby/Gems/2.0.0/gems/grape-0.9.0/lib/grape/middleware/base.rb:18:in `call'
    /Library/Ruby/Gems/2.0.0/gems/grape-0.9.0/lib/grape/middleware/error.rb:27:in `block in call!'
    /Library/Ruby/Gems/2.0.0/gems/grape-0.9.0/lib/grape/middleware/error.rb:26:in `catch'
    /Library/Ruby/Gems/2.0.0/gems/grape-0.9.0/lib/grape/middleware/error.rb:26:in `call!'
    /Library/Ruby/Gems/2.0.0/gems/grape-0.9.0/lib/grape/middleware/base.rb:18:in `call'
    /Library/Ruby/Gems/2.0.0/gems/rack-1.5.2/lib/rack/head.rb:11:in `call'
    /Library/Ruby/Gems/2.0.0/gems/rack-1.5.2/lib/rack/builder.rb:138:in `call'
    /Library/Ruby/Gems/2.0.0/gems/grape-0.9.0/lib/grape/endpoint.rb:172:in `call!'
    /Library/Ruby/Gems/2.0.0/gems/grape-0.9.0/lib/grape/endpoint.rb:160:in `call'
    /Library/Ruby/Gems/2.0.0/gems/rack-mount-0.8.3/lib/rack/mount/route_set.rb:152:in `block in call'
    /Library/Ruby/Gems/2.0.0/gems/rack-mount-0.8.3/lib/rack/mount/code_generation.rb:96:in `block in recognize'
    /Library/Ruby/Gems/2.0.0/gems/rack-mount-0.8.3/lib/rack/mount/code_generation.rb:89:in `optimized_each'
    /Library/Ruby/Gems/2.0.0/gems/rack-mount-0.8.3/lib/rack/mount/code_generation.rb:95:in `recognize'
    /Library/Ruby/Gems/2.0.0/gems/rack-mount-0.8.3/lib/rack/mount/route_set.rb:141:in `call'
    /Library/Ruby/Gems/2.0.0/gems/grape-0.9.0/lib/grape/api.rb:128:in `call'
    /Library/Ruby/Gems/2.0.0/gems/grape-0.9.0/lib/grape/api.rb:43:in `call!'
    /Library/Ruby/Gems/2.0.0/gems/grape-0.9.0/lib/grape/api.rb:39:in `call'
    /Library/Ruby/Gems/2.0.0/gems/rack-cors-0.2.9/lib/rack/cors.rb:54:in `call'
    /Library/Ruby/Gems/2.0.0/gems/lifx-http-0.2.3/lib/lifx-http/method_override.rb:19:in `call'
    /Library/Ruby/Gems/2.0.0/gems/rack-1.5.2/lib/rack/builder.rb:138:in `call'
    /Library/Ruby/Gems/2.0.0/gems/rack-1.5.2/lib/rack/handler/webrick.rb:60:in `service'
    /System/Library/Frameworks/Ruby.framework/Versions/2.0/usr/lib/ruby/2.0.0/webrick/httpserver.rb:138:in `service'
    /System/Library/Frameworks/Ruby.framework/Versions/2.0/usr/lib/ruby/2.0.0/webrick/httpserver.rb:94:in `run'
    /System/Library/Frameworks/Ruby.framework/Versions/2.0/usr/lib/ruby/2.0.0/webrick/server.rb:295:in `block in start_thread'

On standard up to date mac os mavericks, with standard ruby 2.0. Previously I had to restart lifx-http every few days to get it working again. Since updating to the 1.5 bulb firmware from 1.3, it seems to break after a few hours. Totally unreliable. I don't know if this issue belongs on the lifx gem or this.. Hopefully @chendo can figure that puzzle out?

ristomatti commented 9 years ago

@Bluebie, have you figured out a fix for this? I haven't seen this particular error but the server seems to stop responding after few hours of idle time. I also have the 1.5 firmware on my bulb.

I'm a developer myself but have no ruby experience. I did some digging on the lifx-http files and noticed it is using lifx gem 0.4.5 but I also seem to have version 0.4.11 installed. So maybe it would require a newer version of the lifx gem?

Too bad to see so little updates to lifx-http and also lifx gem. I really like the hardware and would like to buy another bulb but since there doesn't seem to be a reliable application to control the bulb from my home server it seems like a bad idea.

I also wrote my own AngularJS based web app to control the lights through this REST API since lifx-http-client seemed too restricted (only on/off toggle) and would like to make it available through Github but that also seems a bit pointless in this situation. But have to see, maybe I'll try to learn some ruby and try to fix this issue and make a pull request or a fork if @chendo doesn't have time or interest to look into this issue. :)

ristomatti commented 9 years ago

Ok now I got the same error as @Bluebie. Using Ruby 2.1.3 and experimenting with newer versions of the LIFX gem.

[2014-10-21 20:42:59] INFO  WEBrick 1.3.1
[2014-10-21 20:42:59] INFO  ruby 2.1.3 (2014-09-19) [x86_64-linux-gnu]
[2014-10-21 20:42:59] INFO  WEBrick::HTTPServer#start: pid=49847 port=56780
....
localhost - - [22/Oct/2014:00:31:27 EEST] "PUT /lights/all/color HTTP/1.0" 500 392
http://localhost/nglifx/ -> /lights/all/color
[2014-10-22 00:31:33] ERROR Timeout::Error: Timeout::Error
        /var/lib/gems/2.1.0/gems/lifx-0.4.6.1/lib/lifx/utilities.rb:27:in `rescue in try_until'
        /var/lib/gems/2.1.0/gems/lifx-0.4.6.1/lib/lifx/utilities.rb:9:in `try_until'
        /var/lib/gems/2.1.0/gems/lifx-0.4.6.1/lib/lifx/network_context.rb:104:in `sync'
        /var/lib/gems/2.1.0/gems/lifx-0.4.6.1/lib/lifx/client.rb:91:in `sync'
        /home/ristomatti/dev/lifx-http/lib/lifx-http.rb:156:in `block (3 levels) in <class:API>'
        /var/lib/gems/2.1.0/gems/grape-0.9.0/lib/grape/endpoint.rb:45:in `call'
        /var/lib/gems/2.1.0/gems/grape-0.9.0/lib/grape/endpoint.rb:45:in `block in generate_api_method'
        /var/lib/gems/2.1.0/gems/grape-0.9.0/lib/grape/endpoint.rb:220:in `call'
        /var/lib/gems/2.1.0/gems/grape-0.9.0/lib/grape/endpoint.rb:220:in `run'
        /var/lib/gems/2.1.0/gems/grape-0.9.0/lib/grape/endpoint.rb:171:in `block in call!'
        /var/lib/gems/2.1.0/gems/grape-0.9.0/lib/grape/middleware/base.rb:24:in `call'
        /var/lib/gems/2.1.0/gems/grape-0.9.0/lib/grape/middleware/base.rb:24:in `call!'
        /var/lib/gems/2.1.0/gems/grape-0.9.0/lib/grape/middleware/base.rb:18:in `call'
        /var/lib/gems/2.1.0/gems/grape-0.9.0/lib/grape/middleware/error.rb:27:in `block in call!'
        /var/lib/gems/2.1.0/gems/grape-0.9.0/lib/grape/middleware/error.rb:26:in `catch'
        /var/lib/gems/2.1.0/gems/grape-0.9.0/lib/grape/middleware/error.rb:26:in `call!'
        /var/lib/gems/2.1.0/gems/grape-0.9.0/lib/grape/middleware/base.rb:18:in `call'
        /var/lib/gems/2.1.0/gems/rack-1.5.2/lib/rack/head.rb:11:in `call'
        /var/lib/gems/2.1.0/gems/rack-1.5.2/lib/rack/builder.rb:138:in `call'
        /var/lib/gems/2.1.0/gems/grape-0.9.0/lib/grape/endpoint.rb:172:in `call!'
        /var/lib/gems/2.1.0/gems/grape-0.9.0/lib/grape/endpoint.rb:160:in `call'
        /var/lib/gems/2.1.0/gems/rack-mount-0.8.3/lib/rack/mount/route_set.rb:152:in `block in call'
        /var/lib/gems/2.1.0/gems/rack-mount-0.8.3/lib/rack/mount/code_generation.rb:96:in `block in recognize'
        /var/lib/gems/2.1.0/gems/rack-mount-0.8.3/lib/rack/mount/code_generation.rb:89:in `optimized_each'
        /var/lib/gems/2.1.0/gems/rack-mount-0.8.3/lib/rack/mount/code_generation.rb:95:in `recognize'
        /var/lib/gems/2.1.0/gems/rack-mount-0.8.3/lib/rack/mount/route_set.rb:141:in `call'
        /var/lib/gems/2.1.0/gems/grape-0.9.0/lib/grape/api.rb:128:in `call'
        /var/lib/gems/2.1.0/gems/grape-0.9.0/lib/grape/api.rb:43:in `call!'
        /var/lib/gems/2.1.0/gems/grape-0.9.0/lib/grape/api.rb:39:in `call'
        /var/lib/gems/2.1.0/gems/rack-cors-0.2.9/lib/rack/cors.rb:54:in `call'
        /home/ristomatti/dev/lifx-http/lib/lifx-http/method_override.rb:19:in `call'
        /var/lib/gems/2.1.0/gems/rack-1.5.2/lib/rack/builder.rb:138:in `call'
        /var/lib/gems/2.1.0/gems/rack-1.5.2/lib/rack/handler/webrick.rb:60:in `service'
        /usr/lib/ruby/2.1.0/webrick/httpserver.rb:138:in `service'
        /usr/lib/ruby/2.1.0/webrick/httpserver.rb:94:in `run'
        /usr/lib/ruby/2.1.0/webrick/server.rb:295:in `block in start_thread'

I'm now running an experiment with LIFX 0.4.11. Will have to wait before I see if it fails again (which I assume it will).

Bluebie commented 9 years ago

I never found a fix. Having older rubygems installed shouldn't cause conflict. Rubygems can have multiple versions concurrently installed, and different apps and libraries can require the specific version they want. If you don't feel like giving up, you could try playing with the unofficial lifx node.js implementation that existed before lifx released any developer libraries. It seemed more stable: https://github.com/magicmonkey/lifxjs and seems to still be getting updates. My bulbs glitch out frequently even when I don't use the ruby or javascript stuff at all, so I think probably just lifx as a whole company suck at building stable software. pretty fed up.

For whatever it's worth, some of my friends have Hue systems and they say they've been very reliable.

As another sidenote: lifx don't do refunds for kickstarter backers. Another thing I discovered when talking to them :P

ristomatti commented 9 years ago

Thanks for the tip. I tried some Node.js ones first as I'm more familiar with it but they felt a bit buggy. I guess as all of them are based on reverse engineering the protocol. But maybe have to try if I run into a wall with this Ruby stuff I'm completely new to.

Personally I haven't had any issues with the bulb itself, only software related. But then again I bought it from a retailer only about 6 months ago so maybe they have done changes to the hardware itself. In the beginning the Android app was horrible but it has become quite reliable for me (only thing is randomly disappearing/appearing scene settings).

Too bad to hear about your issues, an unfortunately price to pay for backing the project up. I read some comparison articles between Hue and LIFX before buying it. The Hue lamps apparently have lower lux levels and aren't so good with white colors (no separate white LED to my understanding) so I would really like to get this one working at least 95% flawlessly and then buy more units.

I have now had lifx-http running since last night with the latest LIFX gem set in the gemspec and it hasn't timed out yet at least (it's been a matter of few hours) so having fingers crossed.

chendo commented 9 years ago

Hey fellas, been super busy with work so I haven't had time to work on my own projects as much.

We've figured out an issue that should fix the flakiness you might be seeing which will be in the next update (assuming it's the same issue)

ristomatti commented 9 years ago

Great to hear! I assume you have already then tried with newer LIFX gem versions? I'll probably see later today if the same problem occurs with the latest version.

ristomatti commented 9 years ago

I'm now running the third day without issues after the gemspec change: spec.add_dependency "lifx", "~> 0.4.11". This is double the time I've had it running without issues than with the "= 4.5" gemspec setting.

What was strange was that before I could get lifx-http running without crashing I had to remove older versions of the lifx gem. As I mentined before I haven't been exposed to Ruby prior to this so I guess there's a chance I just didn't know how to do this properly. The only thing I did was clone the repository, change gemspec and run "bundle install" (and later removed the older versions of the lifx gem as I noticed references to them in the error stack traces).

@Bluebie, you should try this also if you haven't already! It would only seem logical to me that upgrading the bulb firmware might also require a newer version of the API. I wouldn't have even run across this project unless LIFXtend (the only Windows LIFX application) stopped working after the bulb firmware update and I needed a way to control the bulb from my computer.

Bluebie commented 9 years ago

I can't properly test it currently - the recent storm in Sydney knocked out a lot of internet access and has made my antique ADSL much worse. My LIFX bulbs cannot contact internet time reliably, and the TCP stack on my computers and wifi devices are getting confused by the extreme intermittent packet loss. I can't even connect to a computer right beside me a lot of the time. I understand lifx is udp-powered now, but the actual connection to the lifx-http daemon is over TCP, which I can't reliably use. So I can't make any meaningful comparisons on reliability for a while yet.

ristomatti commented 9 years ago

Huh, sounds like no storm ever seen here! But let me know when you are able to test.

ristomatti commented 9 years ago

Update: after three days of working perfectly got the same error as previously. So the only hope is the fix @chendo had in mind. If there is anything I can help with please let me know! I really like the REST API concept and it seems a bit too overwhelming to start learning Ruby to try to implement something myself (bad luck in API language lottery). And anyway, even if this will never be fixed this has been an interesting exercise trying to understand at least something from the Ruby world. :)

chendo commented 9 years ago

I know it's not a proper solution, but you could use cron to restart it every day >_>

Ruby is pretty easy to pick up (IMO). Either way, it should be resolved (or at least significantly improved) with next firmware update, assuming the issue you're having is the issue we've resolved

ristomatti commented 9 years ago

That's a good point. Just create a script that kills the process once in an hour or so and restarts the server and the problem is basically gone. Of course it's against all the principles I have for choosing the software to use, but in this case it's actually a reasonable option as it's not about business critical stuff and there really is no alternative anyway. :)

But what it still unfortunately does is lower my motivation to build my first open source project on top of it (the UI I mentioned earlier which I would love to develop furher from this one purpose tool to a more configurable one)...

So you believe it could have something to do with the firmware? It seems odd as the bulb has worked without any physical intervention since I bought it (for several months). Or is it just something on the next firmware that could fix the bug that causes the software to time out (just curious)?

What goes with Ruby being easy to pick up, can't say much about that. As a Java developer (and lately JavaScript in the form of AngularJS and Node.js) it seems like another world). But regardless of it being easy to pick up or not maybe solving an issue like this is a little bit more advanced topic than something to do as the first project. :)

chendo commented 9 years ago

To be specific, the problem is not in our part of the firmware, rather the black box WiFi stack that we have to use, but we've worked around the issue. The timeouts happen when it doesn't receive a response from a device in time, which could be due to WiFi interference at that point in time or other network issues.

Does it reliably continue to throw TimeoutErrors once it starts? And if it's in that state, is the bulb still controllable by the app? Or does simply restarting lifx-http fix the issue?

ristomatti commented 9 years ago

Ok thank you for the clarification. Once it happens lifx-http becomes unresponsive to any other actions than light off. During that time controlling the lamp with the Android app works fine. And restarting lifx-http always fixes the issue for an undetermined time ranging from two hours to days.

Could a try catch of some sort (not sure what is the Ruby equivalent) and trying to reconnect to the bulb help? To me it seems like timing out renders the app to a state it can't recover from even though meanwhile the bulb can be accessed.

If there's something specific I could try out to help resolving this just let me know. Also thank you for responding to this thread!