IR Node resending last signal ca every 15 minutes

[mfalkvidd]

@kiesel getting a log of the serial output might be the quickest wayto troubleshoot. you already have nice serial prints that will describe what the node is doing.

[kiesel]

@mfalkvidd

I am a bit embarrassed that I didn't post them straight away. I'll collect a bit of data during the night and send the logs tomorrow. Thanks!

[kiesel]

I had a look at the Home Assistant logs and I think I have been blaming the wrong beast, my code seems to be innocent.

I use appdaemon to execute actions in/from Home Assistant. There I can see exactly when a "ghost"-update was received.

Matching those timestamps with timestamps from the Home Assistant log was spot on:

Appdaemon log:

2020-03-11 09:38:23.092076 INFO Living_Room_IR: ir_value: 551505585
2020-03-11 09:39:48.834817 INFO Living_Room_IR: ir_value: 551505585
2020-03-11 09:48:03.398937 INFO Living_Room_IR: ir_value: 551505585
2020-03-11 09:49:19.742706 INFO Living_Room_IR: ir_value: 551505585
2020-03-11 10:05:24.735442 INFO Living_Room_IR: ir_value: 551505585
2020-03-11 10:06:58.973448 INFO Living_Room_IR: ir_value: 551505585
2020-03-11 10:38:26.141511 INFO Living_Room_IR: ir_value: 551505585
2020-03-11 10:39:42.890820 INFO Living_Room_IR: ir_value: 551505585
2020-03-11 10:47:59.874830 INFO Living_Room_IR: ir_value: 551505585
2020-03-11 10:49:16.437996 INFO Living_Room_IR: ir_value: 551505585
2020-03-11 11:15:23.592502 INFO Living_Room_IR: ir_value: 551505585
2020-03-11 11:16:40.138025 INFO Living_Room_IR: ir_value: 551505585
2020-03-11 11:18:05.195990 INFO Living_Room_IR: ir_value: 551505585
2020-03-11 11:19:39.443632 INFO Living_Room_IR: ir_value: 551505585
2020-03-11 12:27:05.469657 INFO Living_Room_IR: ir_value: 551505585
2020-03-11 12:28:22.691106 INFO Living_Room_IR: ir_value: 551505585
2020-03-11 12:35:15.985303 INFO Living_Room_IR: ir_value: 551505585
2020-03-11 12:36:33.073911 INFO Living_Room_IR: ir_value: 551505585
2020-03-11 12:40:29.881660 INFO Living_Room_IR: ir_value: 551505585
2020-03-11 12:42:01.804079 INFO Living_Room_IR: ir_value: 551505585

Here is the corresponding part of the home assistant log:

{"log":"2020-03-11 09:38:22 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: n
ode 3 child 255\n","stream":"stderr","time":"2020-03-11T08:38:22.931537407Z"}
{"log":"2020-03-11 09:39:48 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: n
ode 3 child 255\n","stream":"stderr","time":"2020-03-11T08:39:48.650792534Z"}
{"log":"2020-03-11 09:48:03 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: n
ode 3 child 255\n","stream":"stderr","time":"2020-03-11T08:48:03.210220912Z"}
{"log":"2020-03-11 09:49:19 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: n
ode 3 child 255\n","stream":"stderr","time":"2020-03-11T08:49:19.579932619Z"}
{"log":"2020-03-11 10:05:24 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: n
ode 3 child 255\n","stream":"stderr","time":"2020-03-11T09:05:24.564205929Z"}
{"log":"2020-03-11 10:06:58 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: n
ode 3 child 255\n","stream":"stderr","time":"2020-03-11T09:06:58.804235809Z"}
{"log":"2020-03-11 10:38:25 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: n
ode 3 child 255\n","stream":"stderr","time":"2020-03-11T09:38:25.95710773Z"}
{"log":"2020-03-11 10:39:42 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: n
ode 3 child 255\n","stream":"stderr","time":"2020-03-11T09:39:42.703318764Z"}
{"log":"2020-03-11 10:47:59 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: n
ode 3 child 255\n","stream":"stderr","time":"2020-03-11T09:47:59.694853604Z"}
{"log":"2020-03-11 10:49:16 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: n
ode 3 child 255\n","stream":"stderr","time":"2020-03-11T09:49:16.294815751Z"}
{"log":"2020-03-11 11:15:23 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: n
ode 3 child 255\n","stream":"stderr","time":"2020-03-11T10:15:23.452517606Z"}
{"log":"2020-03-11 11:16:39 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: n
ode 3 child 255\n","stream":"stderr","time":"2020-03-11T10:16:39.957885612Z"}
{"log":"2020-03-11 11:18:05 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: n
ode 3 child 255\n","stream":"stderr","time":"2020-03-11T10:18:05.045447402Z"}
{"log":"2020-03-11 11:19:39 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: n
ode 3 child 255\n","stream":"stderr","time":"2020-03-11T10:19:39.270413469Z"}
{"log":"2020-03-11 12:27:05 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: n
ode 3 child 255\n","stream":"stderr","time":"2020-03-11T11:27:05.326243334Z"}
{"log":"2020-03-11 12:28:22 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: n
ode 3 child 255\n","stream":"stderr","time":"2020-03-11T11:28:22.519338238Z"}
{"log":"2020-03-11 12:35:15 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: n
ode 3 child 255\n","stream":"stderr","time":"2020-03-11T11:35:15.805191381Z"}
{"log":"2020-03-11 12:36:32 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: n
ode 3 child 255\n","stream":"stderr","time":"2020-03-11T11:36:32.903939567Z"}
{"log":"2020-03-11 12:40:29 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: n
ode 3 child 255\n","stream":"stderr","time":"2020-03-11T11:40:29.720752968Z"}
{"log":"2020-03-11 12:42:01 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: n
ode 3 child 255\n","stream":"stderr","time":"2020-03-11T11:42:01.635196016Z"}

So it seems that every time a Node update was triggered Home Assistant was told that there was a new value received from the IR-sensor.

Here is the whole log from Home Assistant:

{"log":"2020-03-11 12:42:00 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:11494641 TSF:MSG:RE
AD,3-3-0,s=0,c=1,t=1,pt=7,l=5,sg=0:38.4\n","stream":"stderr","time":"2020-03-11T11:42:00.295978262Z"}
{"log":"2020-03-11 12:42:00 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: n
ode 3 child 0\n","stream":"stderr","time":"2020-03-11T11:42:00.311538101Z"}
{"log":"2020-03-11 12:42:00 DEBUG (MainThread) [homeassistant.components.mysensors.device] Entity update:
mysensors_wohnzimmer_main 3 0: value_type 1, value = 38.4\n","stream":"stderr","time":"2020-03-11T11:42:00
.415847867Z"}
{"log":"2020-03-11 12:42:00 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:11495280 TSF:MSG:RE
AD,3-3-0,s=2,c=1,t=37,pt=7,l=5,sg=0:45.0\n","stream":"stderr","time":"2020-03-11T11:42:00.93325235Z"}
{"log":"2020-03-11 12:42:00 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: n
ode 3 child 2\n","stream":"stderr","time":"2020-03-11T11:42:00.950559479Z"}
{"log":"2020-03-11 12:42:01 DEBUG (MainThread) [homeassistant.components.mysensors.device] Entity update:
mysensors_wohnzimmer_main 3 2: value_type 37, value = 45.0\n","stream":"stderr","time":"2020-03-11T11:42:0
1.058505324Z"}
{"log":"2020-03-11 12:42:01 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:11495962 TSF:MSG:RE
AD,3-3-0,s=255,c=3,t=0,pt=1,l=1,sg=0:22\n","stream":"stderr","time":"2020-03-11T11:42:01.618936799Z"}
{"log":"2020-03-11 12:42:01 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: n
ode 3 child 255\n","stream":"stderr","time":"2020-03-11T11:42:01.635196016Z"}
{"log":"2020-03-11 12:42:01 DEBUG (MainThread) [homeassistant.components.mysensors.device] Entity update:
mysensors_wohnzimmer_main 3 0: value_type 1, value = 38.4\n","stream":"stderr","time":"2020-03-11T11:42:01
.738527926Z"}
{"log":"2020-03-11 12:42:01 DEBUG (MainThread) [homeassistant.components.mysensors.device] Entity update:
mysensors_wohnzimmer_main 3 1: value_type 0, value = 22.4\n","stream":"stderr","time":"2020-03-11T11:42:01
.743098362Z"}
{"log":"2020-03-11 12:42:01 DEBUG (MainThread) [homeassistant.components.mysensors.device] Entity update:
mysensors_wohnzimmer_main 3 3: value_type 50, value = 624502100\n","stream":"stderr","time":"2020-03-11T11
:42:01.747319859Z"}
{"log":"2020-03-11 12:42:01 DEBUG (MainThread) [homeassistant.components.mysensors.device] Entity update:
mysensors_wohnzimmer_main 3 3: value_type 33, value = 551505585\n","stream":"stderr","time":"2020-03-11T11
:42:01.748432047Z"}
{"log":"2020-03-11 12:42:01 DEBUG (MainThread) [homeassistant.components.mysensors.device] Entity update:
mysensors_wohnzimmer_main 3 2: value_type 37, value = 45.0\n","stream":"stderr","time":"2020-03-11T11:42:0
1.752559045Z"}
{"log":"2020-03-11 12:42:02 DEBUG (SyncWorker_3) [mysensors.persistence] Saving sensors to persistence fil
e /config/mysensorsserial.json\n","stream":"stderr","time":"2020-03-11T11:42:02.441267303Z"}

Does anybody have an idea how I can prevent these updates? Or should I continue this thread in the Home Assistant forum of mysensors?

[mfalkvidd]

@kiesel Nice work. I am not familiar with Home Assistant but I can move this entire thread into the Home Assistant category if you want.

[kiesel]

@mfalkvidd

That would be great, thanks!

[mfalkvidd]

@kiesel done!

[kiesel]

I am working around the issue by sending a zero after every received ir_value, that way I can identify refreshes in home assistant/appdaemon

send(msgIrRecord.set(ir_value));
send(msgIrRecord.set(0));

This is a very ugly workaround though, does anybody have areal fix?

[olka]

@kiesel Have you tried to replace the sensor with a pull-up resistor?

[kiesel]

@olka

Sorry for the late reply, I have been busy with a few other sensors.

Do you mean attach a pull-up resistor to the ir sensor? I haven't tried that, but from what I can see the problem isn't the sensor node, it's the integration that sends events when no event has been sent. The gateway log doesn't show a new message being received so I guess the node isn't to blame.

[electrik]

Is the update mechanism maybe triggered by another meessage coming from your node? e.g. temperature or battery update

[kiesel]

@electrik

These updates trigger the event:

{"log":"2020-03-11 12:42:01 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: n
ode 3 child 255\n","stream":"stderr","time":"2020-03-11T11:42:01.635196016Z"}

From what I can see these updates happen whether I trigger something on the node or not, unfortunately.

[electrik]

Those are battery reports. You should have a look at the update mechanism in appdaemon, maybe that is also responding on this event.

Can you post the code of that? I don't have experience with it but interested if this can be useful for me also, instead of node-red for my automations.

[kiesel]

@electrik

Thanks, I'll have a look at those updates.

Do you mean the code I am using for my appdaemon app? I got everything I use from here: https://github.com/eifinger/appdaemon-scripts

This is much cleaner and easier to understand than my code, but let me know if you want it anyway :)