Mysensors component "losing" nodes?

magnushacker · May 10, 2017, 9:40pm

Hi, I have a weird problem where it seems like mysensors is losing connection to one node.

I have a mysensors RGB light connected to a MQTT gateway which sometimes stops responding. See below the log file from when I click the “on” switch in the HA gui - you can see the turn_on service being called (entity_id: light.led_strip_3_1). This however is not picked up and translated into the corresponding MQTT message to the mysensors gateway. At the same time, mysensors is receiving updates on another node (sensor.temperature_sensor_123_100)

2017-05-10 23:24:31 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: service_data=entity_id=light.led_strip_3_1, service=turn_on, service_call_id=140430312915464-268, domain=homeassistant>
2017-05-10 23:24:31 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: service_data=entity_id=['light.led_strip_3_1'], service=turn_on, service_call_id=140430312915464-269, domain=light>
2017-05-10 23:24:31 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=140430312915464-269>
2017-05-10 23:24:31 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=140430312915464-268>
2017-05-10 23:24:41 DEBUG (Thread-13) [homeassistant.components.mysensors] Update: node 123, child 100 sub_type 38
2017-05-10 23:24:41 DEBUG (Thread-8) [homeassistant.components.mysensors] Temperature sensor 123 100: value_type 38, value = 2.93260145
2017-05-10 23:24:41 INFO (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: old_state=<state sensor.temperature_sensor_123_100=2.93932748; V_VOLTAGE=2.93932748, description=, device=mqtt, battery_level=88, child_id=100, friendly_name=Kitchen, unit_of_measurement=V, node_id=123 @ 2017-05-10T23:02:33.076090+02:00>, entity_id=sensor.temperature_sensor_123_100, new_state=<state sensor.temperature_sensor_123_100=2.93260145; V_VOLTAGE=2.93260145, description=, device=mqtt, battery_level=89, child_id=100, friendly_name=Kitchen, unit_of_measurement=V, node_id=123 @ 2017-05-10T23:24:41.325834+02:00>>
2017-05-10 23:24:41 DEBUG (Thread-13) [homeassistant.components.mysensors] Update: node 123, child 255 sub_type 0

The light itself is functional; if I send the MQTT message manually with mosquitto_pub, it works fine - and mysensors actually picks up the state change. E.g if I execute

mosquitto_pub -t mysensors-in/3/1/1/0/2 -m 1

then HA responds and changes the state on the light accordingly:

2017-05-10 23:34:00 DEBUG (Thread-13) [homeassistant.components.mysensors] Update: node 3, child 1 sub_type 2
2017-05-10 23:34:00 DEBUG (Thread-4) [homeassistant.components.light.mysensors] LED Strip 3 1: value_type 40, value = ff7c11
2017-05-10 23:34:00 DEBUG (Thread-4) [homeassistant.components.light.mysensors] LED Strip 3 1: value_type 2, value = 1
2017-05-10 23:34:00 DEBUG (Thread-4) [homeassistant.components.light.mysensors] LED Strip 3 1: value_type 3, value = 76
2017-05-10 23:34:00 INFO (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: old_state=<state light.led_strip_3_1=off; friendly_name=LED Strip 3 1, supported_features=145, V_RGB=ff7c11, V_PERCENTAGE=76, V_STATUS=off, description=, device=mqtt, battery_level=0, child_id=1, node_id=3 @ 2017-05-10T17:05:12.616046+02:00>, entity_id=light.led_strip_3_1, new_state=<state light.led_strip_3_1=on; friendly_name=LED Strip 3 1, brightness=194, rgb_color=[255, 124, 17], min_mireds=154, supported_features=145, V_RGB=ff7c11, V_PERCENTAGE=76, description=, V_STATUS=on, max_mireds=500, device=mqtt, battery_level=0, child_id=1, node_id=3 @ 2017-05-10T23:34:00.079540+02:00>>

Even after this, I cannot change the state using HA. If I restart HA, everything works fine and when I change the state in the GUI I get this:

2017-05-10 23:37:55 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=homeassistant, service_data=entity_id=light.led_strip_3_1, service_call_id=140085154169520-1, service=turn_off>
2017-05-10 23:37:55 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service_data=entity_id=['light.led_strip_3_1'], service_call_id=140085154169520-2, service=turn_off>
2017-05-10 23:37:55 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=140085154169520-2>
2017-05-10 23:37:55 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=140085154169520-1>
2017-05-10 23:37:55 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=mqtt, service_data=topic=mysensors-in/3/1/1/0/2, payload=0, qos=0, retain=True, service_call_id=140085154169520-3, service=publish>
2017-05-10 23:37:55 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=140085154169520-3>
2017-05-10 23:37:55 INFO (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: old_state=<state light.led_strip_3_1=on; min_mireds=154, device=mqtt, friendly_name=LED Strip 3 1, supported_features=145, brightness=194, description=, V_STATUS=on, V_PERCENTAGE=76, child_id=1, node_id=3, battery_level=0, rgb_color=[255, 124, 17], V_RGB=ff7c11, max_mireds=500 @ 2017-05-10T23:37:44.136891+02:00>, new_state=<state light.led_strip_3_1=off; device=mqtt, friendly_name=LED Strip 3 1, V_STATUS=off, description=, supported_features=145, V_PERCENTAGE=76, child_id=1, node_id=3, battery_level=0, V_RGB=ff7c11 @ 2017-05-10T23:37:55.705312+02:00>, entity_id=light.led_strip_3_1>

Any ideas on how to troubleshoot this further?

martinhjelmare · May 12, 2017, 5:08am

Add debug level logging for the mysensors package.

logger:
  logs:
    mysensors: debug
...

magnushacker · May 14, 2017, 10:01pm

I did, and it seems that mysensors isn’t even listening to the events generated by the GUI. See the log below.

At 23:52:48 I activate the LED strip switch in the GUI and nothing happens. At 23:52:58 I send the on command using mosquitto_pub and both the LED strip itself and HA correctly pick it up.

2017-05-14 23:52:48 DEBUG (MainThread) [homeassistant.components.websocket_api] WS 140381081007888: Received {'domain': 'homeassistant', 'id': 16, 'type': 'call_service', 'service_data': {'entity_id': 'light.led_strip_3_1'}, 'service': 'turn_on'}
2017-05-14 23:52:48 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=homeassistant, service_data=entity_id=light.led_strip_3_1, service_call_id=140382314836488-84, service=turn_on>
2017-05-14 23:52:48 DEBUG (MainThread) [homeassistant.components.api] STREAM 140382427432640 FORWARDING <Event call_service[L]: domain=homeassistant, service_data=entity_id=light.led_strip_3_1, service_call_id=140382314836488-84, service=turn_on>
2017-05-14 23:52:48 DEBUG (MainThread) [homeassistant.components.api] STREAM 140382427432640 WRITING data: {"time_fired": "2017-05-14T21:52:48.026747+00:00", "event_type": "call_service", "data": {"domain": "homeassistant", "service_call_id": "140382314836488-84", "service": "turn_on", "service_data": {"entity_id": "light.led_strip_3_1"}}, "origin": "LOCAL"}
2017-05-14 23:52:48 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=light, service_data=entity_id=['light.led_strip_3_1'], service_call_id=140382314836488-85, service=turn_on>
2017-05-14 23:52:48 DEBUG (MainThread) [homeassistant.components.api] STREAM 140382427432640 FORWARDING <Event call_service[L]: domain=light, service_data=entity_id=['light.led_strip_3_1'], service_call_id=140382314836488-85, service=turn_on>
2017-05-14 23:52:48 DEBUG (MainThread) [homeassistant.components.api] STREAM 140382427432640 WRITING data: {"time_fired": "2017-05-14T21:52:48.037536+00:00", "event_type": "call_service", "data": {"domain": "light", "service_call_id": "140382314836488-85", "service": "turn_on", "service_data": {"entity_id": ["light.led_strip_3_1"]}}, "origin": "LOCAL"}
2017-05-14 23:52:48 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=140382314836488-85>
2017-05-14 23:52:48 DEBUG (MainThread) [homeassistant.components.api] STREAM 140382427432640 FORWARDING <Event service_executed[L]: service_call_id=140382314836488-85>
2017-05-14 23:52:48 DEBUG (MainThread) [homeassistant.components.api] STREAM 140382427432640 WRITING data: {"time_fired": "2017-05-14T21:52:48.042234+00:00", "event_type": "service_executed", "data": {"service_call_id": "140382314836488-85"}, "origin": "LOCAL"}
2017-05-14 23:52:48 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=140382314836488-84>
2017-05-14 23:52:48 DEBUG (MainThread) [homeassistant.components.api] STREAM 140382427432640 FORWARDING <Event service_executed[L]: service_call_id=140382314836488-84>
2017-05-14 23:52:48 DEBUG (MainThread) [homeassistant.components.api] STREAM 140382427432640 WRITING data: {"time_fired": "2017-05-14T21:52:48.045921+00:00", "event_type": "service_executed", "data": {"service_call_id": "140382314836488-84"}, "origin": "LOCAL"}
2017-05-14 23:52:48 DEBUG (MainThread) [homeassistant.components.websocket_api] WS 140381081007888: Sending {'id': 16, 'type': 'result', 'result': None, 'success': True}
2017-05-14 23:52:58 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on mysensors-out/3/1/1/0/2: 1
2017-05-14 23:52:58 DEBUG (Thread-10) [mysensors.gateway_mqtt] Receiving 3;1;1;0;2;1
2017-05-14 23:52:59 DEBUG (Thread-13) [homeassistant.components.mysensors] Update: node 3, child 1 sub_type 2
2017-05-14 23:52:59 DEBUG (Thread-4) [homeassistant.components.light.mysensors] LED Strip 3 1: value_type 40, value = ff4328
2017-05-14 23:52:59 DEBUG (Thread-4) [homeassistant.components.light.mysensors] LED Strip 3 1: value_type 2, value = 1
2017-05-14 23:52:59 DEBUG (Thread-4) [homeassistant.components.light.mysensors] LED Strip 3 1: value_type 3, value = 15
2017-05-14 23:52:59 INFO (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: old_state=<state light.led_strip_3_1=off; V_PERCENTAGE=15, description=, battery_level=0, node_id=3, supported_features=145, child_id=1, V_STATUS=off, device=mqtt, friendly_name=LED Strip 3 1, V_RGB=ff4328 @ 2017-05-14T23:52:37.597832+02:00>, new_state=<state light.led_strip_3_1=on; V_PERCENTAGE=15, description=, battery_level=0, node_id=3, max_mireds=500, child_id=1, rgb_color=[255, 67, 40], V_RGB=ff4328, V_STATUS=on, supported_features=145, device=mqtt, friendly_name=LED Strip 3 1, min_mireds=154, brightness=38 @ 2017-05-14T23:52:59.015262+02:00>, entity_id=light.led_strip_3_1>
2017-05-14 23:52:59 DEBUG (MainThread) [homeassistant.components.api] STREAM 140382427432640 FORWARDING <Event state_changed[L]: old_state=<state light.led_strip_3_1=off; V_PERCENTAGE=15, description=, battery_level=0, node_id=3, supported_features=145, child_id=1, V_STATUS=off, device=mqtt, friendly_name=LED Strip 3 1, V_RGB=ff4328 @ 2017-05-14T23:52:37.597832+02:00>, new_state=<state light.led_strip_3_1=on; V_PERCENTAGE=15, description=, battery_level=0, node_id=3, max_mireds=500, child_id=1, rgb_color=[255, 67, 40], V_RGB=ff4328, V_STATUS=on, supported_features=145, device=mqtt, friendly_name=LED Strip 3 1, min_mireds=154, brightness=38 @ 2017-05-14T23:52:59.015262+02:00>, entity_id=light.led_strip_3_1>
2017-05-14 23:52:59 DEBUG (MainThread) [homeassistant.components.websocket_api] WS 140381081007888: Sending {'id': 2, 'event': {'time_fired': datetime.datetime(2017, 5, 14, 21, 52, 59, 15318, tzinfo=<UTC>), 'event_type': 'state_changed', 'data': {'old_state': <state light.led_strip_3_1=off; V_PERCENTAGE=15, description=, battery_level=0, node_id=3, supported_features=145, child_id=1, V_STATUS=off, device=mqtt, friendly_name=LED Strip 3 1, V_RGB=ff4328 @ 2017-05-14T23:52:37.597832+02:00>, 'new_state': <state light.led_strip_3_1=on; V_PERCENTAGE=15, description=, battery_level=0, node_id=3, max_mireds=500, child_id=1, rgb_color=[255, 67, 40], V_RGB=ff4328, V_STATUS=on, supported_features=145, device=mqtt, friendly_name=LED Strip 3 1, min_mireds=154, brightness=38 @ 2017-05-14T23:52:59.015262+02:00>, 'entity_id': 'light.led_strip_3_1'}, 'origin': 'LOCAL'}, 'type': 'event'}
2017-05-14 23:52:59 DEBUG (MainThread) [homeassistant.components.api] STREAM 140382427432640 WRITING data: {"time_fired": "2017-05-14T21:52:59.015318+00:00", "event_type": "state_changed", "data": {"old_state": {"attributes": {"supported_features": 145, "description": "", "V_STATUS": "off", "device": "mqtt", "battery_level": 0, "V_PERCENTAGE": "15", "child_id": 1, "friendly_name": "LED Strip 3 1", "node_id": 3, "V_RGB": "ff4328"}, "last_changed": "2017-05-14T21:52:37.597832+00:00", "last_updated": "2017-05-14T21:52:37.597832+00:00", "state": "off", "entity_id": "light.led_strip_3_1"}, "new_state": {"attributes": {"V_PERCENTAGE": "15", "description": "", "battery_level": 0, "node_id": 3, "max_mireds": 500, "child_id": 1, "rgb_color": [255, 67, 40], "min_mireds": 154, "V_STATUS": "on", "supported_features": 145, "device": "mqtt", "friendly_name": "LED Strip 3 1", "V_RGB": "ff4328", "brightness": 38}, "last_changed": "2017-05-14T21:52:59.015262+00:00", "last_updated": "2017-05-14T21:52:59.015262+00:00", "state": "on", "entity_id": "light.led_strip_3_1"}, "entity_id": "light.led_strip_3_1"}, "origin": "LOCAL"}

After restarting HA and retrying the same thing, it works as expected. See the log below, at 23:59:18 I click the switch in HA, which results in the message being sent via mysensors.gateway_mqtt:

2017-05-14 23:59:18 DEBUG (MainThread) [homeassistant.components.websocket_api] WS 140579111531856: Received {'service_data': {'entity_id': 'light.led_strip_3_1'}, 'service': 'turn_on', 'id': 10, 'domain': 'homeassistant', 'type': 'call_service'}
2017-05-14 23:59:18 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: service_call_id=140579955139080-1, service_data=entity_id=light.led_strip_3_1, service=turn_on, domain=homeassistant>
2017-05-14 23:59:18 DEBUG (MainThread) [homeassistant.components.api] STREAM 140580067735248 FORWARDING <Event call_service[L]: service_call_id=140579955139080-1, service_data=entity_id=light.led_strip_3_1, service=turn_on, domain=homeassistant>
2017-05-14 23:59:18 DEBUG (MainThread) [homeassistant.components.api] STREAM 140580067735248 WRITING data: {"time_fired": "2017-05-14T21:59:18.143323+00:00", "origin": "LOCAL", "event_type": "call_service", "data": {"service_call_id": "140579955139080-1", "service_data": {"entity_id": "light.led_strip_3_1"}, "service": "turn_on", "domain": "homeassistant"}}
2017-05-14 23:59:18 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: service_call_id=140579955139080-2, service_data=entity_id=['light.led_strip_3_1'], service=turn_on, domain=light>
2017-05-14 23:59:18 DEBUG (MainThread) [homeassistant.components.api] STREAM 140580067735248 FORWARDING <Event call_service[L]: service_call_id=140579955139080-2, service_data=entity_id=['light.led_strip_3_1'], service=turn_on, domain=light>
2017-05-14 23:59:18 DEBUG (MainThread) [homeassistant.components.api] STREAM 140580067735248 WRITING data: {"time_fired": "2017-05-14T21:59:18.151214+00:00", "origin": "LOCAL", "event_type": "call_service", "data": {"service_call_id": "140579955139080-2", "service_data": {"entity_id": ["light.led_strip_3_1"]}, "service": "turn_on", "domain": "light"}}
2017-05-14 23:59:18 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=140579955139080-2>
2017-05-14 23:59:18 DEBUG (MainThread) [homeassistant.components.api] STREAM 140580067735248 FORWARDING <Event service_executed[L]: service_call_id=140579955139080-2>
2017-05-14 23:59:18 DEBUG (MainThread) [homeassistant.components.api] STREAM 140580067735248 WRITING data: {"time_fired": "2017-05-14T21:59:18.155779+00:00", "origin": "LOCAL", "event_type": "service_executed", "data": {"service_call_id": "140579955139080-2"}}
2017-05-14 23:59:18 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=140579955139080-1>
2017-05-14 23:59:18 DEBUG (MainThread) [homeassistant.components.api] STREAM 140580067735248 FORWARDING <Event service_executed[L]: service_call_id=140579955139080-1>
2017-05-14 23:59:18 DEBUG (MainThread) [homeassistant.components.api] STREAM 140580067735248 WRITING data: {"time_fired": "2017-05-14T21:59:18.159536+00:00", "origin": "LOCAL", "event_type": "service_executed", "data": {"service_call_id": "140579955139080-1"}}
2017-05-14 23:59:18 DEBUG (MainThread) [homeassistant.components.websocket_api] WS 140579111531856: Sending {'success': True, 'result': None, 'id': 10, 'type': 'result'}
2017-05-14 23:59:18 DEBUG (Thread-13) [mysensors.gateway_mqtt] Publishing 3;1;1;0;2;1

2017-05-14 23:59:18 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: service_call_id=140579955139080-3, service_data=payload=1, topic=mysensors-in/3/1/1/0/2, qos=0, retain=True, service=publish, domain=mqtt>
2017-05-14 23:59:18 DEBUG (MainThread) [homeassistant.components.api] STREAM 140580067735248 FORWARDING <Event call_service[L]: service_call_id=140579955139080-3, service_data=payload=1, topic=mysensors-in/3/1/1/0/2, qos=0, retain=True, service=publish, domain=mqtt>
2017-05-14 23:59:18 DEBUG (MainThread) [homeassistant.components.api] STREAM 140580067735248 WRITING data: {"time_fired": "2017-05-14T21:59:18.165609+00:00", "origin": "LOCAL", "event_type": "call_service", "data": {"service_call_id": "140579955139080-3", "service_data": {"payload": "1", "topic": "mysensors-in/3/1/1/0/2", "qos": 0, "retain": true}, "service": "publish", "domain": "mqtt"}}
2017-05-14 23:59:18 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=140579955139080-3>
2017-05-14 23:59:18 DEBUG (MainThread) [homeassistant.components.api] STREAM 140580067735248 FORWARDING <Event service_executed[L]: service_call_id=140579955139080-3>
2017-05-14 23:59:18 DEBUG (MainThread) [homeassistant.components.api] STREAM 140580067735248 WRITING data: {"time_fired": "2017-05-14T21:59:18.170379+00:00", "origin": "LOCAL", "event_type": "service_executed", "data": {"service_call_id": "140579955139080-3"}}
2017-05-14 23:59:18 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on mysensors-out/3/1/1/0/2: 1
2017-05-14 23:59:18 DEBUG (Thread-1) [mysensors.gateway_mqtt] Receiving 3;1;1;0;2;1
2017-05-14 23:59:18 DEBUG (Thread-13) [homeassistant.components.mysensors] Update: node 3, child 1 sub_type 2
2017-05-14 23:59:18 DEBUG (Thread-7) [homeassistant.components.light.mysensors] LED Strip 3 1: value_type 40, value = ff4328
2017-05-14 23:59:18 DEBUG (Thread-7) [homeassistant.components.light.mysensors] LED Strip 3 1: value_type 2, value = 1
2017-05-14 23:59:18 DEBUG (Thread-7) [homeassistant.components.light.mysensors] LED Strip 3 1: value_type 3, value = 15
2017-05-14 23:59:18 INFO (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: old_state=<state light.led_strip_3_1=off; node_id=3, V_PERCENTAGE=15, description=, child_id=1, supported_features=145, battery_level=0, device=mqtt, V_STATUS=off, V_RGB=ff4328, friendly_name=LED Strip 3 1 @ 2017-05-14T23:57:35.765794+02:00>, new_state=<state light.led_strip_3_1=on; node_id=3, V_PERCENTAGE=15, max_mireds=500, description=, min_mireds=154, child_id=1, supported_features=145, battery_level=0, rgb_color=[255, 67, 40], device=mqtt, V_STATUS=on, brightness=38, V_RGB=ff4328, friendly_name=LED Strip 3 1 @ 2017-05-14T23:59:18.476789+02:00>, entity_id=light.led_strip_3_1>
2017-05-14 23:59:18 DEBUG (MainThread) [homeassistant.components.api] STREAM 140580067735248 FORWARDING <Event state_changed[L]: old_state=<state light.led_strip_3_1=off; node_id=3, V_PERCENTAGE=15, description=, child_id=1, supported_features=145, battery_level=0, device=mqtt, V_STATUS=off, V_RGB=ff4328, friendly_name=LED Strip 3 1 @ 2017-05-14T23:57:35.765794+02:00>, new_state=<state light.led_strip_3_1=on; node_id=3, V_PERCENTAGE=15, max_mireds=500, description=, min_mireds=154, child_id=1, supported_features=145, battery_level=0, rgb_color=[255, 67, 40], device=mqtt, V_STATUS=on, brightness=38, V_RGB=ff4328, friendly_name=LED Strip 3 1 @ 2017-05-14T23:59:18.476789+02:00>, entity_id=light.led_strip_3_1>
2017-05-14 23:59:18 DEBUG (MainThread) [homeassistant.components.websocket_api] WS 140579111531856: Sending {'event': {'time_fired': datetime.datetime(2017, 5, 14, 21, 59, 18, 476846, tzinfo=<UTC>), 'origin': 'LOCAL', 'event_type': 'state_changed', 'data': {'old_state': <state light.led_strip_3_1=off; node_id=3, V_PERCENTAGE=15, description=, child_id=1, supported_features=145, battery_level=0, device=mqtt, V_STATUS=off, V_RGB=ff4328, friendly_name=LED Strip 3 1 @ 2017-05-14T23:57:35.765794+02:00>, 'new_state': <state light.led_strip_3_1=on; node_id=3, V_PERCENTAGE=15, max_mireds=500, description=, min_mireds=154, child_id=1, supported_features=145, battery_level=0, rgb_color=[255, 67, 40], device=mqtt, V_STATUS=on, brightness=38, V_RGB=ff4328, friendly_name=LED Strip 3 1 @ 2017-05-14T23:59:18.476789+02:00>, 'entity_id': 'light.led_strip_3_1'}}, 'id': 2, 'type': 'event'}
2017-05-14 23:59:18 DEBUG (MainThread) [homeassistant.components.api] STREAM 140580067735248 WRITING data: {"time_fired": "2017-05-14T21:59:18.476846+00:00", "origin": "LOCAL", "event_type": "state_changed", "data": {"old_state": {"last_updated": "2017-05-14T21:57:35.765794+00:00", "state": "off", "last_changed": "2017-05-14T21:57:35.765794+00:00", "attributes": {"battery_level": 0, "node_id": 3, "V_PERCENTAGE": "15", "device": "mqtt", "child_id": 1, "V_STATUS": "off", "description": "", "friendly_name": "LED Strip 3 1", "supported_features": 145, "V_RGB": "ff4328"}, "entity_id": "light.led_strip_3_1"}, "new_state": {"last_updated": "2017-05-14T21:59:18.476789+00:00", "state": "on", "last_changed": "2017-05-14T21:59:18.476789+00:00", "attributes": {"node_id": 3, "V_PERCENTAGE": "15", "max_mireds": 500, "description": "", "min_mireds": 154, "child_id": 1, "V_RGB": "ff4328", "battery_level": 0, "rgb_color": [255, 67, 40], "device": "mqtt", "V_STATUS": "on", "brightness": 38, "supported_features": 145, "friendly_name": "LED Strip 3 1"}, "entity_id": "light.led_strip_3_1"}, "entity_id": "light.led_strip_3_1"}}

gpbenton · May 15, 2017, 6:33am

Can you define it as an ordinary MQTT light and use it like that?

magnushacker · May 15, 2017, 7:18am

I guess that would work, but that’s just a workaround anyway.

martinhjelmare · May 15, 2017, 8:47am

Do you have any other mysensors actuators that are working in home assistant?

Can you post your mysensors home assistant config section?

Are you sending a heartbeat from the node in question, or using smartsleep?

I’d like to see a log from the start of home assistant, including a reboot of the node in question, and then turning on/off the light in home assistant. Use this logger config:

logger:
  default: info
  logs:
    homeassistant.components.mqtt: debug
    homeassistant.components.mysensors: debug
    homeassistant.components.light.mysensors: debug
    mysensors: debug

magnushacker · May 15, 2017, 1:34pm

This is the only actuator I have setup. It’s a AC powered node, so it doesn’t sleep, nor does it send out heartbeats (I wasn’t aware that this needed to be handled by my sketch?)

Here’s the full log (at least the interesting bits - had to strip some since the forum only allows 32kb messages…)

After startup, I turn on the led strip at 15:09:56 and then turn off again at 15:10:16. I then reboot the node (15:10:57) and turn it on (15:11:21) and off again (15:11:27)

2017-05-15 15:09:56 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: service_data=entity_id=light.led_strip_3_1, domain=homeassistant, service=turn_on, service_call_id=139828561793712-1>
2017-05-15 15:09:56 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: service_data=entity_id=['light.led_strip_3_1'], domain=light, service=turn_on, service_call_id=139828561793712-2>
2017-05-15 15:09:56 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=139828561793712-2>
2017-05-15 15:09:56 DEBUG (Thread-13) [mysensors.gateway_mqtt] Publishing 3;1;1;0;2;1

2017-05-15 15:09:56 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: service_data=qos=0, topic=mysensors-in/3/1/1/0/2, payload=1, retain=True, domain=mqtt, service=publish, service_call_id=139828561793712-3>
2017-05-15 15:09:56 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=139828561793712-1>
2017-05-15 15:09:56 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=139828561793712-3>
2017-05-15 15:09:56 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on mysensors-out/3/1/1/0/2: 1
2017-05-15 15:09:56 DEBUG (Thread-8) [mysensors.gateway_mqtt] Receiving 3;1;1;0;2;1
2017-05-15 15:09:56 DEBUG (Thread-13) [homeassistant.components.mysensors] Update: node 3, child 1 sub_type 2
2017-05-15 15:09:56 DEBUG (Thread-4) [homeassistant.components.light.mysensors] LED Strip 3 1: value_type 40, value = ffdf09
2017-05-15 15:09:56 DEBUG (Thread-4) [homeassistant.components.light.mysensors] LED Strip 3 1: value_type 2, value = 1
2017-05-15 15:09:56 DEBUG (Thread-4) [homeassistant.components.light.mysensors] LED Strip 3 1: value_type 3, value = 94
2017-05-15 15:09:56 INFO (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: old_state=<state light.led_strip_3_1=off; friendly_name=LED Strip 3 1, V_RGB=ffdf09, battery_level=0, supported_features=145, description=, child_id=1, device=mqtt, V_PERCENTAGE=94, V_STATUS=off, node_id=3 @ 2017-05-15T15:09:26.593930+02:00>, new_state=<state light.led_strip_3_1=on; friendly_name=LED Strip 3 1, V_RGB=ffdf09, battery_level=0, description=, supported_features=145, brightness=240, max_mireds=500, child_id=1, node_id=3, device=mqtt, V_PERCENTAGE=94, min_mireds=154, V_STATUS=on, rgb_color=[255, 223, 9] @ 2017-05-15T15:09:56.781385+02:00>, entity_id=light.led_strip_3_1>
2017-05-15 15:09:56 INFO (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: old_state=<state group.all_lights=off; friendly_name=all lights, entity_id=('light.taklampa_vardagsrum', 'light.led_strip_3_1', 'light.taklampa_matbord'), hidden=True, order=7, assumed_state=True, auto=True @ 2017-05-15T15:09:26.601546+02:00>, new_state=<state group.all_lights=on; friendly_name=all lights, entity_id=('light.taklampa_vardagsrum', 'light.led_strip_3_1', 'light.taklampa_matbord'), hidden=True, order=7, assumed_state=True, auto=True @ 2017-05-15T15:09:56.817811+02:00>, entity_id=group.all_lights>
2017-05-15 15:10:16 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: service_data=entity_id=light.led_strip_3_1, domain=homeassistant, service=turn_off, service_call_id=139828561793712-4>
2017-05-15 15:10:16 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: service_data=entity_id=['light.led_strip_3_1'], domain=light, service=turn_off, service_call_id=139828561793712-5>
2017-05-15 15:10:16 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=139828561793712-5>
2017-05-15 15:10:16 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=139828561793712-4>
2017-05-15 15:10:16 DEBUG (Thread-13) [mysensors.gateway_mqtt] Publishing 3;1;1;0;2;0

2017-05-15 15:10:16 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: service_data=qos=0, topic=mysensors-in/3/1/1/0/2, payload=0, retain=True, domain=mqtt, service=publish, service_call_id=139828561793712-6>
2017-05-15 15:10:16 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=139828561793712-6>
2017-05-15 15:10:16 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on mysensors-out/3/1/1/0/2: 0
2017-05-15 15:10:16 DEBUG (Thread-5) [mysensors.gateway_mqtt] Receiving 3;1;1;0;2;0
2017-05-15 15:10:16 DEBUG (Thread-13) [homeassistant.components.mysensors] Update: node 3, child 1 sub_type 2
2017-05-15 15:10:16 DEBUG (Thread-3) [homeassistant.components.light.mysensors] LED Strip 3 1: value_type 40, value = ffdf09
2017-05-15 15:10:16 DEBUG (Thread-3) [homeassistant.components.light.mysensors] LED Strip 3 1: value_type 2, value = 0
2017-05-15 15:10:16 DEBUG (Thread-3) [homeassistant.components.light.mysensors] LED Strip 3 1: value_type 3, value = 94
2017-05-15 15:10:16 INFO (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: old_state=<state light.led_strip_3_1=on; friendly_name=LED Strip 3 1, V_RGB=ffdf09, battery_level=0, description=, supported_features=145, brightness=240, max_mireds=500, child_id=1, node_id=3, device=mqtt, V_PERCENTAGE=94, min_mireds=154, V_STATUS=on, rgb_color=[255, 223, 9] @ 2017-05-15T15:09:56.781385+02:00>, new_state=<state light.led_strip_3_1=off; friendly_name=LED Strip 3 1, V_RGB=ffdf09, battery_level=0, supported_features=145, description=, child_id=1, device=mqtt, V_PERCENTAGE=94, V_STATUS=off, node_id=3 @ 2017-05-15T15:10:16.951282+02:00>, entity_id=light.led_strip_3_1>
2017-05-15 15:10:16 INFO (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: old_state=<state group.all_lights=on; friendly_name=all lights, entity_id=('light.taklampa_vardagsrum', 'light.led_strip_3_1', 'light.taklampa_matbord'), hidden=True, order=7, assumed_state=True, auto=True @ 2017-05-15T15:09:56.817811+02:00>, new_state=<state group.all_lights=off; friendly_name=all lights, entity_id=('light.taklampa_vardagsrum', 'light.led_strip_3_1', 'light.taklampa_matbord'), hidden=True, order=7, assumed_state=True, auto=True @ 2017-05-15T15:10:16.958544+02:00>, entity_id=group.all_lights>
2017-05-15 15:10:30 INFO (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: old_state=<state sun.sun=above_horizon; next_dawn=2017-05-16T01:49:33+00:00, next_midnight=2017-05-15T23:06:40+00:00, next_dusk=2017-05-15T20:21:08+00:00, next_rising=2017-05-16T02:44:57+00:00, elevation=45.34, friendly_name=Sun, next_noon=2017-05-16T11:06:38+00:00, next_setting=2017-05-15T19:26:19+00:00, azimuth=223.35 @ 2017-05-15T15:09:05.958789+02:00>, new_state=<state sun.sun=above_horizon; next_dawn=2017-05-16T01:49:33+00:00, next_midnight=2017-05-15T23:06:40+00:00, next_dusk=2017-05-15T20:21:08+00:00, next_rising=2017-05-16T02:44:57+00:00, elevation=45.25, friendly_name=Sun, next_noon=2017-05-16T11:06:38+00:00, next_setting=2017-05-15T19:26:19+00:00, azimuth=223.66 @ 2017-05-15T15:09:05.958789+02:00>, entity_id=sun.sun>
2017-05-15 15:10:41 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on mysensors-out/123/0/1/0/0: 24.0
2017-05-15 15:10:41 DEBUG (Thread-1) [mysensors.gateway_mqtt] Receiving 123;0;1;0;0;24.0
2017-05-15 15:10:41 DEBUG (Thread-13) [homeassistant.components.mysensors] Update: node 123, child 0 sub_type 0
2017-05-15 15:10:41 DEBUG (Thread-10) [homeassistant.components.mysensors] Temperature sensor 123 0: value_type 0, value = 24.0
2017-05-15 15:10:41 INFO (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: old_state=<state sensor.temperature_sensor_123_0=23.9; V_TEMP=23.9, friendly_name=Kitchen, child_id=0, unit_of_measurement=°C, device=mqtt, battery_level=88, node_id=123, description= @ 2017-05-15T15:09:26.742269+02:00>, new_state=<state sensor.temperature_sensor_123_0=24.0; V_TEMP=24.0, friendly_name=Kitchen, child_id=0, unit_of_measurement=°C, device=mqtt, battery_level=88, node_id=123, description= @ 2017-05-15T15:10:41.501837+02:00>, entity_id=sensor.temperature_sensor_123_0>
2017-05-15 15:10:41 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on mysensors-out/123/255/3/0/22: 1661624
2017-05-15 15:10:41 DEBUG (Thread-3) [mysensors.gateway_mqtt] Receiving 123;255;3;0;22;1661624
2017-05-15 15:10:57 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on mysensors-out/3/255/4/0/0: 03000800C002219F0103
2017-05-15 15:10:57 DEBUG (Thread-8) [mysensors.gateway_mqtt] Receiving 3;255;4;0;0;03000800C002219F0103
2017-05-15 15:10:57 DEBUG (Thread-13) [mysensors.ota] Received firmware config request with firmware type 3, firmware version 8, 704 blocks, CRC 40737, bootloader 769
2017-05-15 15:10:57 DEBUG (Thread-13) [mysensors.ota] Node 3 is not set for firmware update
2017-05-15 15:11:00 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on mysensors-out/3/255/4/0/0: 03000800C002219F0300
2017-05-15 15:11:00 DEBUG (Thread-4) [mysensors.gateway_mqtt] Receiving 3;255;4;0;0;03000800C002219F0300
2017-05-15 15:11:00 DEBUG (Thread-13) [mysensors.ota] Received firmware config request with firmware type 3, firmware version 8, 704 blocks, CRC 40737, bootloader 3
2017-05-15 15:11:00 DEBUG (Thread-13) [mysensors.ota] Node 3 is not set for firmware update
2017-05-15 15:11:00 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on mysensors-out/3/255/0/0/17: 2.1.1
2017-05-15 15:11:00 DEBUG (Thread-11) [mysensors.gateway_mqtt] Receiving 3;255;0;0;17;2.1.1
2017-05-15 15:11:00 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on mysensors-out/3/255/3/0/6: 0
2017-05-15 15:11:00 DEBUG (Thread-6) [mysensors.gateway_mqtt] Receiving 3;255;3;0;6;0
2017-05-15 15:11:00 DEBUG (Thread-13) [mysensors.gateway_mqtt] Publishing 3;255;3;0;6;M

2017-05-15 15:11:00 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: service_data=qos=0, topic=mysensors-in/3/255/3/0/6, payload=M, retain=True, domain=mqtt, service=publish, service_call_id=139828561793712-7>
2017-05-15 15:11:00 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=139828561793712-7>
2017-05-15 15:11:01 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on mysensors-out/3/255/3/0/11: LED Strip
2017-05-15 15:11:01 DEBUG (Thread-7) [mysensors.gateway_mqtt] Receiving 3;255;3;0;11;LED Strip
2017-05-15 15:11:01 DEBUG (Thread-13) [homeassistant.components.mysensors] Update: node 3, child 255 sub_type 11
2017-05-15 15:11:01 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on mysensors-out/3/255/3/0/12: 1.5
2017-05-15 15:11:01 DEBUG (Thread-1) [mysensors.gateway_mqtt] Receiving 3;255;3;0;12;1.5
2017-05-15 15:11:01 DEBUG (Thread-13) [homeassistant.components.mysensors] Update: node 3, child 255 sub_type 12
2017-05-15 15:11:01 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on mysensors-out/3/1/0/0/26: 
2017-05-15 15:11:01 DEBUG (Thread-10) [mysensors.gateway_mqtt] Receiving 3;1;0;0;26;
2017-05-15 15:11:01 WARNING (Thread-13) [mysensors] child_id 1 already exists in children of node 3, cannot add child
2017-05-15 15:11:08 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on mysensors-out/3/1/1/0/40: ffffff
2017-05-15 15:11:08 DEBUG (Thread-5) [mysensors.gateway_mqtt] Receiving 3;1;1;0;40;ffffff
2017-05-15 15:11:08 DEBUG (Thread-13) [homeassistant.components.mysensors] Update: node 3, child 1 sub_type 40
2017-05-15 15:11:08 DEBUG (Thread-3) [homeassistant.components.light.mysensors] LED Strip 3 1: value_type 40, value = ffffff
2017-05-15 15:11:08 DEBUG (Thread-3) [homeassistant.components.light.mysensors] LED Strip 3 1: value_type 2, value = 0
2017-05-15 15:11:08 DEBUG (Thread-3) [homeassistant.components.light.mysensors] LED Strip 3 1: value_type 3, value = 94
2017-05-15 15:11:08 INFO (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: old_state=<state light.led_strip_3_1=off; friendly_name=LED Strip 3 1, V_RGB=ffdf09, battery_level=0, supported_features=145, description=, child_id=1, device=mqtt, V_PERCENTAGE=94, V_STATUS=off, node_id=3 @ 2017-05-15T15:10:16.951282+02:00>, new_state=<state light.led_strip_3_1=off; friendly_name=LED Strip 3 1, V_RGB=ffffff, battery_level=0, supported_features=145, description=, child_id=1, device=mqtt, V_PERCENTAGE=94, V_STATUS=off, node_id=3 @ 2017-05-15T15:10:16.951282+02:00>, entity_id=light.led_strip_3_1>
2017-05-15 15:11:08 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on mysensors-out/3/1/1/0/2: 0
2017-05-15 15:11:08 DEBUG (Thread-4) [mysensors.gateway_mqtt] Receiving 3;1;1;0;2;0
2017-05-15 15:11:08 DEBUG (Thread-13) [homeassistant.components.mysensors] Update: node 3, child 1 sub_type 2
2017-05-15 15:11:08 DEBUG (Thread-11) [homeassistant.components.light.mysensors] LED Strip 3 1: value_type 40, value = ffffff
2017-05-15 15:11:08 DEBUG (Thread-11) [homeassistant.components.light.mysensors] LED Strip 3 1: value_type 2, value = 0
2017-05-15 15:11:08 DEBUG (Thread-11) [homeassistant.components.light.mysensors] LED Strip 3 1: value_type 3, value = 94
2017-05-15 15:11:08 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on mysensors-out/3/1/1/0/3: 100
2017-05-15 15:11:08 DEBUG (Thread-6) [mysensors.gateway_mqtt] Receiving 3;1;1;0;3;100
2017-05-15 15:11:08 DEBUG (Thread-13) [homeassistant.components.mysensors] Update: node 3, child 1 sub_type 3
2017-05-15 15:11:08 DEBUG (Thread-9) [homeassistant.components.light.mysensors] LED Strip 3 1: value_type 40, value = ffffff
2017-05-15 15:11:08 DEBUG (Thread-9) [homeassistant.components.light.mysensors] LED Strip 3 1: value_type 2, value = 0
2017-05-15 15:11:08 DEBUG (Thread-9) [homeassistant.components.light.mysensors] LED Strip 3 1: value_type 3, value = 100
2017-05-15 15:11:08 INFO (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: old_state=<state light.led_strip_3_1=off; friendly_name=LED Strip 3 1, V_RGB=ffffff, battery_level=0, supported_features=145, description=, child_id=1, device=mqtt, V_PERCENTAGE=94, V_STATUS=off, node_id=3 @ 2017-05-15T15:10:16.951282+02:00>, new_state=<state light.led_strip_3_1=off; friendly_name=LED Strip 3 1, V_RGB=ffffff, battery_level=0, supported_features=145, description=, child_id=1, device=mqtt, V_PERCENTAGE=100, V_STATUS=off, node_id=3 @ 2017-05-15T15:10:16.951282+02:00>, entity_id=light.led_strip_3_1>
2017-05-15 15:11:21 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: service_data=entity_id=['light.led_strip_3_1'], domain=light, service=turn_on, service_call_id=139828561793712-9>
2017-05-15 15:11:21 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=139828561793712-9>
2017-05-15 15:11:21 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=139828561793712-8>
2017-05-15 15:11:21 DEBUG (Thread-13) [mysensors.gateway_mqtt] Publishing 3;1;1;0;2;1

2017-05-15 15:11:21 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: service_data=qos=0, topic=mysensors-in/3/1/1/0/2, payload=1, retain=True, domain=mqtt, service=publish, service_call_id=139828561793712-10>
2017-05-15 15:11:21 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=139828561793712-10>
2017-05-15 15:11:21 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on mysensors-out/3/1/1/0/2: 1
2017-05-15 15:11:21 DEBUG (Thread-4) [mysensors.gateway_mqtt] Receiving 3;1;1;0;2;1
2017-05-15 15:11:21 DEBUG (Thread-13) [homeassistant.components.mysensors] Update: node 3, child 1 sub_type 2
2017-05-15 15:11:21 DEBUG (Thread-11) [homeassistant.components.light.mysensors] LED Strip 3 1: value_type 40, value = ffffff
2017-05-15 15:11:21 DEBUG (Thread-11) [homeassistant.components.light.mysensors] LED Strip 3 1: value_type 2, value = 1
2017-05-15 15:11:21 DEBUG (Thread-11) [homeassistant.components.light.mysensors] LED Strip 3 1: value_type 3, value = 100
2017-05-15 15:11:21 INFO (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: old_state=<state light.led_strip_3_1=off; friendly_name=LED Strip 3 1, V_RGB=ffffff, battery_level=0, supported_features=145, description=, child_id=1, device=mqtt, V_PERCENTAGE=100, V_STATUS=off, node_id=3 @ 2017-05-15T15:10:16.951282+02:00>, new_state=<state light.led_strip_3_1=on; friendly_name=LED Strip 3 1, V_RGB=ffffff, battery_level=0, description=, supported_features=145, brightness=255, max_mireds=500, child_id=1, node_id=3, device=mqtt, V_PERCENTAGE=100, min_mireds=154, V_STATUS=on, rgb_color=[255, 255, 255] @ 2017-05-15T15:11:21.568232+02:00>, entity_id=light.led_strip_3_1>
2017-05-15 15:11:21 INFO (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: old_state=<state group.all_lights=off; friendly_name=all lights, entity_id=('light.taklampa_vardagsrum', 'light.led_strip_3_1', 'light.taklampa_matbord'), hidden=True, order=7, assumed_state=True, auto=True @ 2017-05-15T15:10:16.958544+02:00>, new_state=<state group.all_lights=on; friendly_name=all lights, entity_id=('light.taklampa_vardagsrum', 'light.led_strip_3_1', 'light.taklampa_matbord'), hidden=True, order=7, assumed_state=True, auto=True @ 2017-05-15T15:11:21.575609+02:00>, entity_id=group.all_lights>
2017-05-15 15:11:27 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: service_data=entity_id=light.led_strip_3_1, domain=homeassistant, service=turn_off, service_call_id=139828561793712-11>
2017-05-15 15:11:27 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: service_data=entity_id=['light.led_strip_3_1'], domain=light, service=turn_off, service_call_id=139828561793712-12>
2017-05-15 15:11:27 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=139828561793712-12>
2017-05-15 15:11:27 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=139828561793712-11>
2017-05-15 15:11:27 DEBUG (Thread-13) [mysensors.gateway_mqtt] Publishing 3;1;1;0;2;0

2017-05-15 15:11:27 INFO (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: service_data=qos=0, topic=mysensors-in/3/1/1/0/2, payload=0, retain=True, domain=mqtt, service=publish, service_call_id=139828561793712-13>
2017-05-15 15:11:27 INFO (MainThread) [homeassistant.core] Bus:Handling <Event service_executed[L]: service_call_id=139828561793712-13>
2017-05-15 15:11:28 DEBUG (MainThread) [homeassistant.components.mqtt] Received message on mysensors-out/3/1/1/0/2: 0
2017-05-15 15:11:28 DEBUG (Thread-1) [mysensors.gateway_mqtt] Receiving 3;1;1;0;2;0
2017-05-15 15:11:28 DEBUG (Thread-13) [homeassistant.components.mysensors] Update: node 3, child 1 sub_type 2
2017-05-15 15:11:28 DEBUG (Thread-10) [homeassistant.components.light.mysensors] LED Strip 3 1: value_type 40, value = ffffff
2017-05-15 15:11:28 DEBUG (Thread-10) [homeassistant.components.light.mysensors] LED Strip 3 1: value_type 2, value = 0
2017-05-15 15:11:28 DEBUG (Thread-10) [homeassistant.components.light.mysensors] LED Strip 3 1: value_type 3, value = 100
2017-05-15 15:11:28 INFO (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: old_state=<state light.led_strip_3_1=on; friendly_name=LED Strip 3 1, V_RGB=ffffff, battery_level=0, description=, supported_features=145, brightness=255, max_mireds=500, child_id=1, node_id=3, device=mqtt, V_PERCENTAGE=100, min_mireds=154, V_STATUS=on, rgb_color=[255, 255, 255] @ 2017-05-15T15:11:21.568232+02:00>, new_state=<state light.led_strip_3_1=off; friendly_name=LED Strip 3 1, V_RGB=ffffff, battery_level=0, supported_features=145, description=, child_id=1, device=mqtt, V_PERCENTAGE=100, V_STATUS=off, node_id=3 @ 2017-05-15T15:11:28.120713+02:00>, entity_id=light.led_strip_3_1>
2017-05-15 15:11:28 INFO (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: old_state=<state group.all_lights=on; friendly_name=all lights, entity_id=('light.taklampa_vardagsrum', 'light.led_strip_3_1', 'light.taklampa_matbord'), hidden=True, order=7, assumed_state=True, auto=True @ 2017-05-15T15:11:21.575609+02:00>, new_state=<state group.all_lights=off; friendly_name=all lights, entity_id=('light.taklampa_vardagsrum', 'light.led_strip_3_1', 'light.taklampa_matbord'), hidden=True, order=7, assumed_state=True, auto=True @ 2017-05-15T15:11:28.127162+02:00>, entity_id=group.all_lights>
2017-05-15 15:11:30 INFO (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: old_state=<state sun.sun=above_horizon; next_dawn=2017-05-16T01:49:33+00:00, next_midnight=2017-05-15T23:06:40+00:00, next_dusk=2017-05-15T20:21:08+00:00, next_rising=2017-05-16T02:44:57+00:00, elevation=45.25, friendly_name=Sun, next_noon=2017-05-16T11:06:38+00:00, next_setting=2017-05-15T19:26:19+00:00, azimuth=223.66 @ 2017-05-15T15:09:05.958789+02:00>, new_state=<state sun.sun=above_horizon; next_dawn=2017-05-16T01:49:33+00:00, next_midnight=2017-05-15T23:06:40+00:00, next_dusk=2017-05-15T20:21:08+00:00, next_rising=2017-05-16T02:44:57+00:00, elevation=45.16, friendly_name=Sun, next_noon=2017-05-16T11:06:38+00:00, next_setting=2017-05-15T19:26:19+00:00, azimuth=223.96 @ 2017-05-15T15:09:05.958789+02:00>, entity_id=sun.sun>

martinhjelmare · May 16, 2017, 6:13am

Nothing seems obviously wrong. Next time you experience loss of function, can you copy your persistence file contents and paste it here? Compare that with a file that you know is working.

magnushacker · May 18, 2017, 9:32pm

Actually, the persistence file entry is identical both when it’s working and when it’s not. Since HA correctly picks up updates sent from the node (via MQTT) I believe this part is working. It’s only that HA will not send OUT anything to MQTT.

martinhjelmare · May 19, 2017, 4:50am

If you hastebin your sketch I could try to reproduce the problem.

magnushacker · May 20, 2017, 7:53am

Have a look here:

https://hastebin.com/hiforihine.cpp

martinhjelmare · May 22, 2017, 7:04am

I’ve started testing this now. So far I’ve seen nothing that explains your experience. I’ve left my test setup running. Maybe something will show later.

I found another bug with nested topic prefixes though. Made a PR to pymysensors for that.

There’s also another known issue currently during addition of new devices, due to the home assistant core change to async. But that’s not related to your experience either, since the device already has been added properly.