Home Assistant not assigning Node IDs

[AdamAnt]

Hello,

I'm setting up home assistant with mysensors for the first time, and have hit a snag. If I assign a node ID manually, the network works fine, however if I leave it to the controller to assign a node ID, it tries to assign node 0 to the sensor (I think, if i'm interpreting the logs correctly). The gateway is running on the example sketch for the WS5100 ethernet module, and the sketch for the sensor is below. I have tried a different arduino for both gateway and sensor, and tried clearing the EEPROM of both the gateway and sensor (these arduinos have been used to tinker with MySensors a few years ago).
I have also tried clearing the home-assistant persistence file.

Below are some logs from each of the pieces of the puzzle:

Gateway Serial Output:

0 MCO:BGN:INIT GW,CP=RNNGA---,REL=255,VER=2.3.1
4 TSM:INIT
5 TSF:WUR:MS=0
11 TSM:INIT:TSP OK
13 TSM:INIT:GW MODE
15 TSM:READY:ID=0,PAR=0,DIS=0
17 MCO:REG:NOT NEEDED
320 GWT:TIN:IP=192.168.1.25
1323 MCO:BGN:STP
1325 MCO:BGN:INIT OK,TSP=1
1327 TSM:READY:NWD REQ
1363 TSF:MSG:SEND,0-0-255-255,s=255,c=3,t=20,pt=0,l=0,sg=0,ft=0,st=OK:
12073 GWT:TSA:ETH OK
12082 GWT:RFC:MSG=0;255;3;0;2;
12091 GWT:RFC:MSG=255;255;3;0;20;
12129 TSF:MSG:SEND,0-0-255-255,s=255,c=3,t=20,pt=0,l=0,sg=0,ft=0,st=OK:
22179 GWT:RFC:MSG=0;255;3;0;2;

Sensor Sketch:

/*
 * Documentation: http://www.mysensors.org
 * Support Forum: http://forum.mysensors.org
 *
 * http://www.mysensors.org/build/relay
 */

#define MY_DEBUG
#define MY_RADIO_NRF24
#define MY_REPEATER_FEATURE
#include <SPI.h>
#include <MySensors.h>

#define RELAY_PIN  4
#define CHILD_ID 1
#define RELAY_ON 1
#define RELAY_OFF 0

bool state = false;
bool initialValueSent = false;

MyMessage msg(CHILD_ID, V_STATUS);

void setup()
{
  // Make sure relays are off when starting up
  digitalWrite(RELAY_PIN, RELAY_OFF);
  pinMode(RELAY_PIN, OUTPUT);
}

void presentation()  {
  sendSketchInfo("Relay+button", "1.0");
  present(CHILD_ID, S_BINARY);
}

void loop()
{
  if (!initialValueSent) {
    Serial.println("Sending initial value");
    send(msg.set(state?RELAY_ON:RELAY_OFF));
    Serial.println("Requesting initial value from controller");
    request(CHILD_ID, V_STATUS);
    wait(2000, C_SET, V_STATUS);
  }
}

void receive(const MyMessage &message) {
  if (message.isAck()) {
     Serial.println("This is an ack from gateway");
  }

  if (message.type == V_STATUS) {
    if (!initialValueSent) {
      Serial.println("Receiving initial value from controller");
      initialValueSent = true;
    }
    // Change relay state
    state = (bool)message.getInt();
    digitalWrite(RELAY_PIN, state?RELAY_ON:RELAY_OFF);
    send(msg.set(state?RELAY_ON:RELAY_OFF));
  }
}

Sensor Serial Output:

16 MCO:BGN:INIT REPEATER,CP=RNNRA---,REL=255,VER=2.3.1
26 TSM:INIT
27 TSF:WUR:MS=0
34 TSM:INIT:TSP OK
35 !TSF:SID:FAIL,ID=0
37 TSM:FAIL:CNT=1
39 TSM:FAIL:DIS
40 TSF:TDI:TSL

Home Assistant config:

mysensors:
  version: '2.3'
  gateways:
    - device: '192.168.XX.XX'
      persistence_file: /config/mysensors.json

I have also tried a mysensors version of 2.2, but no change.

Home Assistant log:

Config directory: /config
2019-03-23 22:58:02 ERROR (SyncWorker_0) [homeassistant.util.yaml] YAML file /config/configuration.yaml contains duplicate key "notify". Check lines 73 and 79.
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded updater from homeassistant.components.updater
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded owntracks from homeassistant.components.owntracks
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded webhook from homeassistant.components.webhook
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded http from homeassistant.components.http
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded map from homeassistant.components.map
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded shell_command from homeassistant.components.shell_command
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded custom_updater from custom_components.custom_updater
2019-03-23 22:58:03 WARNING (MainThread) [homeassistant.loader] You are using a custom component for custom_updater which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you do experience issues with Home Assistant.
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded script from homeassistant.components.script
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded group from homeassistant.components.group
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded mqtt from homeassistant.components.mqtt
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded frontend from homeassistant.components.frontend
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded api from homeassistant.components.api
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded websocket_api from homeassistant.components.websocket_api
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded system_log from homeassistant.components.system_log
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded auth from homeassistant.components.auth
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded onboarding from homeassistant.components.onboarding
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded lovelace from homeassistant.components.lovelace
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded sensor from homeassistant.components.sensor
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded system_health from homeassistant.components.system_health
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded device_tracker from homeassistant.components.device_tracker
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded zone from homeassistant.components.zone
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded tts from homeassistant.components.tts
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded sun from homeassistant.components.sun
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded logger from homeassistant.components.logger
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded conversation from homeassistant.components.conversation
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded input_boolean from homeassistant.components.input_boolean
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded twilio from homeassistant.components.twilio
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded input_datetime from homeassistant.components.input_datetime
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded person from homeassistant.components.person
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded logbook from homeassistant.components.logbook
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded recorder from homeassistant.components.recorder
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded notify from homeassistant.components.notify
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded automation from homeassistant.components.automation
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded history from homeassistant.components.history
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded mysensors from homeassistant.components.mysensors
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded config from homeassistant.components.config
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.bootstrap] Home Assistant core initialized
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.setup] Setting up mqtt
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.loader] Loaded mqtt.server from homeassistant.components.mqtt.server
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.setup] Setting up logger
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.setup] Setup of domain logger took 0.0 seconds.
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.setup] Setting up recorder
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.setup] Setting up http
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.setup] Setup of domain http took 0.0 seconds.
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.setup] Setting up lovelace
2019-03-23 22:58:03 INFO (MainThread) [homeassistant.setup] Setup of domain lovelace took 0.0 seconds.
2019-03-23 22:58:04 INFO (MainThread) [transitions.core] Exited state new
2019-03-23 22:58:04 INFO (MainThread) [transitions.core] Entered state starting
2019-03-23 22:58:04 INFO (MainThread) [homeassistant.setup] Setting up system_log
2019-03-23 22:58:04 INFO (MainThread) [homeassistant.setup] Setup of domain system_log took 0.0 seconds.
2019-03-23 22:58:04 INFO (MainThread) [homeassistant.setup] Setting up api
2019-03-23 22:58:04 INFO (MainThread) [homeassistant.setup] Setting up websocket_api
2019-03-23 22:58:04 INFO (MainThread) [homeassistant.setup] Setup of domain websocket_api took 0.0 seconds.
2019-03-23 22:58:04 INFO (MainThread) [homeassistant.setup] Setting up auth
2019-03-23 22:58:04 INFO (MainThread) [homeassistant.setup] Setup of domain auth took 0.0 seconds.
2019-03-23 22:58:04 INFO (MainThread) [homeassistant.setup] Setting up onboarding
2019-03-23 22:58:04 INFO (MainThread) [homeassistant.setup] Setup of domain api took 0.0 seconds.
2019-03-23 22:58:04 INFO (MainThread) [hbmqtt.broker] Listener 'default' bind to 0.0.0.0:1883 (max_connections=-1)
2019-03-23 22:58:04 INFO (MainThread) [homeassistant.setup] Setup of domain recorder took 1.4 seconds.
2019-03-23 22:58:04 INFO (MainThread) [hbmqtt.broker] Listener 'ws-1' bind to 0.0.0.0:8080 (max_connections=-1)
2019-03-23 22:58:04 INFO (MainThread) [transitions.core] Exited state starting
2019-03-23 22:58:04 INFO (MainThread) [transitions.core] Entered state started
2019-03-23 22:58:04 INFO (MainThread) [homeassistant.setup] Setup of domain mqtt took 1.4 seconds.
2019-03-23 22:58:04 INFO (MainThread) [homeassistant.setup] Setup of domain onboarding took 0.0 seconds.
2019-03-23 22:58:04 INFO (MainThread) [homeassistant.setup] Setting up history
2019-03-23 22:58:04 INFO (MainThread) [homeassistant.setup] Setup of domain history took 0.0 seconds.
2019-03-23 22:58:04 INFO (MainThread) [homeassistant.setup] Setting up frontend
2019-03-23 22:58:05 INFO (MainThread) [hbmqtt.broker] Listener 'default': 1 connections acquired
2019-03-23 22:58:05 INFO (MainThread) [hbmqtt.broker] Connection from 127.0.0.1:57651 on listener 'default'
2019-03-23 22:58:05 INFO (MainThread) [homeassistant.setup] Setup of domain frontend took 0.7 seconds.
2019-03-23 22:58:06 INFO (MainThread) [transitions.core] Exited state new
2019-03-23 22:58:06 INFO (MainThread) [transitions.core] Entered state connected
2019-03-23 22:58:06 INFO (MainThread) [homeassistant.setup] Setting up updater
2019-03-23 22:58:06 INFO (MainThread) [homeassistant.setup] Setting up map
2019-03-23 22:58:06 INFO (MainThread) [homeassistant.setup] Setup of domain map took 0.0 seconds.
2019-03-23 22:58:06 INFO (MainThread) [homeassistant.setup] Setting up shell_command
2019-03-23 22:58:06 INFO (MainThread) [homeassistant.setup] Setup of domain shell_command took 0.0 seconds.
2019-03-23 22:58:06 INFO (MainThread) [homeassistant.loader] Loaded mqtt.sensor from homeassistant.components.mqtt.sensor
2019-03-23 22:58:06 INFO (MainThread) [homeassistant.loader] Loaded sensor.time_date from homeassistant.components.sensor.time_date
2019-03-23 22:58:06 INFO (MainThread) [homeassistant.setup] Setting up sensor
2019-03-23 22:58:06 INFO (MainThread) [homeassistant.loader] Loaded device_tracker.luci from homeassistant.components.device_tracker.luci
2019-03-23 22:58:06 INFO (MainThread) [homeassistant.loader] Loaded google from homeassistant.components.google
2019-03-23 22:58:06 INFO (MainThread) [homeassistant.loader] Loaded google.tts from homeassistant.components.google.tts
2019-03-23 22:58:06 INFO (MainThread) [homeassistant.setup] Setting up sun
2019-03-23 22:58:06 INFO (MainThread) [homeassistant.setup] Setup of domain sun took 0.1 seconds.
2019-03-23 22:58:06 INFO (MainThread) [homeassistant.setup] Setting up zone
2019-03-23 22:58:06 INFO (MainThread) [homeassistant.setup] Setup of domain zone took 0.0 seconds.
2019-03-23 22:58:06 INFO (MainThread) [homeassistant.setup] Setting up input_boolean
2019-03-23 22:58:06 INFO (MainThread) [homeassistant.setup] Setting up input_datetime
2019-03-23 22:58:06 INFO (MainThread) [homeassistant.setup] Setting up group
2019-03-23 22:58:06 INFO (MainThread) [homeassistant.setup] Setup of domain group took 0.0 seconds.
2019-03-23 22:58:06 INFO (MainThread) [homeassistant.setup] Setting up person
2019-03-23 22:58:06 INFO (MainThread) [homeassistant.loader] Loaded notify.twilio_sms from homeassistant.components.notify.twilio_sms
2019-03-23 22:58:06 INFO (MainThread) [homeassistant.setup] Setting up notify
2019-03-23 22:58:06 INFO (MainThread) [homeassistant.setup] Setting up mysensors
2019-03-23 22:58:06 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.time_date
2019-03-23 22:58:06 INFO (MainThread) [homeassistant.setup] Setup of domain updater took 0.5 seconds.
2019-03-23 22:58:06 INFO (MainThread) [homeassistant.setup] Setting up script
2019-03-23 22:58:06 INFO (MainThread) [homeassistant.setup] Setup of domain script took 0.0 seconds.
2019-03-23 22:58:06 INFO (MainThread) [homeassistant.setup] Setting up webhook
2019-03-23 22:58:06 INFO (MainThread) [homeassistant.setup] Setup of domain webhook took 0.0 seconds.
2019-03-23 22:58:06 INFO (MainThread) [homeassistant.setup] Setting up system_health
2019-03-23 22:58:06 INFO (MainThread) [homeassistant.setup] Setup of domain system_health took 0.0 seconds.
2019-03-23 22:58:06 INFO (MainThread) [homeassistant.setup] Setting up device_tracker
2019-03-23 22:58:06 INFO (MainThread) [homeassistant.setup] Setting up tts
2019-03-23 22:58:06 INFO (MainThread) [homeassistant.setup] Setting up conversation
2019-03-23 22:58:07 INFO (MainThread) [homeassistant.setup] Setup of domain conversation took 0.0 seconds.
2019-03-23 22:58:07 INFO (MainThread) [homeassistant.setup] Setting up logbook
2019-03-23 22:58:07 INFO (MainThread) [homeassistant.setup] Setup of domain logbook took 0.0 seconds.
2019-03-23 22:58:07 INFO (MainThread) [homeassistant.setup] Setting up automation
2019-03-23 22:58:07 INFO (MainThread) [homeassistant.setup] Setting up config
2019-03-23 22:58:07 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.mqtt
2019-03-23 22:58:07 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.mqtt
2019-03-23 22:58:07 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.mqtt
2019-03-23 22:58:07 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.mqtt
2019-03-23 22:58:07 DEBUG (SyncWorker_21) [mysensors.persistence] Loading sensors from persistence file /config/mysensors.json
[SNIP]
2019-03-23 22:58:07 DEBUG (SyncWorker_9) [mysensors.persistence] Saving sensors to persistence file /config/mysensors.json
2019-03-23 22:58:07 INFO (MainThread) [homeassistant.setup] Setup of domain config took 0.2 seconds.
2019-03-23 22:58:07 INFO (MainThread) [homeassistant.setup] Setup of domain tts took 0.2 seconds.
2019-03-23 22:58:07 INFO (MainThread) [homeassistant.setup] Setup of domain notify took 0.5 seconds.
2019-03-23 22:58:07 INFO (MainThread) [homeassistant.setup] Setup of domain mysensors took 0.4 seconds.
2019-03-23 22:58:07 INFO (MainThread) [homeassistant.setup] Setup of domain input_boolean took 0.6 seconds.
2019-03-23 22:58:07 INFO (MainThread) [homeassistant.setup] Setup of domain input_datetime took 0.6 seconds.
2019-03-23 22:58:07 INFO (MainThread) [homeassistant.setup] Setup of domain automation took 0.2 seconds.
2019-03-23 22:58:07 INFO (MainThread) [homeassistant.setup] Setup of domain person took 0.6 seconds.
2019-03-23 22:58:07 INFO (MainThread) [mysensors.gateway_tcp] Trying to connect to ('192.168.1.25', 5003)
2019-03-23 22:58:07 INFO (MainThread) [homeassistant.setup] Setup of domain sensor took 0.7 seconds.
2019-03-23 22:58:07 INFO (MainThread) [mysensors] Connected to <TCPTransport closed=False reading=False 0x55b5d4923eb8>
[SNIP]
2019-03-23 22:58:17 DEBUG (MainThread) [mysensors] Sending 0;255;3;0;2;
2019-03-23 22:58:17 DEBUG (MainThread) [mysensors] Receiving 0;255;3;0;14;Gateway startup complete.
2019-03-23 22:58:17 INFO (MainThread) [mysensors.handler] n:0 c:255 t:3 s:14 p:Gateway startup complete.
2019-03-23 22:58:17 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: node 0 child 255
2019-03-23 22:58:17 DEBUG (MainThread) [mysensors] Sending 255;255;3;0;20;
2019-03-23 22:58:17 DEBUG (MainThread) [mysensors] Receiving 0;255;0;0;18;2.3.1
2019-03-23 22:58:17 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: node 0 child 255
2019-03-23 22:58:17 INFO (MainThread) [homeassistant.bootstrap] Home Assistant initialized in 14.47s
2019-03-23 22:58:17 INFO (MainThread) [homeassistant.core] Starting Home Assistant
2019-03-23 22:58:17 DEBUG (MainThread) [mysensors] Receiving 0;255;3;0;2;2.3.1
[SNIP]
2019-03-23 22:58:27 DEBUG (SyncWorker_32) [mysensors.persistence] Saving sensors to persistence file /config/mysensors.json
2019-03-23 22:58:27 DEBUG (MainThread) [mysensors] Sending 0;255;3;0;2;
2019-03-23 22:58:27 DEBUG (MainThread) [mysensors] Receiving 0;255;3;0;2;2.3.1

Hope I've provided enough info here.

Thanks.

[mfalkvidd]

@adamant yes you are inerpreting the logs correctly.

35 !TSF:SID:FAIL,ID=0

The log parser says this line means "Assigned id 0 is invalid". The node probably has 0 in the eeprom address MySensors uses for keeping track of the node's id.

Load the MySensors cleareeprom sketch on the node and run the sketch, then load the repeater sketch again.

[AdamAnt]

A ha, that fixed it. Thanks very much! If you don't mind, what is the difference between the MySensors eeprom clearing sketch vs the stock arduino one? From first glance it seems as if the Arduino one would actually clean more, since it iterates over the whole eeprom rather than just the bits relevant to MySensors.

[mfalkvidd]

@adamant yes that's correct. The (other) difference is that the stock arduino version writes 0x00 to each location, while the MySensors version writes 0xFF. 0xFF is the value the eeprom has before it is written to the first time when it comes out of the factory.