Closed svwb22 closed 7 years ago
I got the same problem, this bug came in one of the last updates. I had running a old version of this plugin without any problems. Is there any solution?
Well.. I've taken a HomeKit app (Eve in this case) and toggled one switch off and on again. At some point I have the same situation: The commands are being sent but no switches anymore.
Then I've switched to the remote web control of pilight. And it looks like that even pilight itself cannot change the switches anymore. Can you confirm this?
My pi is running pilight 7.0
The icon in Apples Home App, the webinterface button and the device itself are flashing on and off, when I switch the device on and off in under 1sec. Only a restart of the Homebridge service will stop the flashing.
Perhaps it was not clear enough: If I cannot change the state via pilights web interface anymore (that's why I am asking for), the issue is probably not in the homebridge stack.
Also: Do you get a real automatic (infinite) on/off-loop, or only a non-working and on-demand on/off-function?
I get a infinite On/off-loop
+1
Also got this with my 433MHz power switches controlled by pilight. Gets into an infinite loop. Pressing the flashing button in iOS also doesn't help to interrupt the loop.
@knalli To answer your question: While the infinite loop is happening (when I try to switch a 433MHz power switch), then I can go to pilight web interface and control other switches by turning them on and off. And I can also see the switch that is in the loop playing ping pong with "on" and "off" state in the web interface.
There is one strange thing to be mentioned though: While I was in the pilight web interface and turning one of the other switches... at some point suddenly one of those switches also starts to go into the infinite loop! To stop all this I had top restart my homebridge service on my Raspberry Pi again. I did not restart the pilight service, though.
One more thing: When I use the Eve app and try to do the switing in the "Rooms" tab of the app, then I have never observed that any switch goes into an infinite loop. But when I perform switching in the "At a Glance" tab, then sometimes it could happen that the switches go wild.
What is your configuration in pilight regarding sending and receiving? Do you have a receiver installed, or only sender? Do do you have repeats more than 1?
For me: only sender installed. Repeats not explicitly set in config aka default. Built pilight from source from development branch (about a week ago).
Update: protocol is "quigg_gt7000".
I'm using pilight 7.0 and I also do not have any "repeats" set explicitly. Only the sender hardware is atttached to my Raspberry Pi 3. Additionally I'm using "protocol": ["intertechno_switch" ]
in the config.json for the power switches.
In my config I have following values for "hardware" section:
"hardware": {
"433gpio": {
"sender": 3,
"receiver": 4
}
}
I also have only a sender installed. The protocol is "Clarus_Switch" and the homebridge is running on a Raspberry first gen.
I've published 1.4.0-beta.1
providing additional log lines if env HOMEBRIDGE_PILIGHT_TRACE=1
is set. Depends on your system, maybe a prepended export HOMEBRIDGE_PILIGHT_TRACE=1
is enough.
Also: Are you using the feature sharedWS
? It's opt-in, so default would be false.
I have the same issue!
But first: Thank you sooo much for your great work - it was very straightforward to get very nice integration of homekit-homebridge-pilight to control my 433Mhz switches from my iphone! Very cool!
Here are some details to help fix the infinite loop issue:
1.4.0-beta.1
"protocol": [ "quigg_gt7000" ]
"sharedWS": false
Steps to get to the infinite loop: in Apple Home app, toggle any switch on and off quickly.
Steps to stop infinite loop: stop homebridge process with ctrl+c start homebridge again.
oddly, export HOMEBRIDGE_PILIGHT_TRACE=1
did not result in any additional traces that I could see...
Full Log of a testcase (with my actions added):
pi@raspberrypi:~ $ sudo service pilight stop
pi@raspberrypi:~ $ export HOMEBRIDGE_PILIGHT_TRACE=1
pi@raspberrypi:~ $ sudo service pilight start
pi@raspberrypi:~ $ homebridge
*** WARNING *** The program 'nodejs' uses the Apple Bonjour compatibility layer of Avahi.
*** WARNING *** Please fix your application to use the native API of Avahi!
*** WARNING *** For more information see <http://0pointer.de/avahi-compat?s=libdns_sd&e=nodejs>
*** WARNING *** The program 'nodejs' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
*** WARNING *** Please fix your application to use the native API of Avahi!
*** WARNING *** For more information see <http://0pointer.de/avahi-compat?s=libdns_sd&e=nodejs&f=DNSServiceRegister>
[2/18/2017, 10:46:41 AM] Loaded plugin: homebridge-pilight
[2/18/2017, 10:46:42 AM] Registering accessory 'homebridge-pilight.pilight'
[2/18/2017, 10:46:42 AM] ---
[2/18/2017, 10:46:42 AM] Loaded config.json with 7 accessories and 0 platforms.
[2/18/2017, 10:46:42 AM] ---
[2/18/2017, 10:46:42 AM] Loading 0 platforms...
[2/18/2017, 10:46:42 AM] Loading 7 accessories...
[2/18/2017, 10:46:42 AM] [70er Lampe] Initializing pilight accessory...
[2/18/2017, 10:46:42 AM] [70er Lampe] Option sharedWS = false
[2/18/2017, 10:46:42 AM] [70er Lampe] Connecting to "ws://localhost:5001/"
[2/18/2017, 10:46:42 AM] [Sofalampe] Initializing pilight accessory...
[2/18/2017, 10:46:42 AM] [Sofalampe] Option sharedWS = false
[2/18/2017, 10:46:42 AM] [Sofalampe] Connecting to "ws://localhost:5001/"
[2/18/2017, 10:46:42 AM] [Pilzlampe] Initializing pilight accessory...
[2/18/2017, 10:46:42 AM] [Pilzlampe] Option sharedWS = false
[2/18/2017, 10:46:42 AM] [Pilzlampe] Connecting to "ws://localhost:5001/"
[2/18/2017, 10:46:42 AM] [Lichterkette] Initializing pilight accessory...
[2/18/2017, 10:46:42 AM] [Lichterkette] Option sharedWS = false
[2/18/2017, 10:46:42 AM] [Lichterkette] Connecting to "ws://localhost:5001/"
[2/18/2017, 10:46:42 AM] [Kuechentisch] Initializing pilight accessory...
[2/18/2017, 10:46:42 AM] [Kuechentisch] Option sharedWS = false
[2/18/2017, 10:46:42 AM] [Kuechentisch] Connecting to "ws://localhost:5001/"
[2/18/2017, 10:46:42 AM] [Kuechentisch-2] Initializing pilight accessory...
[2/18/2017, 10:46:42 AM] [Kuechentisch-2] Option sharedWS = false
[2/18/2017, 10:46:42 AM] [Kuechentisch-2] Connecting to "ws://localhost:5001/"
[2/18/2017, 10:46:42 AM] [Dim] Initializing pilight accessory...
[2/18/2017, 10:46:42 AM] [Dim] Option sharedWS = false
[2/18/2017, 10:46:42 AM] [Dim] Connecting to "ws://localhost:5001/"
Scan this code with your HomeKit App on your iOS device to pair with Homebridge:
┌────────────┐
│ 123-45-678 │
└────────────┘
[2/18/2017, 10:46:42 AM] Homebridge is running on port 51826.
[2/18/2017, 10:46:42 AM] [70er Lampe] WebSocket connection established!
[2/18/2017, 10:46:42 AM] [70er Lampe] Requesting initial states...
[2/18/2017, 10:46:42 AM] [Sofalampe] WebSocket connection established!
[2/18/2017, 10:46:42 AM] [Sofalampe] Requesting initial states...
[2/18/2017, 10:46:42 AM] [Pilzlampe] WebSocket connection established!
[2/18/2017, 10:46:42 AM] [Pilzlampe] Requesting initial states...
[2/18/2017, 10:46:42 AM] [Lichterkette] WebSocket connection established!
[2/18/2017, 10:46:42 AM] [Lichterkette] Requesting initial states...
[2/18/2017, 10:46:42 AM] [Kuechentisch] WebSocket connection established!
[2/18/2017, 10:46:42 AM] [Kuechentisch] Requesting initial states...
[2/18/2017, 10:46:42 AM] [Kuechentisch-2] WebSocket connection established!
[2/18/2017, 10:46:42 AM] [Kuechentisch-2] Requesting initial states...
[2/18/2017, 10:46:42 AM] [Dim] WebSocket connection established!
[2/18/2017, 10:46:42 AM] [Dim] Requesting initial states...
[2/18/2017, 10:46:42 AM] [70er Lampe] Initialized device with state "off"
[2/18/2017, 10:46:42 AM] [Sofalampe] Initialized device with state "off"
[2/18/2017, 10:46:42 AM] [Pilzlampe] Initialized device with state "off"
[2/18/2017, 10:46:42 AM] [Lichterkette] Initialized device with state "off"
[2/18/2017, 10:46:42 AM] [Kuechentisch] Initialized device with state "off"
[2/18/2017, 10:46:42 AM] [Kuechentisch-2] Initialized device with state "up"
[2/18/2017, 10:46:42 AM] [Dim] Initialized device with state "on"
-----my action: turn on from Home app on iPhone ----
[2/18/2017, 10:46:49 AM] [70er Lampe] Try to set powerstate to "on"
[2/18/2017, 10:46:50 AM] [70er Lampe] Updated internal state to "on"
[2/18/2017, 10:46:50 AM] [70er Lampe] Try to set powerstate to "on"
-----my action: turn off from Home app on iPhone ----
[2/18/2017, 10:46:54 AM] [70er Lampe] Try to set powerstate to "off"
[2/18/2017, 10:46:55 AM] [70er Lampe] Updated internal state to "off"
[2/18/2017, 10:46:55 AM] [70er Lampe] Try to set powerstate to "off"
-----my action: turn on and off really quickly from Home app on iPhone ----
[2/18/2017, 10:47:00 AM] [70er Lampe] Try to set powerstate to "on"
[2/18/2017, 10:47:00 AM] [70er Lampe] Try to set powerstate to "off"
-----infinite loop begins----
[2/18/2017, 10:47:01 AM] [70er Lampe] Updated internal state to "on"
[2/18/2017, 10:47:01 AM] [70er Lampe] Try to set powerstate to "on"
[2/18/2017, 10:47:01 AM] [70er Lampe] Updated internal state to "off"
[2/18/2017, 10:47:01 AM] [70er Lampe] Try to set powerstate to "off"
[2/18/2017, 10:47:02 AM] [70er Lampe] Updated internal state to "on"
[2/18/2017, 10:47:02 AM] [70er Lampe] Try to set powerstate to "on"
[2/18/2017, 10:47:02 AM] [70er Lampe] Updated internal state to "off"
[2/18/2017, 10:47:02 AM] [70er Lampe] Try to set powerstate to "off"
[2/18/2017, 10:47:03 AM] [70er Lampe] Updated internal state to "on"
[2/18/2017, 10:47:03 AM] [70er Lampe] Try to set powerstate to "on"
[2/18/2017, 10:47:03 AM] [70er Lampe] Updated internal state to "off"
[2/18/2017, 10:47:03 AM] [70er Lampe] Try to set powerstate to "off"
[2/18/2017, 10:47:04 AM] [70er Lampe] Updated internal state to "on"
[2/18/2017, 10:47:04 AM] [70er Lampe] Try to set powerstate to "on"
[2/18/2017, 10:47:04 AM] [70er Lampe] Updated internal state to "off"
[2/18/2017, 10:47:04 AM] [70er Lampe] Try to set powerstate to "off"
[2/18/2017, 10:47:05 AM] [70er Lampe] Updated internal state to "on"
[2/18/2017, 10:47:05 AM] [70er Lampe] Try to set powerstate to "on"
[2/18/2017, 10:47:05 AM] [70er Lampe] Updated internal state to "off"
[2/18/2017, 10:47:05 AM] [70er Lampe] Try to set powerstate to "off"
[2/18/2017, 10:47:06 AM] [70er Lampe] Updated internal state to "on"
[2/18/2017, 10:47:06 AM] [70er Lampe] Try to set powerstate to "on"
[2/18/2017, 10:47:06 AM] [70er Lampe] Updated internal state to "off"
[2/18/2017, 10:47:06 AM] [70er Lampe] Try to set powerstate to "off"
^C[2/18/2017, 10:47:07 AM] Got SIGINT, shutting down Homebridge...
pi@raspberrypi:~ $
-----after killing homebridge, just start it again, and everything is fine----
pi@raspberrypi:~ $ homebridge
....
My observation:
The output [2/18/2017, 10:46:50 AM] [70er Lampe] Updated internal state to "on"
comes with a delay of about 1s after [2/18/2017, 10:46:49 AM] [70er Lampe] Try to set powerstate to "on"
and is followed by another command [2/18/2017, 10:46:50 AM] [70er Lampe] Try to set powerstate to "on"
which I did not issue.
My diagnosis: If you toggle to off again within that 1s delay between the on command and the internal state updating to on (see log at 10:47:00), then as soon as the state gets updated, it starts to "work on" the next command - turning it off. However, since that additional command to turn it on is somehow appended as observed, this gets put into the command queue right after the off command, but before the internal state is updated to off, hence starting the infinite loop.
My conclusion: I'd say that that extra command that is issued again even though the internal state has been set already, is what is causing the problem.
The problem is I don't know where that extra command is coming from - I have set any explicit repeats. Since I don't need to restart pilight to stop the loop, I am quite sure this is not where the problem lies. My assumption is that it's either homebridge or homebridge-pilight, but I haven't looked at either code to figure it out myself - I'm sure you'd be much quicker ;-)
I hope this helps, and thanks already for any fix ;-)
thefool
@thefool Thank you for the diagnosis. However, it seems you don't have HOMEBRIDGE_PILIGHT_TRACE
set correctly. I've created a simple start script for that:
"scripts": {
"start": "export HOMEBRIDGE_PILIGHT_TRACE=1; homebridge --plugin-path plugins"
}
I have tweaked the logging to the more relevant part, available at 1.4.0-beta.2
.
Something likes this
[2/18/2017, 3:48:56 PM] [Bulb1] Try to set powerstate to "on"
[2/18/2017, 3:48:57 PM] [Bulb1] TRACE: handleMessage: item={"origin":"update","type":1,"devices":["bulb1"],"values":{"timestamp":1487429336,"state":"on"}}
[2/18/2017, 3:48:57 PM] [Bulb1] Updated internal state to "on"
[2/18/2017, 3:48:57 PM] [Bulb1] Try to set powerstate to "off"
[2/18/2017, 3:48:58 PM] [Bulb1] TRACE: handleMessage: item={"origin":"update","type":1,"devices":["bulb"],"values":{"timestamp":1487429338,"state":"off"}}
[2/18/2017, 3:48:58 PM] [Bulb1] Updated internal state to "off"
The additional line is the payload of the pilight socket. If this is different, we probably have different messages. If they are equal, well, we'll have to investigate why they are processed multiple times.
I'm not quite sure where you expect me to put the script or how to run it. I'm currently running homebridge straight from the shell (logged in via ssh pi@raspberrypi
):
pi@raspberrypi:~ $ homebridge
(running it as a service is one of the next items on my todo list, but I wanted it to run smoothly first)
After calling export HOMEBRIDGE_PILIGHT_TRACE=1
(which I do before running homebridge) When I check the Enivronment Variables, it seems to be set correctly:
pi@raspberrypi:~ $ set | grep TRACE
I get:
HOMEBRIDGE_PILIGHT_TRACE=1
Sorry for my ignorance: I'm new to RaspberryPi, node.js, json, homebridge and everything ;-) I've only spent around 8 hours with all that, and am super happy to have a working homekit installation in my house in that time!
OK, my bad.
I had initially installed homebridge-pilight like this:
sudo npm install -g homebridge-pilight
and installed the beta like so:
sudo npm install homebridge-pilight@1.4.0-beta.2
I now tried again:
sudo npm install -g homebridge-pilight@1.4.0-beta.2 --unsafe-perm
and voila, my export HOMEBRIDGE_PILIGHT_TRACE=1
does seem to work.
I'm also not getting the second command anymore, so no more infinite loop! Hooray!
my latest log:
[2/18/2017, 5:22:11 PM] [70er Lampe] TRACE: handleMessage: item={"origin":"update","type":1,"devices":["Lampe1"],"values":{"timestamp":1487434930,"state":"on"}}
[2/18/2017, 5:22:11 PM] [70er Lampe] Updated internal state to "on"
[2/18/2017, 5:22:12 PM] [70er Lampe] Try to set powerstate to "off"
[2/18/2017, 5:22:13 PM] [70er Lampe] TRACE: handleMessage: item={"origin":"update","type":1,"devices":["Lampe1"],"values":{"timestamp":1487434932,"state":"off"}}
[2/18/2017, 5:22:13 PM] [70er Lampe] Updated internal state to "off"
[2/18/2017, 5:22:18 PM] [70er Lampe] Try to set powerstate to "on"
[2/18/2017, 5:22:19 PM] [70er Lampe] TRACE: handleMessage: item={"origin":"update","type":1,"devices":["Lampe1"],"values":{"timestamp":1487434939,"state":"on"}}
[2/18/2017, 5:22:19 PM] [70er Lampe] Updated internal state to "on"
[2/18/2017, 5:22:19 PM] [70er Lampe] Try to set powerstate to "off"
[2/18/2017, 5:22:20 PM] [70er Lampe] TRACE: handleMessage: item={"origin":"update","type":1,"devices":["Lampe1"],"values":{"timestamp":1487434940,"state":"off"}}
[2/18/2017, 5:22:20 PM] [70er Lampe] Updated internal state to "off"
[2/18/2017, 5:22:25 PM] [70er Lampe] Try to set powerstate to "on"
[2/18/2017, 5:22:26 PM] [70er Lampe] TRACE: handleMessage: item={"origin":"update","type":1,"devices":["Lampe1"],"values":{"timestamp":1487434946,"state":"on"}}
[2/18/2017, 5:22:26 PM] [70er Lampe] Updated internal state to "on"
[2/18/2017, 5:22:26 PM] [70er Lampe] Try to set powerstate to "off"
[2/18/2017, 5:22:27 PM] [70er Lampe] TRACE: handleMessage: item={"origin":"update","type":1,"devices":["Lampe1"],"values":{"timestamp":1487434947,"state":"off"}}
[2/18/2017, 5:22:27 PM] [70er Lampe] Updated internal state to "off"
[2/18/2017, 5:22:27 PM] [70er Lampe] Try to set powerstate to "on"
[2/18/2017, 5:22:28 PM] [70er Lampe] TRACE: handleMessage: item={"origin":"update","type":1,"devices":["Lampe1"],"values":{"timestamp":1487434948,"state":"on"}}
[2/18/2017, 5:22:28 PM] [70er Lampe] Updated internal state to "on"
That includes slow on and off to start with, then very quick, then multiple very quick on/off presses None of which caused any problems (it looks like it now waits for the internal state update before trying to change the state. - Excellent.)
Sorry for the mis-information about my beta-install :-(
@thefool
I'm not quite sure where you expect me to put the script or how to run it. I'm currently running homebridge straight from the shell (logged in via ssh pi@raspberrypi):
Well, it's okay. Obviously, you are using the globally installed variant. That's not wrong, I'm forgetting this sometimes. (I'm personally not being a fan of doing this, so I try to install dependency locally as much as possible avoiding any conflicts with other stuff. That's also the case of NodeJS, so I'm using nvm).
Anyway. So you are using the beta now, but you have not the issue any more? Between beta.0 and beta.2 has nothing changed except some logging lines.
@svwb22 @mrbeach69 @andre-richter @speedy-colibri @thefool
I would consolidate this as much as possible. There is a fresh 1.4.0-beta.3
which improves the logging mostly. And it's logging out current used plugin version, so we can ensure everyone is using the correct one.
[2/18/2017, 6:35:45 PM] [Bulp1] [homebridge-pilight] Plugin 'homebridge-pilight 1.4.0-beta.3' registered as: plugin='homebridge-pilight', accessory='pilight', name='Bulp1'
@knalli I thought I was using beta.1, where I was actually using the last stable release I believe the changes proposed by @Qonstrukt here (who restructured the callback functions to work better with dimmers) might have fixed the issue, which you merged into the beta.0 if I understood correctly.
Yeah, like I said, I'm new to this, and only got this far by following a mix of tutorials... :-/ I've never even really worked with linux before unless I had to, but mainly do bare-metal embedded development on Atmel and STM32 chips, in plain C, with no OS, and little chance for dependency conflicts ;-)
update: sudo npm install -g --unsafe-perm homebridge hap-nodejs node-gyp
seems to be the recommended installation method
I have only used my own version the last couple of moths, and haven't ran into this issue at all. So I don't think it exists after my fixes.
Hi guys, thanks everyone putting effort into this issue!
I have installed beta.3 with following log output:
[Light1] [homebridge-pilight] Plugin 'homebridge-pilight 1.4.0-beta.3' registered as: plugin='homebridge-pilight', accessory='pilight', name='Light1'
I have tried quiet a couple of times to re-produce the infinite loops but can't accomplish: using Apples Home and also using Eve (as I have described in my first post). So there seems to be good news from my side. :)
Thank you all.
1.4.0 released. 🎉
It is possible to provoke the plugin into an on/off-loop. In addition, it will start the loop sporadically.
I am able to provoke it by switching one device from on to off to on to off again in under a few seconds. This is the log of the "normal" process. All fine.
This is the log, when I try to switch on-off-on-off:
At this point, the following processes are starting, without me doing anything.
There should be an option to first fulfill one command, then head to the next one. Or inserting a timer (1000ms?) before processing the next one.