Interference between pimatic-hap and Homeduino RF

[rspaargaren]

This issue is already present for a while and reported in an other issue. Today I did a bit of debugging. If I disable the Hap plugin, it does not happen. As soon as I enable the pluging the interference starts. As soon as I change the setting for my RF Dimmer it keeps oscillating between values. This behaviour is consistant. The only way to stop is to restart pimatic. I have enabled debug for homeduino and hap. Below the output. This does not only happen with the dimmer but also with a switch. I have one door contact which activates a RFswitch. Sometime in keeps oscillating between ON/OFF. Again restarting is the only way out. This behaviour is not consistant.

16:50:09.744 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:0 all:false dimlevel:2 Pin:4 Repeats:1 16:50:10.481 [pimatic-homeduino] debug: data: "ACK" 16:50:10.518 [pimatic-homeduino] debug: data: "RF receive 352 2644 212 1258 10412 0 0 0 0102030203020302030203030202030302020302030203030203020203020303020302030202030203020303020203030203020203020302020203020302030203020302030302020304" 16:50:10.626 [pimatic-homeduino] debug: received: [ 212, 352, 1258, 2644, 10412 ] 1310121012101210121012121010121210101210121012121012101012101212101210121010121012101212101012121012101012101210101012101210121012101210121210101214 16:50:11.168 [pimatic-homeduino] debug: dimmer1: { id: 1337110, all: false, unit: 0, dimlevel: 2, state: undefined } 16:50:11.198 [pimatic-hap] debug: changing dimlevel of Lamp Bank to 13 16:50:11.214 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:0 all:false dimlevel:2 Pin:4 Repeats:1 16:50:11.283 [pimatic-hap] debug: changing dimlevel of Lamp Bank to 15 16:50:11.296 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:0 all:false dimlevel:2 Pin:4 Repeats:1 16:50:12.200 [pimatic-homeduino] debug: data: "ACK" 16:50:12.216 [pimatic-homeduino] debug: data: "RF receive 352 2640 211 1258 10408 0 0 0 0102030203020302030203030202030302020302030203030203020203020303020302030202030203020303020203030203020203020302020203020302030203020302030302020304" 16:50:12.236 [pimatic-homeduino] debug: received: [ 211, 352, 1258, 2640, 10408 ] 1310121012101210121012121010121210101210121012121012101012101212101210121010121012101212101012121012101012101210101012101210121012101210121210101214 16:50:12.261 [pimatic-homeduino] debug: dimmer1: { id: 1337110, all: false, unit: 0, dimlevel: 2, state: undefined } 16:50:12.278 [pimatic-hap] debug: changing dimlevel of Lamp Bank to 13 16:50:12.289 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:0 all:false dimlevel:2 Pin:4 Repeats:1 16:50:13.101 [pimatic-homeduino] debug: data: "ACK" 16:50:13.141 [pimatic-homeduino] debug: data: "RF receive 303 2660 214 1278 10444 0 0 0 0102030203020302030003030200030300000300030003030003000003000303000300030000030003000303000003030003000003000300000003000300030003000300030300000304" 16:50:13.164 [pimatic-homeduino] debug: received: [ 214, 303, 1278, 2660, 10444 ] 1310121012101210121112121011121211111211121112121112111112111212111211121111121112111212111112121112111112111211111112111211121112111211121211111214 16:50:13.184 [pimatic-homeduino] debug: dimmer1: { id: 1337110, all: false, unit: 0, dimlevel: 2, state: undefined } 16:50:13.214 [pimatic-hap] debug: changing dimlevel of Lamp Bank to 15 16:50:13.226 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:0 all:false dimlevel:2 Pin:4 Repeats:1 16:50:13.796 [pimatic-homeduino] debug: data: "ACK" 16:50:13.837 [pimatic-homeduino] debug: data: "RF receive 297 2672 212 1286 10452 0 0 0 0102030003000300030003030000030300000300030003030003000003000303000300030000030003000303000003030003000003000300000003000300030003000300030300000304" 16:50:13.860 [pimatic-homeduino] debug: received: [ 212, 297, 1286, 2672, 10452 ] 1310121112111211121112121111121211111211121112121112111112111212111211121111121112111212111112121112111112111211111112111211121112111211121211111214 16:50:13.881 [pimatic-homeduino] debug: dimmer1: { id: 1337110, all: false, unit: 0, dimlevel: 2, state: undefined } 16:50:13.897 [pimatic-hap] debug: changing dimlevel of Lamp Bank to 13

[michbeck100]

What type of dimmer do you use?

[rspaargaren]

Kaku device. But i don't think that had any influence on the behaviour as there is no feedback signal from the device to the RF receiver.

My guess it has more to do with "slow" reaction and by the time one end has processed the signal the other end has already changed it.

In the very early days of hap plugin / homeduino I did not have this behaviour. But now it is there for a while and it is consistent. Before it was occasionally... Maybe this info helps with debugging. Try to dig in the source as well but I get a bit lost.

[michbeck100]

Your guess is right i think. The frontend is sending multiple values while sliding the dimmer.

Do you use the frontend for changing the dim level? Or do you have a remote?

[michbeck100]

And what about the repeats that homeduino sends? Maybe thats the problem. First it sends a dim level of 13, then 15, then the first repeat sends another 13. Since this is done parallel, i think pimatic-hap gets confused.

[rspaargaren]

Don't know about that at that moment I am not touching anything... So a loop is created

[michbeck100]

I think this one is the same bug like described in #37 and might be fixed by 2a773af8946bfa5132d68e6b9689954189e8d9c0.

[rspaargaren]

Sorry wrong button for closing... I already posted some feedback in that issue as well. The sliding back dimmers were caused by an bug in homeduino. So here it could be the same case that a bug in homeduino is triggering some unwanted behaviour in the hap plugin.

[michbeck100]

Just released version 0.8.0 including 2a773af8946bfa5132d68e6b9689954189e8d9c0. Please test if this helps. I did have a strange behavior at home with sliding back dimmers as described in #37 and it was gone with the update. Maybe this fix helps with the infinite switching, too.

[rspaargaren]

Ok Thanks, it is updating now. Takes a little while as other updates are running as well. Will test it tomorrow and let you know!

[michbeck100]

I was using the latest homeduino but still had sliding back dimmers. With 0.8.0 it was gone. Hope it helps for you as well

[rspaargaren]

Unfortunately it did not solve the problem. Got a new piece of feedback:

Via the web I changed the dimlevel (lamp was off) to 47. It start oscilating between 47 and 44. Then after a while I tried to change it back to 0 via the web. Then it started oscilating between values 47 / 44 and 0... See below.

Can it maybe have something to do with rounding the values of the dimlevel?

18:22:14.213 [pimatic-homeduino] debug: data: "ACK" 18:22:14.255 [pimatic-homeduino] debug: data: "RF receive 295 2668 1288 10440 0 0 0 0 0100020002000200020002020000020200000200020002020002000002000202000200020000020002000202000002020002000002000200000002000200020002000202000200020003" 18:22:14.281 [pimatic-homeduino] debug: received: [ 295, 1288, 2668, 10440 ] 0200010001000100010001010000010100000100010001010001000001000101000100010000010001000101000001010001000001000100000001000100010001000101000100010003 18:22:14.302 [pimatic-homeduino] debug: dimmer1: { id: 1337110, all: false, unit: 0, dimlevel: 7, state: undefined } 18:22:14.318 [pimatic-hap] debug: changing dimlevel of Lamp Bank to 47 18:22:14.336 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:0 all:false dimlevel:7 Pin:4 Repeats:1 18:22:14.918 [pimatic-homeduino] debug: data: "ACK" 18:22:14.957 [pimatic-homeduino] debug: data: "RF receive 297 2672 218 1288 10448 0 0 0 0102030203000300030003030000030300000300030003030003000003000303000300030000030003000303000003030003000003000300030003000300030003000300030003000304" 18:22:14.981 [pimatic-homeduino] debug: received: [ 218, 297, 1288, 2672, 10448 ] 1310121012111211121112121111121211111211121112121112111112111212111211121111121112111212111112121112111112111211121112111211121112111211121112111214 18:22:15.002 [pimatic-homeduino] debug: dimmer1: { id: 1337110, all: false, unit: 0, dimlevel: 0, state: false } 18:22:15.018 [pimatic-hap] debug: changing dimlevel of Lamp Bank to 0 18:22:15.034 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:0 all:false state:false dimlevel:0 Pin:4 Repeats:1 18:22:15.050 [pimatic-hap] debug: value false equals current state of Lamp Bank. Not switching. 18:22:15.090 [pimatic-homeduino] debug: pir5: { id: 1337110, all: false, presence: false, unit: 0 } 18:22:15.110 [pimatic-homeduino] debug: contact1: { id: 1337110, all: false, contact: true, unit: 0 } 18:22:15.613 [pimatic-homeduino] debug: data: "ACK" 18:22:15.652 [pimatic-homeduino] debug: data: "RF receive 295 2676 1288 10444 0 0 0 0 0100020002000200020002020000020200000200020002020002000002000202000200020000020002000202000002020002000002000200000002000200020002000202000200020003" 18:22:15.677 [pimatic-homeduino] debug: received: [ 295, 1288, 2676, 10444 ] 0200010001000100010001010000010100000100010001010001000001000101000100010000010001000101000001010001000001000100000001000100010001000101000100010003 18:22:15.699 [pimatic-homeduino] debug: dimmer1: { id: 1337110, all: false, unit: 0, dimlevel: 7, state: undefined } 18:22:15.725 [pimatic-hap] debug: changing dimlevel of Lamp Bank to 47 18:22:15.737 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:0 all:false dimlevel:7 Pin:4 Repeats:1 18:22:15.754 [pimatic-hap] debug: value true equals current state of Lamp Bank. Not switching. 18:22:16.308 [pimatic-homeduino] debug: data: "ACK" 18:22:16.347 [pimatic-homeduino] debug: data: "RF receive 295 2668 1288 10440 0 0 0 0 0100020002000200020002020000020200000200020002020002000002000202000200020000020002000202000002020002000002000200000002000200020002000202000200020003" 18:22:16.368 [pimatic-homeduino] debug: received: [ 295, 1288, 2668, 10440 ] 0200010001000100010001010000010100000100010001010001000001000101000100010000010001000101000001010001000001000100000001000100010001000101000100010003 18:22:16.392 [pimatic-homeduino] debug: dimmer1: { id: 1337110, all: false, unit: 0, dimlevel: 7, state: undefined } 18:22:16.420 [pimatic-hap] debug: changing dimlevel of Lamp Bank to 44

[rspaargaren]

Would there be anyway how I can debug it in more detail, to see what is happening under the hood?

[michbeck100]

you can enable debug output in the pimatic-hap plugin. Additionally you could add some more debug statements in the code itself. Especially pay attention to the debug lines 'changing dimlevel of device to x' and 'value x equals current dim level of device. Not changing.'. These should be in that order. If you encounter the 'changing ...' line two times without the other line in between, that means that homeduino switched to "fast".

[rspaargaren]

Ok the debug option was already enabled but I will add a few more debug lines in the code so we can see what is happening. BTW there is no debug option in the menu off pimatic 0.9.0 of the hap plugin...?

[michbeck100]

BTW there is no debug option in the menu off pimatic 0.9.0 of the hap plugin...?

By default no plugin has the debug option, but you can still add it to the config. it will be recognized by pimatic, although it logs a warning that debug isn't allowed. One day I'll fix this, but for now, its the way how it works.

[rspaargaren]

I have noticed that if I control the dimmer via rules it works. If PIR signals present then dim the Lamp to 40 -> No problem. If PIR is absent then turn off Lamp ->No problem. Pushing the off button on home-app on iPhone works as well but sliding is a problem. Maybe a side step, the dimmer are shown as on in the home-app of apple even though they are turned off. (by the rule above).

[michbeck100]

i'm pretty sure this is because different dim levels are sent in short intervals. If you switch from 10% to 70% it will send commands in between, too, like 40%. The pimatic-hap is still busy working with the 40% request, when the 70% request comes in. Because i have to remember what the current state (dim level, on/off etc.) of the device is (to prevent infinite loops), this mechanism doesn't work sometimes when a new request comes in too fast.

[rspaargaren]

Would it be possible to build a short delay after receiving a value? If a new value is received, drop the old value, if no value is received for the delay period then continue execute the routine?

[michbeck100]

That means you have to wait 500 - 1000 ms more than before. I would say no. I'm planning to implement some semaphore that prevents subsequent request from interfere.

[rspaargaren]

I was already changing my comment you were to fast in reply. But can't you drop values in the queue if they are entered to fast in the queue.

[michbeck100]

If I dropped any request chances are good that I drop the wrong request. That means for my dimmer example that I would drop the last of two requests which would be the actual dim level that the user wanted to switch to. Bad idea. Sorry

[rspaargaren]

I understand your remark but I was not suggesting to drop the last package. I had more the following sequence in my mind. Receive the value, que it and wait for XX ms. If there is a new request drop the first item and que this request wait for XX ms, etc. If no new request is received within the XX ms execute the last request. Only request are dropped when they are overruled by new info...?

[michbeck100]

That would leave the last value when dimming. This would work probably, although with a bigger delay than before. Whats also missing would be the smoothly dimming from on value to another with the steps between. No, I'm still working on a solution that just queues the request and processes them FIFO. I hope to have a working branch until tomorrow, so you can test if it works.

[rspaargaren]

You are right about the smooth dimming and let us hope it works. I am more than happy to test and make the system wife aproved! My only concern is that still loops can be created after fast switching. Let us say I switch something on/off fast by a contact. Pimatic send ON to hab and little later OFF. ON is executed and hap send back status ON but Pimatic is already OFF so it is changing the state to ON again and sending this to HAP to be queued but HAP is working on OFF etc etc then a que will not help or am I wrong about the procedure?

[michbeck100]

I think it must be really fast! The new implementation adds a "queue" where the requests are put into and then they are processed synchronously. First tests look good.

[michbeck100]

Please checkout https://github.com/michbeck100/pimatic-hap/tree/request_queue and test if the issue is resolved for you.

[rspaargaren]

Unfortunately it did not work out. Here is part of my log. Within the home app I changed the setting of the dimmer device. A run off was imediately the result. 21:42:03.608 [pimatic-hap] debug: [fa:fe:db:e4:36:2c] HAP Request: PUT /characteristics 21:42:03.626 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Processing characteristic set: [{"aid":12,"iid":15,"value":26},{"aid":12,"iid":14,"value":1}] 21:42:03.641 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Setting Characteristic "Brightness" to value 26 21:42:03.657 [pimatic-hap] debug: changing dimlevel of Lamp Bank to 26 21:42:03.691 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:0 all:false dimlevel:4 Pin:4 Repeats:1 21:42:03.730 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Setting Characteristic "On" to value 1 21:42:03.888 [pimatic-hap] debug: value true equals current state of Lamp Bank. Not switching. 21:42:04.538 [pimatic-homeduino] debug: data: "ACK" 21:42:04.571 [pimatic-homeduino] debug: data: "RF receive 355 2636 209 1255 10412 0 0 0 0102030203020302030203030202030302020302030203030203020203020303020302030202030203020303020203030203020203020302020203020302030203020303020203020304" 21:42:04.680 [pimatic-homeduino] debug: received: [ 209, 355, 1255, 2636, 10412 ] 1310121012101210121012121010121210101210121012121012101012101212101210121010121012101212101012121012101012101210101012101210121012101212101012101214 21:42:05.245 [pimatic-homeduino] debug: dimmer1: { id: 1337110, all: false, unit: 0, dimlevel: 4, state: undefined } 21:42:05.277 [pimatic-hap] debug: changing dimlevel of Lamp Bank to 27 21:42:05.292 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:0 all:false dimlevel:4 Pin:4 Repeats:1 21:42:05.564 [pimatic-hap] debug: value true equals current state of Lamp Bank. Not switching. 21:42:05.626 [pimatic-hap] debug: changing dimlevel of Lamp Bank to 26 21:42:05.640 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:0 all:false dimlevel:4 Pin:4 Repeats:1 21:42:05.759 [pimatic-hap] debug: [fa:fe:db:e4:36:2c] HAP Request: PUT /characteristics 21:42:05.780 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Processing characteristic set: [{"aid":12,"iid":15,"value":46}] 21:42:05.793 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Setting Characteristic "Brightness" to value 46 21:42:05.804 [pimatic-hap] debug: changing dimlevel of Lamp Bank to 46 21:42:05.816 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:0 all:false dimlevel:7 Pin:4 Repeats:1 21:42:06.220 [pimatic-homeduino] debug: data: "ACK" 21:42:06.257 [pimatic-homeduino] debug: data: "RF receive 355 2636 209 1255 10404 0 0 0 0102030203020302030203030202030302020302030203030203020203020303020302030202030203020303020203030203020203020302020203020302030203020303020203020304" 21:42:06.281 [pimatic-homeduino] debug: received: [ 209, 355, 1255, 2636, 10404 ] 1310121012101210121012121010121210101210121012121012101012101212101210121010121012101212101012121012101012101210101012101210121012101212101012101214 21:42:06.306 [pimatic-homeduino] debug: dimmer1: { id: 1337110, all: false, unit: 0, dimlevel: 4, state: undefined } 21:42:06.321 [pimatic-hap] debug: changing dimlevel of Lamp Bank to 27 21:42:06.333 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:0 all:false dimlevel:4 Pin:4 Repeats:1 21:42:06.911 [pimatic-homeduino] debug: data: "ACK" 21:42:06.948 [pimatic-homeduino] debug: data: "RF receive 299 2668 212 1283 10436 0 0 0 0102030203000300030003030000030300000300030003030003000003000303000300030000030003000303000003030003000003000300000003000300030003000303000003000304" 21:42:06.968 [pimatic-homeduino] debug: received: [ 212, 299, 1283, 2668, 10436 ] 1310121012111211121112121111121211111211121112121112111112111212111211121111121112111212111112121112111112111211111112111211121112111212111112111214 21:42:06.990 [pimatic-homeduino] debug: dimmer1: { id: 1337110, all: false, unit: 0, dimlevel: 4, state: undefined } 21:42:07.008 [pimatic-hap] debug: changing dimlevel of Lamp Bank to 26 21:42:07.020 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:0 all:false dimlevel:4 Pin:4 Repeats:1 21:42:07.602 [pimatic-homeduino] debug: data: "ACK" 21:42:07.638 [pimatic-homeduino] debug: data: "RF receive 296 2672 212 1288 10440 0 0 0 0102030003000300030003030000030300000300030003030003000003000303000300030000030003000303000003030003000003000300000003000300030003000303000300030004" 21:42:07.658 [pimatic-homeduino] debug: received: [ 212, 296, 1288, 2672, 10440 ] 1310121112111211121112121111121211111211121112121112111112111212111211121111121112111212111112121112111112111211111112111211121112111212111211121114 21:42:07.679 [pimatic-homeduino] debug: dimmer1: { id: 1337110, all: false, unit: 0, dimlevel: 7, state: undefined } 21:42:07.695 [pimatic-hap] debug: changing dimlevel of Lamp Bank to 47 21:42:07.707 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:0 all:false dimlevel:7 Pin:4 Repeats:1 21:42:07.882 [pimatic-hap] debug: changing dimlevel of Lamp Bank to 46 21:42:07.894 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:0 all:false dimlevel:7 Pin:4 Repeats:1 21:42:08.021 [pimatic-hap] debug: [fa:fe:db:e4:36:2c] HAP Request: PUT /characteristics 21:42:08.038 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Processing characteristic set: [{"aid":12,"iid":15,"value":55}] 21:42:08.051 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Setting Characteristic "Brightness" to value 55 21:42:08.064 [pimatic-hap] debug: changing dimlevel of Lamp Bank to 55 21:42:08.076 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:0 all:false dimlevel:8 Pin:4 Repeats:1 21:42:08.293 [pimatic-homeduino] debug: data: "ACK" 21:42:08.328 [pimatic-homeduino] debug: data: "RF receive 295 2676 1289 10448 0 0 0 0 0100020002000200020002020000020200000200020002020002000002000202000200020000020002000202000002020002000002000200000002000200020002000202000002000203" 21:42:08.345 [pimatic-homeduino] debug: received: [ 295, 1289, 2676, 10448 ] 0200010001000100010001010000010100000100010001010001000001000101000100010000010001000101000001010001000001000100000001000100010001000101000001000103 21:42:08.365 [pimatic-homeduino] debug: dimmer1: { id: 1337110, all: false, unit: 0, dimlevel: 4, state: undefined } 21:42:08.380 [pimatic-hap] debug: changing dimlevel of Lamp Bank to 27 21:42:08.391 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:0 all:false dimlevel:4 Pin:4 Repeats:1 21:42:08.983 [pimatic-homeduino] debug: data: "ACK" 21:42:09.022 [pimatic-homeduino] debug: data: "RF receive 295 2680 1288 10456 0 0 0 0 0100020002000200020002020000020200000200020002020002000002000202000200020000020002000202000002020002000002000200000002000200020002000202000002000203" 21:42:09.040 [pimatic-homeduino] debug: received: [ 295, 1288, 2680, 10456 ] 0200010001000100010001010000010100000100010001010001000001000101000100010000010001000101000001010001000001000100000001000100010001000101000001000103 21:42:09.060 [pimatic-homeduino] debug: dimmer1: { id: 1337110, all: false, unit: 0, dimlevel: 4, state: undefined } 21:42:09.080 [pimatic-hap] debug: changing dimlevel of Lamp Bank to 26 21:42:09.092 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:0 all:false dimlevel:4 Pin:4 Repeats:1

[michbeck100]

There is something strange with your installation. Look at this part of the log file above:

1. dim level is set via homekit to 26%

21:42:03.626 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Processing characteristic set: [{"aid":12,"iid":15,"value":26},{"aid":12,"iid":14,"value":1}]

1. pimatic-hap sends the dim level to homeduino

21:42:03.657 [pimatic-hap] debug: changing dimlevel of Lamp Bank to 26

1. homeduino send the dim level to the actual device

21:42:03.691 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:0 all:false dimlevel:4 Pin:4 Repeats:1

1. But then homeduino receives a new dim level

21:42:05.245 [pimatic-homeduino] debug: dimmer1: { id: 1337110, all: false, unit: 0, dimlevel: 4, state: undefined }

1. This leads to pimatic-hap changing the value again, and your infinite loop starts.

21:42:05.277 [pimatic-hap] debug: changing dimlevel of Lamp Bank to 27

If i dim my lamps at home using homekit homeduino won't receive any signals, like in article 4. There must be something strange going on with your pimatic installation.

[michbeck100]

I'm pretty sure that the implementation is solid. Maybe not rock-solid, but solid. Please investigate what leads to this behavior that homeduino receives its own signal. Do you you some kind of repeater?

[rspaargaren]

I understand your comments and I will try to debug the homeduino system as well. The only thing is that if I switch off the hap plug-in the behaviour does not occur. I Will post the outcome

[michbeck100]

But does homeduino receive its own signals when pimatic-hap is not activated? If yes then you found the problem.

Am 28.09.2016 um 18:02 schrieb rspaargaren notifications@github.com:

I understand your comments and I will try to debug the homeduino system as well. The only thing is that if I switch off the hap plug-in the behaviour does not occur. I Will post the outcome

— You are receiving this because you commented. Reply to this email directly, view it on GitHub, or mute the thread.

[michbeck100]

Any news?

[rspaargaren]

I did not have time to test last night. But tonight I am going to test it with a test config file. My feeling is that you are right about the receiving part of arduino.

[michbeck100]

What makes you feel that I'm right? Are you using any RF repeater?

[rspaargaren]

As far as I know, I am not using a RF repeater. But to my feeling it makes no sense for the homeduino unit to receive the same signal you have just submitted.

[michbeck100]

And it seems that it even receives a slightly different signal with different values. If the values wouldn't change there would be no flickering and no infinite loop.

[rspaargaren]

Hi, as you can see I have opened an issue on homeduino as well. To have some experts reviewed the homeduino behaviour. I will do some more debugging tonight.

[michbeck100]

I consider this issue closed then, because pimatic-hap can't do anything then react, if it gets values from homeduino. If the values were at least equal, then you wouldn't have this infinite loop. You can still open this issue again, if there's still a problem with pimatic-hap, after the homeduino issue is solved.

[rspaargaren]

Well not completely closed as even when I switch the receiving part off. The HAP plugin does retrigger homeduino to submit again? See last test log in the issue....? Do you have the same behaviour.

[michbeck100]

Ok, i reopen this again. Please post your complete log without the receiving part and describe what you are doing there, e.g. switch on/off using pimatic or pimatic-hap or remote control. I think we're getting closer to the root of this problem. Another question is, did you use the branch from https://github.com/michbeck100/pimatic-hap/tree/request_queue or the official release?

[rspaargaren]

First the answer to the last question. I have manually installed the request-queue branch. So that is the version. Now the output from my tests. Homeduino receiving is OFF. First switched in the Pimatic screen second try in the iPhone Home app.

Switching ON Via the Pimatic User Interface

16:27:00.783 [pimatic-homeduino] debug: Sending Protocol: switch1 id:43962 unit:9 all:false state:true Pin:4 Repeats:7 16:27:01.413 [pimatic-homeduino] debug: data: "ACK" 16:27:01.455 [pimatic-hap] debug: switching device Lamp Kast to true 16:27:01.486 [pimatic-homeduino] debug: Sending Protocol: switch1 id:43962 unit:9 all:false state:true Pin:4 Repeats:7 16:27:02.157 [pimatic-homeduino] debug: data: "ACK"

Switching OFF Via the Pimatic User Interface

16:27:03.103 [pimatic-homeduino] debug: Sending Protocol: switch1 id:43962 unit:9 all:false state:false Pin:4 Repeats:7 16:27:03.732 [pimatic-homeduino] debug: data: "ACK" 16:27:03.774 [pimatic-hap] debug: switching device Lamp Kast to false 16:27:03.805 [pimatic-homeduino] debug: Sending Protocol: switch1 id:43962 unit:9 all:false state:false Pin:4 Repeats:7 16:27:04.490 [pimatic-homeduino] debug: data: "ACK"

OPENING HOME APP ON IPHONE

16:27:09.786 [pimatic-hap] debug: [fa:fe:db:e4:36:2c] HAP Request: PUT /characteristics 16:27:09.818 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Processing characteristic set: [{"aid":22,"iid":14,"ev":true}] 16:27:09.838 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Registering Characteristic "Motion Detected" for events 16:27:09.995 [pimatic-hap] debug: [fa:fe:db:e4:36:2c] HAP Request: PUT /characteristics 16:27:10.020 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Processing characteristic set: [{"aid":14,"iid":14,"ev":true}] 16:27:10.037 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Registering Characteristic "On" for events 16:27:10.196 [pimatic-hap] debug: [fa:fe:db:e4:36:2c] HAP Request: PUT /characteristics 16:27:10.224 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Processing characteristic set: [{"aid":4,"iid":14,"ev":true},{"aid":4,"iid":15,"ev":true},{"aid":4,"iid":16,"ev":true},{"aid":4,"iid":17,"ev":true},{"aid":4,"iid":18,"ev":true}] 16:27:10.242 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Registering Characteristic "Current Heating Cooling State" for events 16:27:10.256 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Registering Characteristic "Target Heating Cooling State" for events 16:27:10.270 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Registering Characteristic "Current Temperature" for events 16:27:10.283 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Registering Characteristic "Target Temperature" for events 16:27:10.301 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Registering Characteristic "Temperature Display Units" for events 16:27:10.543 [pimatic-hap] debug: [fa:fe:db:e4:36:2c] HAP Request: PUT /characteristics 16:27:10.570 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Processing characteristic set: [{"aid":9,"iid":14,"ev":true}] 16:27:10.586 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Registering Characteristic "Motion Detected" for events 16:27:10.814 [pimatic-hap] debug: [fa:fe:db:e4:36:2c] HAP Request: PUT /characteristics 16:27:10.837 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Processing characteristic set: [{"aid":7,"iid":14,"ev":true}] 16:27:10.860 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Registering Characteristic "Current Temperature" for events 16:27:11.001 [pimatic-hap] debug: [fa:fe:db:e4:36:2c] HAP Request: PUT /characteristics 16:27:11.031 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Processing characteristic set: [{"aid":8,"iid":14,"ev":true}] 16:27:11.047 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Registering Characteristic "Motion Detected" for events 16:27:11.185 [pimatic-hap] debug: [fa:fe:db:e4:36:2c] HAP Request: PUT /characteristics 16:27:11.207 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Processing characteristic set: [{"aid":20,"iid":14,"ev":true}] 16:27:11.223 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Registering Characteristic "Motion Detected" for events 16:27:11.374 [pimatic-hap] debug: [fa:fe:db:e4:36:2c] HAP Request: PUT /characteristics 16:27:11.397 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Processing characteristic set: [{"aid":5,"iid":14,"ev":true},{"aid":5,"iid":15,"ev":true}] 16:27:11.416 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Registering Characteristic "On" for events 16:27:11.431 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Registering Characteristic "Brightness" for events 16:27:11.591 [pimatic-hap] debug: [fa:fe:db:e4:36:2c] HAP Request: PUT /characteristics 16:27:11.613 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Processing characteristic set: [{"aid":16,"iid":14,"ev":true}] 16:27:11.632 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Registering Characteristic "Contact Sensor State" for events 16:27:11.774 [pimatic-hap] debug: [fa:fe:db:e4:36:2c] HAP Request: PUT /characteristics 16:27:11.797 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Processing characteristic set: [{"aid":18,"iid":14,"ev":true}] 16:27:11.813 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Registering Characteristic "On" for events 16:27:11.974 [pimatic-hap] debug: [fa:fe:db:e4:36:2c] HAP Request: PUT /characteristics 16:27:11.997 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Processing characteristic set: [{"aid":12,"iid":14,"ev":true},{"aid":12,"iid":15,"ev":true}] 16:27:12.013 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Registering Characteristic "On" for events 16:27:12.027 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Registering Characteristic "Brightness" for events 16:27:12.196 [pimatic-hap] debug: [fa:fe:db:e4:36:2c] HAP Request: PUT /characteristics 16:27:12.219 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Processing characteristic set: [{"aid":3,"iid":14,"ev":true}] 16:27:12.236 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Registering Characteristic "Current Temperature" for events 16:27:12.382 [pimatic-hap] debug: [fa:fe:db:e4:36:2c] HAP Request: PUT /characteristics 16:27:12.405 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Processing characteristic set: [{"aid":21,"iid":14,"ev":true}] 16:27:12.422 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Registering Characteristic "Motion Detected" for events 16:27:12.574 [pimatic-hap] debug: [fa:fe:db:e4:36:2c] HAP Request: PUT /characteristics 16:27:12.596 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Processing characteristic set: [{"aid":19,"iid":14,"ev":true}] 16:27:12.613 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Registering Characteristic "On" for events 16:27:12.843 [pimatic-hap] debug: [fa:fe:db:e4:36:2c] HAP Request: PUT /characteristics 16:27:12.865 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Processing characteristic set: [{"aid":15,"iid":14,"ev":true}] 16:27:12.882 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Registering Characteristic "On" for events 16:27:13.117 [pimatic-hap] debug: [fa:fe:db:e4:36:2c] HAP Request: PUT /characteristics 16:27:13.143 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Processing characteristic set: [{"aid":2,"iid":14,"ev":true}] 16:27:13.162 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Registering Characteristic "On" for events 16:27:13.299 [pimatic-hap] debug: [fa:fe:db:e4:36:2c] HAP Request: PUT /characteristics 16:27:13.321 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Processing characteristic set: [{"aid":10,"iid":14,"ev":true}] 16:27:13.340 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Registering Characteristic "Motion Detected" for events 16:27:13.488 [pimatic-hap] debug: [fa:fe:db:e4:36:2c] HAP Request: PUT /characteristics 16:27:13.514 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Processing characteristic set: [{"aid":11,"iid":14,"ev":true}] 16:27:13.530 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Registering Characteristic "Current Temperature" for events 16:27:13.669 [pimatic-hap] debug: [fa:fe:db:e4:36:2c] HAP Request: PUT /characteristics 16:27:13.691 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Processing characteristic set: [{"aid":6,"iid":14,"ev":true}] 16:27:13.710 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Registering Characteristic "Motion Detected" for events 16:27:13.984 [pimatic-hap] debug: [fa:fe:db:e4:36:2c] HAP Request: PUT /characteristics 16:27:14.006 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Processing characteristic set: [{"aid":13,"iid":14,"ev":true},{"aid":13,"iid":15,"ev":true}] 16:27:14.023 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Registering Characteristic "On" for events 16:27:14.044 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Registering Characteristic "Brightness" for events 16:27:14.216 [pimatic-hap] debug: [fa:fe:db:e4:36:2c] HAP Request: PUT /characteristics 16:27:14.239 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Processing characteristic set: [{"aid":17,"iid":14,"ev":true}] 16:27:14.256 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Registering Characteristic "On" for events 16:27:14.508 [pimatic-hap] debug: [fa:fe:db:e4:36:2c] HAP Request: GET /characteristics?id=20.14,11.14,21.14,22.14,6.14,15.14,10.14,16.14,18.14,13.15,13.14,4.16,4.18,4.14,4.15,4.17,12.15,12.14,5.14,8.14,17.14,2.14,19.14,14.14,9.14 16:27:14.545 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Getting value for Characteristic "Motion Detected" 16:27:14.583 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Getting value for Characteristic "Current Temperature" 16:27:14.601 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Getting value for Characteristic "Motion Detected" 16:27:14.618 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Getting value for Characteristic "Motion Detected" 16:27:14.632 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Getting value for Characteristic "Motion Detected" 16:27:14.649 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Getting value for Characteristic "On" 16:27:14.673 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Getting value for Characteristic "Motion Detected" 16:27:14.691 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Getting value for Characteristic "Contact Sensor State" 16:27:14.709 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Getting value for Characteristic "On" 16:27:14.724 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Getting value for Characteristic "Brightness" 16:27:14.741 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Getting value for Characteristic "On" 16:27:14.757 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Getting value for Characteristic "Current Temperature" 16:27:14.777 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Got Characteristic "Current Temperature" value: 5 16:27:14.793 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Getting value for Characteristic "Temperature Display Units" 16:27:14.810 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Got Characteristic "Temperature Display Units" value: 0 16:27:14.826 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Getting value for Characteristic "Current Heating Cooling State" 16:27:14.843 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Got Characteristic "Current Heating Cooling State" value: 1 16:27:14.860 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Getting value for Characteristic "Target Heating Cooling State" 16:27:14.888 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Got Characteristic "Target Heating Cooling State" value: 3 16:27:14.902 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Getting value for Characteristic "Target Temperature" 16:27:14.918 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Getting value for Characteristic "Brightness" 16:27:14.933 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Getting value for Characteristic "On" 16:27:14.948 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Getting value for Characteristic "On" 16:27:14.963 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Getting value for Characteristic "Motion Detected" 16:27:14.981 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Getting value for Characteristic "On" 16:27:14.995 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Getting value for Characteristic "On" 16:27:15.010 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Getting value for Characteristic "On" 16:27:15.025 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Getting value for Characteristic "On" 16:27:15.040 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Getting value for Characteristic "Motion Detected" 16:27:15.135 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Got Characteristic "Motion Detected" value: false 16:27:15.154 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Got Characteristic "Current Temperature" value: 22.5 16:27:15.174 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Got Characteristic "Motion Detected" value: false 16:27:15.188 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Got Characteristic "Motion Detected" value: false 16:27:15.201 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Got Characteristic "Motion Detected" value: false 16:27:15.214 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Got Characteristic "On" value: false 16:27:15.228 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Got Characteristic "Motion Detected" value: false 16:27:15.242 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Got Characteristic "Contact Sensor State" value: 0 16:27:15.259 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Got Characteristic "On" value: false 16:27:15.272 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Got Characteristic "Brightness" value: 100 16:27:15.286 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Got Characteristic "On" value: true 16:27:15.299 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Got Characteristic "Target Temperature" value: 5 16:27:15.312 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Got Characteristic "Brightness" value: 17 16:27:15.325 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Got Characteristic "On" value: true 16:27:15.343 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Got Characteristic "On" value: false 16:27:15.357 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Got Characteristic "Motion Detected" value: false 16:27:15.371 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Got Characteristic "On" value: false 16:27:15.384 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Got Characteristic "On" value: false 16:27:15.398 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Got Characteristic "On" value: false 16:27:15.411 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Got Characteristic "On" value: false 16:27:15.427 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Got Characteristic "Motion Detected" value: false

Switching the same Lamp ON via the HOME APP

16:27:20.282 [pimatic-hap] debug: [fa:fe:db:e4:36:2c] HAP Request: PUT /characteristics 16:27:20.307 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Processing characteristic set: [{"aid":15,"iid":14,"value":1}] 16:27:20.327 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Setting Characteristic "On" to value 1 16:27:20.343 [pimatic-hap] debug: switching device Lamp Kast to true 16:27:20.368 [pimatic-homeduino] debug: Sending Protocol: switch1 id:43962 unit:9 all:false state:true Pin:4 Repeats:7 16:27:21.050 [pimatic-homeduino] debug: data: "ACK" 16:27:21.094 [pimatic-hap] debug: value true equals current state of Lamp Kast. Not switching.

Switching the same Lamp OFF via the HOME APP

16:27:22.675 [pimatic-hap] debug: [fa:fe:db:e4:36:2c] HAP Request: PUT /characteristics 16:27:22.701 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Processing characteristic set: [{"aid":15,"iid":14,"value":0}] 16:27:22.718 [pimatic-hap] debug: [Pimatic HomeKit Bridge] Setting Characteristic "On" to value 0 16:27:22.731 [pimatic-hap] debug: switching device Lamp Kast to false 16:27:22.755 [pimatic-homeduino] debug: Sending Protocol: switch1 id:43962 unit:9 all:false state:false Pin:4 Repeats:7 16:27:23.432 [pimatic-homeduino] debug: data: "ACK" 16:27:23.474 [pimatic-hap] debug: value false equals current state of Lamp Kast. Not switching.

[rspaargaren]

I have recompiled the latest homeduino sketch and uploaded this to the Nano and it looks like that this has helped...No more receiving after sending. And even better Rock Solid behaviour when dimming my lamps! YEAH... Now we still have the effect that if I switch something within Pimatic the sending gets triggered twice after feedback from the Hap plugin. I think the response will be improved when sliding the dimmer if we can eliminate this effect?

[michbeck100]

Good to hear. The second sending is because pimatic-homeduino send the event that the state has changed before sending the RF signal. pimatic-hap observes the event and triggers another sending. But sending true two times doesn't change anything on the switch. So I would consider this issue as closed.

[rspaargaren]

Last night suddenly I had am issue with one of my dimmer. It might be triggered by my pir but suddenly the light was dimming from 0 to 100 and back again... See screenshots for more info. This time no repeat/echo from the homeduino....?

Verstuurd vanaf mijn iPhone

Op 30 sep. 2016 om 01:14 heeft Michael Kotten notifications@github.com het volgende geschreven:

Good to hear. The second sending is because pimatic-homeduino send the event that the state has changed before sending the RF signal. pimatic-hap observes the event and triggers another sending. But sending true two times doesn't change anything on the switch. So I would consider this issue as closed.

— You are receiving this because you modified the open/close state. Reply to this email directly, view it on GitHub, or mute the thread.

[michbeck100]

What Screenshots? Do you also have the part of the log file?

[rspaargaren]

I am abroad at the moment but I could trace the part in log... 05:09:46.486 [pimatic-homeduino] debug: data: "ACK" 05:09:46.511 [pimatic-homeduino] debug: data: "PING" 05:09:46.525 [pimatic-homeduino] debug: data: "PING" 05:09:46.537 [pimatic-homeduino] debug: data: "PING" 05:09:46.550 [pimatic-homeduino] debug: data: "PING" 05:09:46.562 [pimatic-homeduino] debug: data: "PING" 05:09:46.574 [pimatic-homeduino] debug: data: "PING" 05:09:46.585 [pimatic-homeduino] debug: data: "PING" 05:09:46.597 [pimatic-homeduino] debug: data: "PING" 05:09:46.609 [pimatic-homeduino] debug: data: "PING" 05:09:46.621 [pimatic-homeduino] debug: data: "PING" 05:09:46.632 [pimatic-homeduino] debug: data: "PING" 05:09:46.643 [pimatic-homeduino] debug: data: "PING" 05:09:46.885 [pimatic-hap] debug: switching device Lamp Kast $05:09:46.934 [pimatic-homeduino] debug: Sending Protocol: swi$05:09:47.002 [pimatic-homeduino] debug: data: "ERR unknown_co$05:09:47.151 [pimatic-hap] error: Could not call promise: unk$05:09:47.182 [pimatic-hap] debug: Error: unknown_command 05:09:47.182 [pimatic-hap] debug:> at /home/pi/pimatic-app$05:09:47.182 [pimatic-hap] debug:> at tryCatcher (/home/pi$05:09:47.182 [pimatic-hap] debug:> at Promise._settlePromi$05:09:47.182 [pimatic-hap] debug:> at Promise._settlePromi$05:09:47.182 [pimatic-hap] debug:> at Promise._settlePromi$05:09:47.182 [pimatic-hap] debug:> at Async._drainQueue (/$ 05:09:47.182 [pimatic-hap] debug:> at Async._drainQueues ($05:09:47.182 [pimatic-hap] debug:> at Immediate.Async.drai$05:09:47.182 [pimatic-hap] debug:> at processImmediate [as$05:09:47.769 [pimatic-homeduino] debug: data: "ACK" 05:09:47.822 [pimatic-hap] debug: changing dimlevel of Lamp H$05:09:47.856 [pimatic-homeduino] debug: Sending Protocol: dim$05:09:47.943 [pimatic] info: rule zonsopgang: Lamp Hal gedimd$05:09:48.066 [pimatic-hap] debug: value true equals current s$05:09:48.457 [pimatic-homeduino] debug: data: "ACK" 05:09:48.499 [pimatic-hap] debug: changing dimlevel of Lamp H$05:09:48.518 [pimatic-homeduino] debug: Sending Protocol: dim$05:09:48.541 [pimatic] info: rule pir-gang-uit: Lamp Hal uitg$05:09:48.661 [pimatic-hap] debug: value false equals current $05:09:49.136 [pimatic-homeduino] debug: data: "ACK" 05:09:49.181 [pimatic-hap] debug: changing dimlevel of Lamp H$05:09:49.195 [pimatic-homeduino] debug: Sending Protocol: dim$05:09:49.214 [pimatic] info: rule zonsopgang: Lamp Hal gedimd$05:09:49.333 [pimatic-hap] debug: value true equals current s$05:09:49.821 [pimatic-homeduino] debug: data: "ACK" 05:09:49.863 [pimatic-hap] debug: changing dimlevel of Lamp H$05:09:49.878 [pimatic-homeduino] debug: Sending Protocol: dim$05:09:49.897 [pimatic] info: rule pir-gang-uit: Lamp Hal uitg$05:09:50.013 [pimatic-hap] debug: value false equals current $05:09:50.500 [pimatic-homeduino] debug: data: "ACK" 05:09:50.541 [pimatic-hap] debug: changing dimlevel of Lamp H$05:09:50.555 [pimatic-homeduino] debug: Sending Protocol: dim$05:09:50.573 [pimatic] info: rule zonsopgang: Lamp Hal gedimd$05:09:50.687 [pimatic-hap] debug: value true equals current s$05:09:51.185 [pimatic-homeduino] debug: data: "ACK" 05:09:51.226 [pimatic-hap] debug: changing dimlevel of Lamp H$05:09:51.239 [pimatic-homeduino] debug: Sending Protocol: dim$05:09:51.257 [pimatic] info: rule pir-gang-uit: Lamp Hal uitg$

[michbeck100]

some line seem to be truncated, i would need the complete text. Apart from that there was an error at 05:09:47.002. this would be interesting

[rspaargaren]

Now a better copy paste of the log I hope.... 05:09:46.486 [pimatic-homeduino] debug: data: "ACK" 05:09:46.511 [pimatic-homeduino] debug: data: "PING" 05:09:46.525 [pimatic-homeduino] debug: data: "PING" 05:09:46.537 [pimatic-homeduino] debug: data: "PING" 05:09:46.550 [pimatic-homeduino] debug: data: "PING" 05:09:46.562 [pimatic-homeduino] debug: data: "PING" 05:09:46.574 [pimatic-homeduino] debug: data: "PING" 05:09:46.585 [pimatic-homeduino] debug: data: "PING" 05:09:46.597 [pimatic-homeduino] debug: data: "PING" 05:09:46.609 [pimatic-homeduino] debug: data: "PING" 05:09:46.621 [pimatic-homeduino] debug: data: "PING" 05:09:46.632 [pimatic-homeduino] debug: data: "PING" 05:09:46.643 [pimatic-homeduino] debug: data: "PING" 05:09:46.885 [pimatic-hap] debug: switching device Lamp Kast to true 05:09:46.934 [pimatic-homeduino] debug: Sending Protocol: switch1 id:43962 unit:9 all:false state:true Pin:4 Repeats:7 05:09:47.002 [pimatic-homeduino] debug: data: "ERR unknown_command" 05:09:47.151 [pimatic-hap] error: Could not call promise: unknown_command 05:09:47.182 [pimatic-hap] debug: Error: unknown_command 05:09:47.182 [pimatic-hap] debug:> at /home/pi/pimatic-app/node_modules/pimatic-homeduino/node_modules/homeduino/lib/board.js:294:19 05:09:47.182 [pimatic-hap] debug:> at tryCatcher (/home/pi/pimatic-app/node_modules/pimatic-homeduino/node_modules/homeduino/node_modules/bluebird/js/main/util.js:26:23) 05:09:47.182 [pimatic-hap] debug:> at Promise._settlePromiseFromHandler (/home/pi/pimatic-app/node_modules/pimatic-homeduino/node_modules/homeduino/node_modules/bluebird/js/main/promise.js:503:31) 05:09:47.182 [pimatic-hap] debug:> at Promise._settlePromiseAt (/home/pi/pimatic-app/node_modules/pimatic-homeduino/node_modules/homeduino/node_modules/bluebird/js/main/promise.js:577:18) 05:09:47.182 [pimatic-hap] debug:> at Promise._settlePromises (/home/pi/pimatic-app/node_modules/pimatic-homeduino/node_modules/homeduino/node_modules/bluebird/js/main/promise.js:693:14) 05:09:47.182 [pimatic-hap] debug:> at Async._drainQueue (/home/pi/pimatic-app/node_modules/pimatic-homeduino/node_modules/homeduino/node_modules/bluebird/js/main/async.js:123:16) 05:09:47.182 [pimatic-hap] debug:> at Async._drainQueues (/home/pi/pimatic-app/node_modules/pimatic-homeduino/node_modules/homeduino/node_modules/bluebird/js/main/async.js:133:10) 05:09:47.182 [pimatic-hap] debug:> at Immediate.Async.drainQueues as _onImmediate 05:09:47.182 [pimatic-hap] debug:> at processImmediate as _immediateCallback 05:09:47.769 [pimatic-homeduino] debug: data: "ACK" 05:09:47.822 [pimatic-hap] debug: changing dimlevel of Lamp Hal to 100 05:09:47.856 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:2 all:false dimlevel:15 Pin:4 Repeats:2 05:09:47.943 [pimatic] info: rule zonsopgang: Lamp Hal gedimd naar 100% 05:09:48.066 [pimatic-hap] debug: value true equals current state of Lamp Hal. Not switching. 05:09:48.457 [pimatic-homeduino] debug: data: "ACK" 05:09:48.499 [pimatic-hap] debug: changing dimlevel of Lamp Hal to 0 05:09:48.518 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:2 all:false state:false dimlevel:0 Pin:4 Repeats:2 05:09:48.541 [pimatic] info: rule pir-gang-uit: Lamp Hal uitgezet 05:09:48.661 [pimatic-hap] debug: value false equals current state of Lamp Hal. Not switching. 05:09:49.136 [pimatic-homeduino] debug: data: "ACK" 05:09:49.181 [pimatic-hap] debug: changing dimlevel of Lamp Hal to 100 05:09:49.195 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:2 all:false dimlevel:15 Pin:4 Repeats:2 05:09:49.214 [pimatic] info: rule zonsopgang: Lamp Hal gedimd naar 100% 05:09:49.333 [pimatic-hap] debug: value true equals current state of Lamp Hal. Not switching. 05:09:49.821 [pimatic-homeduino] debug: data: "ACK" 05:09:49.863 [pimatic-hap] debug: changing dimlevel of Lamp Hal to 0 05:09:49.878 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:2 all:false state:false dimlevel:0 Pin:4 Repeats:2 05:09:49.897 [pimatic] info: rule pir-gang-uit: Lamp Hal uitgezet 05:09:50.013 [pimatic-hap] debug: value false equals current state of Lamp Hal. Not switching. 05:09:50.500 [pimatic-homeduino] debug: data: "ACK" 05:09:50.541 [pimatic-hap] debug: changing dimlevel of Lamp Hal to 100 05:09:50.555 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:2 all:false dimlevel:15 Pin:4 Repeats:2 05:09:50.573 [pimatic] info: rule zonsopgang: Lamp Hal gedimd naar 100% 05:09:50.687 [pimatic-hap] debug: value true equals current state of Lamp Hal. Not switching. 05:09:51.185 [pimatic-homeduino] debug: data: "ACK" 05:09:51.226 [pimatic-hap] debug: changing dimlevel of Lamp Hal to 0 05:09:51.239 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:2 all:false state:false dimlevel:0 Pin:4 Repeats:2 05:09:51.257 [pimatic] info: rule pir-gang-uit: Lamp Hal uitgezet 05:09:51.367 [pimatic-hap] debug: value false equals current state of Lamp Hal. Not switching. 05:09:51.816 [pimatic-homeduino] debug: data: "ACK" 05:09:51.861 [pimatic-hap] debug: switching device Lamp Televisie to true 05:09:51.883 [pimatic] info: rule lamp-aan: Lamp Televisie aangezet 05:09:51.901 [pimatic-homeduino] debug: Sending Protocol: switch1 id:1337110 unit:1 all:false state:true Pin:4 Repeats:7 05:09:52.443 [pimatic-homeduino] debug: data: "ACK" 05:09:52.483 [pimatic] info: rule bed-lamp-gijs: Lamp Gijs uitgezet 05:09:53.067 [pimatic-homeduino] debug: data: "ACK" 05:09:53.107 [pimatic] info: rule bed-lamp-bas: Lamp Bas uitgezet 05:09:53.691 [pimatic-homeduino] debug: data: "ACK" 05:09:53.730 [pimatic] info: rule bed-lamp-gijs: Lamp Gijs uitgezet 05:09:54.315 [pimatic-homeduino] debug: data: "ACK" 05:09:54.354 [pimatic] info: rule bed-lamp-bas: Lamp Bas uitgezet 05:09:54.939 [pimatic-homeduino] debug: data: "ACK" 05:09:55.512 [pimatic-homeduino] debug: Sending Protocol: switch1 id:4287711 unit:1 all:false state:true Pin:4 Repeats:7 05:09:55.564 [pimatic-homeduino] debug: data: "ACK" 05:09:55.606 [pimatic-hap] debug: value true equals current state of Lamp Tom. Not switching. 05:09:56.129 [pimatic-homeduino] debug: Sending Protocol: switch1 id:4287711 unit:0 all:false state:true Pin:4 Repeats:7 05:09:56.188 [pimatic-homeduino] debug: data: "ACK" 05:09:56.867 [pimatic-homeduino] debug: data: "ACK" 05:09:56.914 [pimatic-hap] debug: changing dimlevel of Lamp Hal to 100 05:09:56.927 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:2 all:false dimlevel:15 Pin:4 Repeats:2 05:09:57.034 [pimatic-hap] debug: value true equals current state of Lamp Hal. Not switching. 05:09:57.557 [pimatic-homeduino] debug: data: "ACK" 05:09:57.598 [pimatic-hap] debug: changing dimlevel of Lamp Hal to 0 05:09:57.611 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:2 all:false state:false dimlevel:0 Pin:4 Repeats:2 05:09:57.720 [pimatic-hap] debug: value false equals current state of Lamp Hal. Not switching. 05:09:58.235 [pimatic-homeduino] debug: data: "ACK" 05:09:58.276 [pimatic-hap] debug: changing dimlevel of Lamp Hal to 100 05:09:58.290 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:2 all:false dimlevel:15 Pin:4 Repeats:2 05:09:58.406 [pimatic-hap] debug: value true equals current state of Lamp Hal. Not switching. 05:09:58.920 [pimatic-homeduino] debug: data: "ACK" 05:09:58.962 [pimatic-hap] debug: changing dimlevel of Lamp Hal to 0 05:09:58.977 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:2 all:false state:false dimlevel:0 Pin:4 Repeats:2 05:09:59.085 [pimatic-hap] debug: value false equals current state of Lamp Hal. Not switching. 05:09:59.599 [pimatic-homeduino] debug: data: "ACK" 05:09:59.642 [pimatic-hap] debug: changing dimlevel of Lamp Hal to 100 05:09:59.655 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:2 all:false dimlevel:15 Pin:4 Repeats:2 05:09:59.783 [pimatic-hap] debug: value true equals current state of Lamp Hal. Not switching. 05:10:00.286 [pimatic-homeduino] debug: data: "ACK" 05:10:00.327 [pimatic-hap] debug: changing dimlevel of Lamp Hal to 0 05:10:00.341 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:2 all:false state:false dimlevel:0 Pin:4 Repeats:2 05:10:00.451 [pimatic-hap] debug: value false equals current state of Lamp Hal. Not switching. 05:10:00.909 [pimatic-homeduino] debug: data: "ACK" 05:10:01.533 [pimatic-homeduino] debug: data: "ACK" 05:10:01.574 [pimatic-hap] debug: switching device Lamp Gijs to true 05:10:01.592 [pimatic] info: rule bed-lamp-gijs: Lamp Gijs aangezet 05:10:01.607 [pimatic-homeduino] debug: Sending Protocol: switch1 id:4287711 unit:1 all:false state:true Pin:4 Repeats:7 05:10:02.156 [pimatic-homeduino] debug: data: "ACK" 05:10:02.207 [pimatic-hap] debug: switching device Lamp Bas to true 05:10:02.224 [pimatic] info: rule bed-lamp-bas: Lamp Bas aangezet 05:10:02.241 [pimatic-homeduino] debug: Sending Protocol: switch1 id:4287711 unit:0 all:false state:true Pin:4 Repeats:7 05:10:02.841 [pimatic-homeduino] debug: data: "ACK" 05:10:02.883 [pimatic-hap] debug: changing dimlevel of Lamp Hal to 100 05:10:02.897 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:2 all:false dimlevel:15 Pin:4 Repeats:2 05:10:03.005 [pimatic-hap] debug: value true equals current state of Lamp Hal. Not switching. 05:10:03.526 [pimatic-homeduino] debug: data: "ACK" 05:10:03.567 [pimatic-hap] debug: changing dimlevel of Lamp Hal to 0 05:10:03.581 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:2 all:false state:false dimlevel:0 Pin:4 Repeats:2 05:10:03.687 [pimatic-hap] debug: value false equals current state of Lamp Hal. Not switching. 05:10:04.204 [pimatic-homeduino] debug: data: "ACK" 05:10:04.245 [pimatic-hap] debug: changing dimlevel of Lamp Hal to 100 05:10:04.258 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:2 all:false dimlevel:15 Pin:4 Repeats:2 05:10:04.362 [pimatic-hap] debug: value true equals current state of Lamp Hal. Not switching. 05:10:04.889 [pimatic-homeduino] debug: data: "ACK" 05:10:04.932 [pimatic-hap] debug: changing dimlevel of Lamp Hal to 0 05:10:04.945 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:2 all:false state:false dimlevel:0 Pin:4 Repeats:2 05:10:05.053 [pimatic-hap] debug: value false equals current state of Lamp Hal. Not switching. 05:10:05.569 [pimatic-homeduino] debug: data: "ACK" 05:10:05.612 [pimatic-hap] debug: changing dimlevel of Lamp Hal to 100 05:10:05.625 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:2 all:false dimlevel:15 Pin:4 Repeats:2 05:10:05.735 [pimatic-hap] debug: value true equals current state of Lamp Hal. Not switching. 05:10:06.255 [pimatic-homeduino] debug: data: "ACK" 05:10:06.297 [pimatic-hap] debug: changing dimlevel of Lamp Hal to 0 05:10:06.311 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:2 all:false state:false dimlevel:0 Pin:4 Repeats:2 05:10:06.421 [pimatic-hap] debug: value false equals current state of Lamp Hal. Not switching. 05:10:06.879 [pimatic-homeduino] debug: data: "ACK" 05:10:07.503 [pimatic-homeduino] debug: data: "ACK" 05:10:08.187 [pimatic-homeduino] debug: data: "ACK" 05:10:08.233 [pimatic-hap] debug: changing dimlevel of Lamp Hal to 100 05:10:08.247 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:2 all:false dimlevel:15 Pin:4 Repeats:2 05:10:08.369 [pimatic-hap] debug: value true equals current state of Lamp Hal. Not switching. 05:10:08.876 [pimatic-homeduino] debug: data: "ACK" 05:10:08.918 [pimatic-hap] debug: changing dimlevel of Lamp Hal to 0 05:10:08.932 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:2 all:false state:false dimlevel:0 Pin:4 Repeats:2 05:10:09.040 [pimatic-hap] debug: value false equals current state of Lamp Hal. Not switching. 05:10:09.553 [pimatic-homeduino] debug: data: "ACK" 05:10:09.595 [pimatic-hap] debug: changing dimlevel of Lamp Hal to 100 05:10:09.608 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:2 all:false dimlevel:15 Pin:4 Repeats:2 05:10:09.714 [pimatic-hap] debug: value true equals current state of Lamp Hal. Not switching. 05:10:10.239 [pimatic-homeduino] debug: data: "ACK" 05:10:10.278 [pimatic-hap] debug: changing dimlevel of Lamp Hal to 0 05:10:10.291 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:2 all:false state:false dimlevel:0 Pin:4 Repeats:2 05:10:10.394 [pimatic-hap] debug: value false equals current state of Lamp Hal. Not switching. 05:10:10.915 [pimatic-homeduino] debug: data: "ACK" 05:10:10.957 [pimatic-hap] debug: changing dimlevel of Lamp Hal to 100 05:10:10.970 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:2 all:false dimlevel:15 Pin:4 Repeats:2 05:10:11.078 [pimatic-hap] debug: value true equals current state of Lamp Hal. Not switching. 05:10:11.601 [pimatic-homeduino] debug: data: "ACK" 05:10:11.643 [pimatic-hap] debug: changing dimlevel of Lamp Hal to 0 05:10:11.656 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:2 all:false state:false dimlevel:0 Pin:4 Repeats:2 05:10:11.765 [pimatic-hap] debug: value false equals current state of Lamp Hal. Not switching. 05:10:12.278 [pimatic-homeduino] debug: data: "ACK" 05:10:12.321 [pimatic-hap] debug: changing dimlevel of Lamp Hal to 100 05:10:12.334 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:2 all:false dimlevel:15 Pin:4 Repeats:2 05:10:12.445 [pimatic-hap] debug: value true equals current state of Lamp Hal. Not switching. 05:10:12.965 [pimatic-homeduino] debug: data: "ACK" 05:10:13.013 [pimatic-hap] debug: changing dimlevel of Lamp Hal to 0 05:10:13.027 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:2 all:false state:false dimlevel:0 Pin:4 Repeats:2 05:10:13.142 [pimatic-hap] debug: value false equals current state of Lamp Hal. Not switching. 05:10:13.651 [pimatic-homeduino] debug: data: "ACK" 05:10:13.696 [pimatic-hap] debug: changing dimlevel of Lamp Hal to 100 05:10:13.710 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:2 all:false dimlevel:15 Pin:4 Repeats:2 05:10:13.827 [pimatic-hap] debug: value true equals current state of Lamp Hal. Not switching. 05:10:14.339 [pimatic-homeduino] debug: data: "ACK" 05:10:14.382 [pimatic-hap] debug: changing dimlevel of Lamp Hal to 0 05:10:14.395 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:2 all:false state:false dimlevel:0 Pin:4 Repeats:2 05:10:14.506 [pimatic-hap] debug: value false equals current state of Lamp Hal. Not switching. 05:10:15.018 [pimatic-homeduino] debug: data: "ACK" 05:10:15.061 [pimatic-hap] debug: changing dimlevel of Lamp Hal to 100 05:10:15.074 [pimatic-homeduino] debug: Sending Protocol: dimmer1 id:1337110 unit:2 all:false dimlevel:15 Pin:4 Repeats:2 05:10:15.185 [pimatic-hap] debug: value true equals current state of Lamp Hal. Not switching.

[michbeck100]

Honestly, this is pretty confusing. Apart from the error at 05:09:47.002 there are also some rules int the log. I think i need the rules and devices from your config file, too. If you have some dev experience it would also help if you could add some more debug log statements in the pimatic-hap sources.

[rspaargaren]

Hi I would love to do some more debugging on this. It is not the first time I have noticed this effect... at the moment I am abroad so I have switched of the hap plugin to keep my wife happy and not having her to call me to reboot the device in the middle of the night...;-)

I can send you a part of the config file with the rules and devices would that help?

Verstuurd vanaf mijn iPhone

Op 5 okt. 2016 om 01:00 heeft Michael Kotten notifications@github.com het volgende geschreven:

Honestly, this is pretty confusing. Apart from the error at 05:09:47.002 there are also some rules int the log. I think i need the rules and devices from your config file, too. If you have some dev experience it would also help if you could add some more debug log statements in the pimatic-hap sources.

— You are receiving this because you modified the open/close state. Reply to this email directly, view it on GitHub, or mute the thread.