mysensors integration freezes when it triggers switch.toggle

kiesel

Hi,

I have an IR-sensor attached to one of my nodes. The goal is to be able to trigger various automations with my TV remote. So far most seem to be working fine, except for switches.

I am using this automation:

alias: 'Infrared Debug'
trigger:
  platform: state
  entity_id: sensor.mysensors_wohnzimmer_main_3_3
condition:
  condition: template
  value_template: "{{ trigger.to_state.state != '0' }}"
action:
  - service: system_log.write
    data_template:
      message: >
              "Automation IR Debug: {{trigger.to_state.state}}"
      level: warning
  - service: switch.toggle
    entity_id: switch.kleine_lampe

When I press the same button a view times the switch gets toggled but at some point the whole integration stops working. Here is an annotated logfile. My comments are {written like this}:

2020-04-18 22:52:02 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:334151 TSF:MSG:READ,3-3-0,s=3,c=1,t=33,pt=5,l=4,sg=0:551505585 {Button pressed}
2020-04-18 22:52:02 DEBUG (MainThread)  
[homeassistant.components.mysensors.gateway] Node update: node 3 child 3
2020-04-18 22:52:02 DEBUG (MainThread) [homeassistant.components.mysensors.device] Entity update: mysensors_wohnzimmer_main 3 3: value_type 33, value = 551505585
2020-04-18 22:52:02 WARNING (MainThread) [homeassistant.components.system_log.external] "Automation IR Debug: 551505585"
2020-04-18 22:52:03 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:334311 TSF:MSG:READ,3-3-0,s=3,c=1,t=33,pt=2,l=2,sg=0:0 {second message to workaround another issue, ignored by the automation}
2020-04-18 22:52:03 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: node 3 child 3
2020-04-18 22:52:03 DEBUG (MainThread) [homeassistant.components.mysensors.device] Entity update: mysensors_wohnzimmer_main 3 3: value_type 33, value = 0
2020-04-18 22:52:04 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:336228 TSF:MSG:READ,3-3-0,s=3,c=1,t=33,pt=5,l=4,sg=0:551505585 {Button pressed}
2020-04-18 22:52:04 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: node 3 child 3
2020-04-18 22:52:05 DEBUG (MainThread) [homeassistant.components.mysensors.device] Entity update: mysensors_wohnzimmer_main 3 3: value_type 33, value = 551505585
2020-04-18 22:52:05 WARNING (MainThread) [homeassistant.components.system_log.external] "Automation IR Debug: 551505585"
2020-04-18 22:52:05 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:336388 TSF:MSG:READ,3-3-0,s=3,c=1,t=33,pt=2,l=2,sg=0:0 {second message to workaround another issue, ignored by the automation}
2020-04-18 22:52:05 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: node 3 child 3
2020-04-18 22:52:05 DEBUG (MainThread) [homeassistant.components.mysensors.device] Entity update: mysensors_wohnzimmer_main 3 3: value_type 33, value = 0
2020-04-18 22:52:06 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:337334 TSF:MSG:READ,3-3-0,s=3,c=1,t=33,pt=5,l=4,sg=0:34469099 {Button pressed}
2020-04-18 22:52:06 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: node 3 child 3
2020-04-18 22:52:06 DEBUG (MainThread) [homeassistant.components.mysensors.device] Entity update: mysensors_wohnzimmer_main 3 3: value_type 33, value = 34469099 {Button pressed}
2020-04-18 22:52:06 WARNING (MainThread) [homeassistant.components.system_log.external] "Automation IR Debug: 34469099"
2020-04-18 22:52:06 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:337491 TSF:MSG:READ,3-3-0,s=3,c=1,t=33,pt=2,l=2,sg=0:0 {second message to workaround another issue, ignored by the automation}
2020-04-18 22:52:06 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: node 3 child 3
2020-04-18 22:52:06 DEBUG (MainThread) [homeassistant.components.mysensors.device] Entity update: mysensors_wohnzimmer_main 3 3: value_type 33, value = 0{second message to workaround another issue, ignored by the automation}
2020-04-18 22:52:06 DEBUG (SyncWorker_9) [mysensors.persistence] Saving sensors to persistence file /config/mysensors1.pickle
2020-04-18 22:52:06 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:338235 TSF:MSG:READ,3-3-0,s=3,c=1,t=33,pt=5,l=4,sg=0:551505585 {Button pressed}
2020-04-18 22:52:06 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: node 3 child 3
2020-04-18 22:52:07 DEBUG (MainThread) [homeassistant.components.mysensors.device] Entity update: mysensors_wohnzimmer_main 3 3: value_type 33, value = 551505585
2020-04-18 22:52:07 WARNING (MainThread) [homeassistant.components.system_log.external] "Automation IR Debug: 551505585"
2020-04-18 22:52:07 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:338395 TSF:MSG:READ,3-3-0,s=3,c=1,t=33,pt=2,l=2,sg=0:0 {second message to workaround another issue, ignored by the automation}
2020-04-18 22:52:07 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: node 3 child 3
2020-04-18 22:52:07 DEBUG (MainThread) [homeassistant.components.mysensors.device] Entity update: mysensors_wohnzimmer_main 3 3: value_type 33, value = 0
2020-04-18 22:52:16 DEBUG (SyncWorker_8) [mysensors.persistence] Saving sensors to persistence file /config/mysensors1.pickle

After this the integration doesn't answer to any more messages, though HA is running fine and I can toggle the lamp from lovelace.

This doesn't happen with other services, it's just the switch that has this issue. It also happens when I use switch.turn_on and switch.turn_off.

The switch is a tasmota-flashed plug, controlled by MQTT.

Does anybody have an idea what I am doing wrong or how I can debug this further?

kiesel

I decided to wait for some time after a freeze and I noticed that the gateway comes back after max 15 minutes:

2020-04-19 21:51:06 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:48615 TSF:MSG:READ,3-3-0,s=3,c=1,t=33,pt=5,l=4,sg=0:34469099
2020-04-19 21:51:06 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: node 3 child 3
2020-04-19 21:51:07 DEBUG (MainThread) [homeassistant.components.mysensors.device] Entity update: mysensors_wohnzimmer_main 3 3: value_type 33, value = 34469099
2020-04-19 21:51:07 WARNING (MainThread) [homeassistant.components.system_log.external] "Automation IR Debug: 34469099"
2020-04-19 21:51:07 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:48775 TSF:MSG:READ,3-3-0,s=3,c=1,t=33,pt=2,l=2,sg=0:0
2020-04-19 21:51:07 DEBUG (MainThread) [homeassistant.components.mysensors.gateway] Node update: node 3 child 3
2020-04-19 21:51:07 DEBUG (MainThread) [homeassistant.components.mysensors.device] Entity update: mysensors_wohnzimmer_main 3 3: value_type 33, value = 0
2020-04-19 21:51:14 WARNING (MainThread) [homeassistant.components.light.reproduce_state] Unable to find entity light.grosse_lampe
2020-04-19 21:51:16 DEBUG (SyncWorker_5) [mysensors.persistence] Saving sensors to persistence file /config/mysensors1.pickle
2020-04-19 22:00:47 WARNING (MainThread) [homeassistant.components.light.reproduce_state] Unable to find entity light.grosse_lampe
2020-04-19 22:05:20 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:900026 !TSF:SAN:FAIL
2020-04-19 22:05:20 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:900034 TSM:FAIL:CNT=1
2020-04-19 22:05:20 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:900044 TSM:FAIL:DIS
2020-04-19 22:05:20 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:900052 TSF:TDI:TSL
2020-04-19 22:05:30 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:910063 TSM:FAIL:RE-INIT
2020-04-19 22:05:30 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:910071 TSM:INIT
2020-04-19 22:05:30 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:910082 TSM:INIT:TSP OK
2020-04-19 22:05:30 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:910090 TSM:INIT:GW MODE
2020-04-19 22:05:30 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:910100 TSM:READY:ID=0,PAR=0,DIS=0
2020-04-19 22:05:30 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:910112 TSM:READY:NWD REQ
2020-04-19 22:05:30 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:910127 ?TSF:MSG:SEND,0-0-255-255,s=255,c=3,t=20,pt=0,l=0,sg=0,ft=0,st=OK:
2020-04-19 22:06:22 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:962252 TSF:MSG:READ,2-2-255,s=255,c=3,t=7,pt=0,l=0,sg=0:
2020-04-19 22:06:22 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:962269 TSF:MSG:BC
2020-04-19 22:06:22 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:962277 TSF:MSG:FPAR REQ,ID=2
2020-04-19 22:06:22 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:962289 TSF:PNG:SEND,TO=0
2020-04-19 22:06:22 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:962299 TSF:CKU:OK
2020-04-19 22:06:22 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:962308 TSF:MSG:GWL OK
2020-04-19 22:06:23 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:963104 TSF:MSG:SEND,0-0-2-2,s=255,c=3,t=8,pt=1,l=1,sg=0,ft=0,st=OK:0
2020-04-19 22:06:24 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:964259 TSF:MSG:READ,2-2-0,s=255,c=3,t=24,pt=1,l=1,sg=0:1
2020-04-19 22:06:24 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:964278 TSF:MSG:PINGED,ID=2,HP=1
2020-04-19 22:06:24 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:964501 TSF:MSG:SEND,0-0-2-2,s=255,c=3,t=25,pt=1,l=1,sg=0,ft=0,st=OK:1
2020-04-19 22:06:24 DEBUG (MainThread) [mysensors.handler] n:0 c:255 t:3 s:9 p:964528 TSF:MSG:READ,2-2-0,s=255,c=3,t=32,pt=5,l=4,sg=0:500

Am I reading this right that the connection to the chip failed? Any ideas how this could happens and what triggers a restart?

kiesel

Even more weirdness: I tried to workaround this by creating an input_boolean, to decouple the switch.toggle from the mysensors integration.

I am using this automation to toggle the input_boolean:

alias: 'Infrared Debug'
trigger:
  platform: state
  entity_id: sensor.mysensors_wohnzimmer_main_3_3
condition:
  condition: or
  conditions:
    - condition: template
      value_template: "{{ trigger.to_state.state == '551505585' }}"
    - condition: template
      value_template: "{{ trigger.to_state.state == '34469099' }}"
action:
  - service: system_log.write
    data_template:
      message: >
              "Automation IR Debug: {{trigger.to_state.state}}"
      level: warning
  - service: input_boolean.toggle
    entity_id: input_boolean.wa_kleine_lampe_infrared_switch

And this automation to toggle the switch when a change of the input_boolean is detected:

alias: 'Infrared Debug'
trigger:
  platform: state
  entity_id: input_boolean.wa_kleine_lampe_infrared_switch
action:
  - service: switch.toggle
    entity_id: switch.kleine_lampe

Still, the integration freezes for some time. If I omit the second automation (don't toggle the switch) then I can press the remote button for all eternity (untested) and the integration doesn't crash/freeze.

There must be some sort of feedback that's too much for the mysensors integration. I noticed the switch is somewhat slow, could the slowness of the switch be the issue here? It's a plug running the newest tasmota firmware (updated it because of this issue).

monte

@kiesel what type of transport do you use? Serial, MQTT, Ethernet? Have you read this paragraph from the manual:
"The MySensors switch platform exposes a service to change an IR code attribute for an IR switch device and turn the switch on. The IR switch will automatically be turned off after being turned on, if optimistic is set to true in the configuration for the MySensors component. This will simulate a push button on a remote. If optimistic is false, the MySensors device will have to report its updated state to reset the switch"?
Maybe this is the problem?

kiesel

@monte

If I get that correctly then that manual is about sending an IR-code to a node, but I am receiving an IR-code from a node. Based on that code I then want to do certain things, like turning a lamp on.

I am using a serial gateway, here is the corresponding config:

mysensors:
  gateways:
        - device: '/dev/ttyUSB0'
          baud_rate: 38400
  version: '2.3'

And here is the sketch of the node with the IR-receiver:

// Enable debug prints
//#define MY_DEBUG

#define MY_OWN_DEBUG

#ifndef MY_OWN_DEBUG //disable serial in production compile, potentially saves few uA in sleep mode
     #define MY_DISABLED_SERIAL
#endif


// Enable and select radio type attached
#define MY_RADIO_RFM69
#define MY_IS_RFM69HW
#define MY_RFM69_NEW_DRIVER


#define MY_NODE_ID 3
#include <MySensors.h>

// IR specific setup  
#include <IRremote.h>
int RECV_PIN     = 3;
IRrecv            irrecv(RECV_PIN);
decode_results    ircode;

unsigned long last_value;
// IR specific setup end

#define CHILD_ID_HUM  0
#define CHILD_ID_TEMP 1
#define CHILD_ID_LUX  2
#define CHILD_ID_IR 3

#define SKETCH_NAME "mysensors_wohnzimmer_main"
#define SKETCH_MAJOR_VER "1"
#define SKETCH_MINOR_VER "0"

static bool metric = true;

int BATTERY_SENSE_PIN = A0;  // select the input pin for the battery sense point
int oldBatteryPcnt = 0;

float lastHum = 0;
float lastTemp = 0;
int lastLux = 0;


// Sleep time between sensor updates (in milliseconds)
static const unsigned long UPDATE_INTERVAL = 90000;

#include <SI7021.h>
#include <BH1750.h>

static SI7021 tempsensor;
BH1750 lightmeter;


// Change to V_LIGHT if you use S_LIGHT in presentation below
MyMessage msgHum(CHILD_ID_HUM, V_HUM);
MyMessage msgTemp(CHILD_ID_TEMP, V_TEMP);
MyMessage msgLux(CHILD_ID_LUX, V_LEVEL);
MyMessage msgIrRecord(CHILD_ID_IR, V_IR_RECEIVE); 



void presentation()  
{ 
 // Send the sketch version information to the gateway and Controller
  sendSketchInfo(SKETCH_NAME, SKETCH_MAJOR_VER "." SKETCH_MINOR_VER);

  present(CHILD_ID_HUM, S_HUM);
   present(CHILD_ID_TEMP, S_TEMP);
  present(CHILD_ID_LUX, S_LIGHT_LEVEL);
  present(CHILD_ID_IR, S_IR);
}

void setup()
{
  //Serial.begin(9600);
  //Serial.print("Starting: ");
  while (not tempsensor.begin())
  {
    Serial.println(F("Temperaturesensor not detected!"));
    delay(5000);
  }
    #ifdef MY_OWN_DEBUG
    Serial.println("Tempsensor started");
  #endif
  lightmeter.begin();
  #ifdef MY_OWN_DEBUG
    Serial.print("UPDATE_INTERVAL:");Serial.println(UPDATE_INTERVAL);
  #endif
  irrecv.enableIRIn();
}


void loop(){
  int8_t wake_reason;
  //send(msgIrRecord.set(0));
  sleep_bod_disable();//disable BOD  - saves~ 15uA
  wake_reason = sleep(RECV_PIN-2, FALLING, UPDATE_INTERVAL);
  #ifdef MY_OWN_DEBUG
  Serial.print("wake_reason=");Serial.println(wake_reason);
  
  #endif
  if (wake_reason == 1){
    //woken up by interrupt on d3
    ir_received();
  }
  else{
    //woken by update_interval
    update_interval();
  }

  //send battery value
  //battery(); //TODO

}

void ir_received(){
  delay(100);
  detachInterrupt(RECV_PIN-2);
    
    if (irrecv.decode(&ircode)) {
      //#ifdef MY_OWN_DEBUG
      //dump(&ircode);
      //#endif
      unsigned long ir_value = ircode.value;
      if (ir_value == REPEAT) //if repeat-code: send last code
      {
         ir_value = last_value;
      }
      else{ //if not: save new value as last value
        last_value = ir_value;
      }
      #ifdef MY_OWN_DEBUG
      Serial.println(ir_value,HEX);
      Serial.println(ir_value);
      #endif
      
      send(msgIrRecord.set(ir_value));
      delay(150); //without this appdaemon doesn't have enough time to react.
      send(msgIrRecord.set(0));
      irrecv.resume(); // Receive the next value
    }
    //delay(100);


    Serial.println("IR Processing done--------------------");
}

void update_interval()      
{  
  #ifdef MY_OWN_DEBUG
  Serial.println("In loop");
  #endif
  // Read temperature & humidity from sensor.
  const float temperature = float( metric ? tempsensor.getCelsiusHundredths() : tempsensor.getFahrenheitHundredths() ) / 100.0;
  float roundedTemp = floorf(temperature * 10) / 10; //round temp down to 1 decimal
  const float humidity    = float( tempsensor.getHumidityBasisPoints() ) / 100.0;
  float roundedHum = floorf(humidity * 10) / 10; //round humidty down to 1 decimal

  lightmeter.configure(BH1750_ONE_TIME_HIGH_RES_MODE);
  //delay(500); // Allow some time
  const uint16_t lux = lightmeter.readLightLevel();

#ifdef MY_OWN_DEBUG
  Serial.print(F("Temp "));
  Serial.print(temperature);
  Serial.print(metric ? 'C' : 'F');
  Serial.print(F("\tHum "));
  Serial.println(humidity);

  Serial.print("Light: ");
  Serial.print(lux);
  Serial.println(" lx");

  Serial.println("-------");
#endif

  if (lastHum != roundedHum){
      #ifdef MY_OWN_DEBUG
        Serial.print("roundedHum: ");Serial.println(roundedHum);
      #endif
    send(msgHum.set(roundedHum, 1));
    lastHum = roundedHum;
  }

  if (lastTemp != roundedTemp){
    send(msgTemp.set(temperature, 1));
    lastTemp = roundedTemp;
  }

  if (lastLux != lux){
    send(msgLux.set(lux, 1));
    lastLux = lux;
  }

  //send battery value
  battery();



  // Sleep until next update to save energy
  //sleep_bod_disable();//disable BOD  - saves~ 15uA
  //smartSleep(UPDATE_INTERVAL); 
}

void battery(){
      // get the battery Voltage
    int sensorValue = analogRead(BATTERY_SENSE_PIN);
#ifdef MY_OWN_DEBUG
    Serial.println(sensorValue);
#endif

    // 1M, 470K divider across battery and using internal ADC ref of 1.1V
    // Sense point is bypassed with 0.1 uF cap to reduce noise at that point
    // ((1e6+470e3)/470e3)*1.1 = Vmax = 3.44 Volts
    // 3.44/1023 = Volts per bit = 0.003363075

    int batteryPcnt = sensorValue / 10;

#ifdef MY_OWN_DEBUG
    float batteryV  = sensorValue * 0.003363075;//3.44v
    //float batteryV  = sensorValue *   0.002541544; //2.6v
    Serial.print("Battery Voltage: ");
    Serial.print(batteryV);
    Serial.println(" V");

    Serial.print("Battery percent: ");
    Serial.print(batteryPcnt);
    Serial.println(" %");
#endif

    if (oldBatteryPcnt != batteryPcnt) {
        // Power up radio after sleep
        sendBatteryLevel(batteryPcnt);
        oldBatteryPcnt = batteryPcnt;
    }

}

The node is waken up by an interrupt when the ir-sensor reads a code. It also polls the other two sensors (temp/humid, lux) once every 90 seconds.

kiesel

Ok, so I think I have been getting at this the wrong way around...

Switching the switch on and off kills the integration/the gateway, it doesn't matter whether the node sent an ir-code to the gateway first. I verified this by opening lovelace and turning the switch on and off from there a few times. The result is that no new messages can be received from any nodes.

The switch in question is a tasmota flashed Gosund SP1 switch that has auto-discovery for Home Assistant activated (SetOption19). It connects to Home Assistant via mqtt. Since the gateway is a serial gateway I can't see how mqtt messages could kill the gateway.

kiesel

I found the issue. Everything works as expected when I use put the plug into another outlet. So this must be a power issue. I will create another thread for how to fix this.

monte

@kiesel interesting! But weird :)
But why the power issue with one of the devices connected to HA breaks integration with Mysensors particularly?

mysensors integration freezes when it triggers switch.toggle

20

11.7k

11.2k

113.1k