MQTTClientGateway broken after upgrade - signature failure

[tomkxy]

I just upgraded my MQTTClientGateway to the most current version of development branch.
In parallel, I uploaded re-compiled sketches to my sensors.

It seems that there is an issue now with respect to signature handling. I used to have ATASHA204 on all my sensors and the gateway.

I already realized that the current version does not seem to support hardware signing so I change to soft signing including uploading the HMAC Key to EEPROM.

I appended the log and the sketches. It seems that the gateway expects a signed message which it does not receive. However, I have signing enabled in the sensor.

I am absolutely stuck and have no glue what the reason is. Any help is highly appreciated.
Interesting enough and just more confusing, after I first uploaded the new sketch to the MQTT Gateway, I saw in the beginning some messages appear in the MQTT broker.

Gateway log:

;255;3;0;9;Starting gateway (RNNGAS, 2.0.0-beta)
0;255;3;0;9;Radio init successful.
0;255;3;0;9;Init complete, id=0, parent=0, distance=0
0;255;3;0;9;Skipping security for command 3 type 16
0;255;3;0;9;read: 26-26-0 s=4,c=3,t=16,pt=0,l=0,sg=0:
0;255;3;0;9;Signing backend: ATSHA204Soft
0;255;3;0;9;SHA256: 6420A6958C538FE9A8076F1F48ACDE828A4A7886859393A20200000000000000
0;255;3;0;9;Transmittng nonce
0;255;3;0;9;Skipping security for command 3 type 17
0;255;3;0;9;send: 0-0-26-26 s=255,c=3,t=17,pt=6,l=25,sg=0,st=fail:6420A6958C538FE9A8076F1F48ACDE828A4A7886859393A202
0;255;3;0;9;Attempting MQTT connection...
0;255;3;0;9;MQTT connected
0;255;3;0;9;Message is not signed, but it should have been!
0;255;3;0;9;verify fail
0;255;3;0;9;Verification timeout
0;255;3;0;9;Skipping security for command 3 type 16
0;255;3;0;9;read: 27-24-0 s=0,c=3,t=16,pt=0,l=0,sg=0:
0;255;3;0;9;Signing backend: ATSHA204Soft
0;255;3;0;9;SHA256: D916CCAA20E05C5533CD2919E2B5286C0559C1552A7F55922CAAAAAAAAAAAAAA
0;255;3;0;9;Transmittng nonce
0;255;3;0;9;Skipping security for command 3 type 17
0;255;3;0;9;send: 0-0-24-27 s=255,c=3,t=17,pt=6,l=25,sg=0,st=fail:D916CCAA20E05C5533CD2919E2B5286C0559C1552A7F55922C
0;255;3;0;9;Message is not signed, but it should have been!
0;255;3;0;9;verify fail
0;255;3;0;9;Verification timeout
0;255;3;0;9;Skipping security for command 3 type 16
0;255;3;0;9;read: 27-24-0 s=0,c=3,t=16,pt=0,l=0,sg=0:
0;255;3;0;9;Signing backend: ATSHA204Soft
0;255;3;0;9;SHA256: 9394294CFBA825C26112C731879AEC90CF0AA0AA2E1338A01EAAAAAAAAAAAAAA
0;255;3;0;9;Transmittng nonce
0;255;3;0;9;Skipping security for command 3 type 17
0;255;3;0;9;send: 0-0-24-27 s=255,c=3,t=17,pt=6,l=25,sg=0,st=fail:9394294CFBA825C26112C731879AEC90CF0AA0AA2E1338A01E
0;255;3;0;9;Verification timeout
0;255;3;0;9;Message is not signed, but it should have been!
0;255;3;0;9;verify fail
0;255;3;0;9;Skipping security for command 3 type 16
0;255;3;0;9;read: 26-26-0 s=255,c=3,t=16,pt=0,l=0,sg=0:
0;255;3;0;9;Signing backend: ATSHA204Soft
0;255;3;0;9;SHA256: 2ECD2A1584FBBB9E269C4DAF8714FA393D6BA2CBD403BF71D1AAAAAAAAAAAAAA
0;255;3;0;9;Transmittng nonce
0;255;3;0;9;Skipping security for command 3 type 17
0;255;3;0;9;send: 0-0-26-26 s=255,c=3,t=17,pt=6,l=25,sg=0,st=fail:2ECD2A1584FBBB9E269C4DAF8714FA393D6BA2CBD403BF71D1
0;255;3;0;9;Message is not signed, but it should have been!
0;255;3;0;9;verify fail
0;255;3;0;9;Verification timeout
0;255;3;0;9;Skipping security for command 3 type 16
0;255;3;0;9;read: 26-26-0 s=255,c=3,t=16,pt=0,l=0,sg=0:
0;255;3;0;9;Signing backend: ATSHA204Soft
0;255;3;0;9;SHA256: 49B80D12C8ED30598B0E4119D1C2F828EE38FD6B035EF520ABAAAAAAAAAAAAAA
0;255;3;0;9;Transmittng nonce
0;255;3;0;9;Skipping security for command 3 type 17
0;255;3;0;9;send: 0-0-26-26 s=255,c=3,t=17,pt=6,l=25,sg=0,st=fail:49B80D12C8ED30598B0E4119D1C2F828EE38FD6B035EF520AB
0;255;3;0;9;Skipping security for command 3 type 16
0;255;3;0;9;read: 27-24-0 s=2,c=3,t=16,pt=0,l=0,sg=0:
0;255;3;0;9;Signing backend: ATSHA204Soft
0;255;3;0;9;SHA256: 261B252BA8FFFB20085C9B493EDA9CCC9F6293095009C5F306AAAAAAAAAAAAAA
0;255;3;0;9;Transmittng nonce
0;255;3;0;9;Skipping security for command 3 type 17
0;255;3;0;9;send: 0-0-24-27 s=255,c=3,t=17,pt=6,l=25,sg=0,st=fail:261B252BA8FFFB20085C9B493EDA9CCC9F6293095009C5F306
0;255;3;0;9;Message is not signed, but it should have been!
0;255;3;0;9;verify fail
0;255;3;0;9;Skipping security for command 3 type 16
0;255;3;0;9;read: 26-26-0 s=1,c=3,t=16,pt=0,l=0,sg=0:
0;255;3;0;9;Signing backend: ATSHA204Soft
0;255;3;0;9;SHA256: 74F626A70BC176FE2D2B1E0EDD64DE4110A6E210551B7E32BEAAAAAAAAAAAAAA
0;255;3;0;9;Transmittng nonce
0;255;3;0;9;Skipping security for command 3 type 17
0;255;3;0;9;send: 0-0-26-26 s=255,c=3,t=17,pt=6,l=25,sg=0,st=fail:74F626A70BC176FE2D2B1E0EDD64DE4110A6E210551B7E32BE
0;255;3;0;9;Message is not signed, but it should have been!
0;255;3;0;9;verify fail
0;255;3;0;9;Skipping security for command 3 type 16
0;255;3;0;9;read: 27-24-0 s=2,c=3,t=16,pt=0,l=0,sg=0:
0;255;3;0;9;Signing backend: ATSHA204Soft
0;255;3;0;9;SHA256: D6F7E817BF30213995EDF2B5709EC24687583DEF1BA2B7DFD3AAAAAAAAAAAAAA
0;255;3;0;9;Transmittng nonce
0;255;3;0;9;Skipping security for command 3 type 17
0;255;3;0;9;send: 0-0-24-27 s=255,c=3,t=17,pt=6,l=25,sg=0,st=fail:D6F7E817BF30213995EDF2B5709EC24687583DEF1BA2B7DFD3

MQTTClientGateway sketch (using ethernet shield W5100)

/**
 * The MySensors Arduino library handles the wireless radio link and protocol
 * between your home built sensors/actuators and HA controller of choice.
 * The sensors forms a self healing radio network with optional repeaters. Each
 * repeater and gateway builds a routing tables in EEPROM which keeps track of the
 * network topology allowing messages to be routed to nodes.
 *
 * Created by Henrik Ekblad <henrik.ekblad@mysensors.org>
 * Copyright (C) 2013-2015 Sensnology AB
 * Full contributor list: https://github.com/mysensors/Arduino/graphs/contributors
 *
 * Documentation: http://www.mysensors.org
 * Support Forum: http://forum.mysensors.org
 *
 * This program is free software; you can redistribute it and/or
 * modify it under the terms of the GNU General Public License
 * version 2 as published by the Free Software Foundation.
 *
 *******************************
 *
 * REVISION HISTORY
 * Version 1.0 - Henrik Ekblad
 * 
 * DESCRIPTION
 * The W5100 MQTT gateway sends radio network (or locally attached sensors) data to your MQTT broker.
 * The node also listens to MY_MQTT_TOPIC_PREFIX and sends out those messages to the radio network
 *
 * LED purposes:
 * - To use the feature, uncomment WITH_LEDS_BLINKING in MyConfig.h
 * - RX (green) - blink fast on radio message recieved. In inclusion mode will blink fast only on presentation recieved
 * - TX (yellow) - blink fast on radio message transmitted. In inclusion mode will blink slowly
 * - ERR (red) - fast blink on error during transmission error or recieve crc error  
 * 
 * See http://www.mysensors.org/build/esp8266_gateway for wiring instructions.
 * nRF24L01+  ESP8266
 * VCC        VCC
 * CE         GPIO4          
 * CSN/CS     GPIO15
 * SCK        GPIO14
 * MISO       GPIO12
 * MOSI       GPIO13
 *            
 * Not all ESP8266 modules have all pins available on their external interface.
 * This code has been tested on an ESP-12 module.
 * The ESP8266 requires a certain pin configuration to download code, and another one to run code:
 * - Connect REST (reset) via 10K pullup resistor to VCC, and via switch to GND ('reset switch')
 * - Connect GPIO15 via 10K pulldown resistor to GND
 * - Connect CH_PD via 10K resistor to VCC
 * - Connect GPIO2 via 10K resistor to VCC
 * - Connect GPIO0 via 10K resistor to VCC, and via switch to GND ('bootload switch')
 * 
  * Inclusion mode button:
 * - Connect GPIO5 via switch to GND ('inclusion switch')
 * 
 * Hardware SHA204 signing is currently not supported!
 *
 * Make sure to fill in your ssid and WiFi password below for ssid & pass.
 */

#include <SPI.h>

#define MY_DEBUG_VERBOSE_SIGNING //!< Enable signing related debug prints to serial monitor


// Hardware signing not yet supported
#define MY_SIGNING_FEATURE
#define MY_SIGNING_SOFT
//#define MY_SIGNING_ATSHA204
//#define MY_SIGNING_ATSHA204_PIN A3
#define MY_SIGNING_REQUEST_SIGNATURES

// Enable debug prints to serial monitor
#define MY_DEBUG 

// Enables and select radio type (if attached)
#define MY_RADIO_NRF24
//#define MY_RADIO_RFM69

#define MY_GATEWAY_MQTT_CLIENT

// Set this nodes subscripe and publish topic prefix
#define MY_MQTT_PUBLISH_TOPIC_PREFIX "GW1_out"
#define MY_MQTT_SUBSCRIBE_TOPIC_PREFIX "GW1_in"

// Set MQTT client id
#define MY_MQTT_CLIENT_ID "mysensors-1"

// W5100 Ethernet module SPI enable (optional if using a shield/module that manages SPI_EN signal)
#define MY_W5100_SPI_EN 4  


// Enable Soft SPI for NRF radio (note different radio wiring is required)
// The W5100 ethernet module seems to have a hard time co-operate with 
// radio on the same spi bus.
#if !defined(MY_W5100_SPI_EN) && !defined(ARDUINO_ARCH_SAMD)
  #define MY_SOFTSPI
  #define MY_SOFT_SPI_SCK_PIN 14
  #define MY_SOFT_SPI_MISO_PIN 16
  #define MY_SOFT_SPI_MOSI_PIN 15
#endif  


// When W5100 is connected we have to move CE/CSN pins for NRF radio
//#define MY_RF24_CE_PIN 5
//#define MY_RF24_CS_PIN 6

// CE_PIN and SPI_SS_PIN for Mega
#define MY_RF24_CE_PIN    48			// radio chip enable
#define MY_RF24_CS_PIN    49			// radio SPI serial select

// Enable these if your MQTT broker requires usenrame/password
#define MY_MQTT_USER "gw"
#define MY_MQTT_PASSWORD "wL6g401gUIUa3xwQ"

// Enable MY_IP_ADDRESS here if you want a static ip address (no DHCP)
#define MY_IP_ADDRESS 192,168,178,11

// If using static ip you need to define Gateway and Subnet address as well
#define MY_IP_GATEWAY_ADDRESS 192,168,178,1
#define MY_IP_SUBNET_ADDRESS 255,255,255,0

// MQTT broker ip address or url. Define one or the other. 
//#define MY_CONTROLLER_URL_ADDRESS "m20.cloudmqtt.com"
#define MY_CONTROLLER_IP_ADDRESS 192, 168, 178, 74

// The MQTT broker port to to open 
#define MY_PORT 1883      

 /*
// Flash leds on rx/tx/err
#define MY_LEDS_BLINKING_FEATURE
// Set blinking period
#define MY_DEFAULT_LED_BLINK_PERIOD 300

// Enable inclusion mode
#define MY_INCLUSION_MODE_FEATURE
// Enable Inclusion mode button on gateway
#define MY_INCLUSION_BUTTON_FEATURE
// Set inclusion mode duration (in seconds)
#define MY_INCLUSION_MODE_DURATION 60 
// Digital pin used for inclusion mode button
#define MY_INCLUSION_MODE_BUTTON_PIN  3 

// Uncomment to override default HW configurations
//#define MY_DEFAULT_ERR_LED_PIN 16  // Error led pin
//#define MY_DEFAULT_RX_LED_PIN  16  // Receive led pin
//#define MY_DEFAULT_TX_LED_PIN  16  // the PCB, on board LED
*/

#include <Ethernet.h>
#include <MySensor.h>


void setup() { 
}

void presentation() {
  // Present locally attached sensors here    
}


void loop() {
  // Send locally attech sensors data here
}

Sensor Sketch:

/*
Multisensor Sketch

Author: Thomas Krebs, thkrebs@gmx.de

This sketch reads temperature, humidity, light and presence.
It is based on the various examples sketches from SparkFun and MySensors 

It uses the following sensors:
Light           - TSL2561
Temp&Humidity   - HTU21D
Presence 

HTU21D and TLS2561 need to connect the I2C pins (SCL and SDA) to your Arduino.
The pins are different on different Arduinos:

                    SDA    SCL
Any Arduino         "SDA"  "SCL"
Uno, Redboard, Pro  A4     A5
Mega2560, Due       20     21
Leonardo            2      3

*/
#define MY_DEBUG_VERBOSE_SIGNING //!< Enable signing related debug prints to serial monitor

#define MY_SIGNING_FEATURE
#define MY_RADIO_NRF24
#define MY_SIGNING_ATSHA204
#define MY_DEBUG
#define MY_NODE_ID              26
#define MY_SIGNING_ATSHA204_PIN 17
#define MY_SIGNING_REQUEST_SIGNATURES

#define BATT_SENSOR

#include <MySensor.h>
#include <TSL2561.h>
#include <SparkFunHTU21D.h>

#include <SPI.h>
#include <Wire.h>
#include <avr/power.h>

#define VERSION           "1.3"
#define SKETCH_NAME       "Multisensor Sketch Type A - Battery Powered Temp/Humid/Light/Presence"

#define TEMP_CHILD_ID   1
#define HUM_CHILD_ID    2
#define LIGHT_CHILD_ID  3
#define MOTION_CHILD_ID 4

// Uncomment the line below, to transmit battery voltage as a normal sensor value
#define BATT_SENSOR    199
#define MAX_VOLTAGE    1316
#define MIN_VOLTAGE    890     // it seems that about 0.89 V the sensor stops working

// How many milli seconds between each measurement
#define MEASURE_INTERVAL 120000

unsigned long SLEEP_TIME = 30000;  // Sleep time between reads (in milliseconds)

// FORCE_TRANSMIT_INTERVAL, this number of times of wakeup, the sensor is forced to report all values to the controller
#define FORCE_TRANSMIT_INTERVAL 30 

// When MEASURE_INTERVAL is 60000 and FORCE_TRANSMIT_INTERVAL is 30, we force a transmission every 30 minutes.
// Between the forced transmissions a tranmission will only occur if the measured value differs from the previous measurement

// HUMI_TRANSMIT_THRESHOLD tells how much the humidity should have changed since last time it was transmitted. Likewise with
// TEMP_TRANSMIT_THRESHOLD for temperature threshold.
#define HUMI_TRANSMIT_THRESHOLD   0.5
#define TEMP_TRANSMIT_THRESHOLD   0.5
#define LIGHT_TRANSMIT_THRESHOLD  0.3    // relative change


// Pin definitions
#define LED_PIN            13            // TODO: need to check that
#define BATTERY_SENSE_PIN  A0            // select the input pin for the battery sense point
#define MOTION_SENSOR      3             // The digital input you attached your motion sensor.  (Only 2 and 3 generates interrupt!)
#define INTERRUPT          1             // Usually the interrupt = pin -2 (on uno/nano anyway)

// Global settings
int tempMeasureCount = 0;
int lightMeasureCount = 0;

int sendBattery = 0;
boolean isMetric = true;
boolean highfreq = true;
boolean motionDetected = false;
int repeats = 3;

// Storage of old measurements
float lastTemperature = -100;
float lastHumidity = -100;
long  lastBattery = -100;
long  lastLight = -5000;
int   lastTripped = -1; 

HTU21D myHumidity;
TSL2561 myLight(TSL2561_ADDR_FLOAT); 

// Sensor messages
MyMessage msgTemp(TEMP_CHILD_ID,V_TEMP);
MyMessage msgHum(HUM_CHILD_ID,V_HUM);
MyMessage msgLight(LIGHT_CHILD_ID,V_LEVEL);
MyMessage msg(MOTION_CHILD_ID, V_TRIPPED);

#ifdef BATT_SENSOR
MyMessage msgBatt(BATT_SENSOR, V_VOLTAGE);
#endif


/****************************************************
 *
 * Setup code 
 *
 ****************************************************/
void setup()  
{ 
  pinMode(LED_PIN, OUTPUT);
  Serial.print(F(SKETCH_NAME));
  Serial.println(VERSION);
  Serial.flush();
  
  
#ifdef MY_SIGNING_ATSHA204_PIN
  // Make sure that ATSHA204 is not floating
  pinMode(MY_SIGNING_ATSHA204_PIN, INPUT);
  digitalWrite(MY_SIGNING_ATSHA204_PIN, HIGH);
#endif  
  
  // use the 1.1 V internal reference
  analogReference(INTERNAL);

  // setup sensors
  setup_htu21d();
  
  delay(100);
  setup_tls2561(); 
  delay(500);
  
  // setup motion sensor 
  pinMode(MOTION_SENSOR, INPUT);    

  Serial.flush();
  Serial.println(F(" - Online!"));
  // Send the sketch version information to the gateway and Controller
  sendSketchInfo(SKETCH_NAME, VERSION);

  // Present all sensors to controller
  present(TEMP_CHILD_ID, S_TEMP);
  present(HUM_CHILD_ID, S_HUM);
  present(LIGHT_CHILD_ID,S_LIGHT_LEVEL);
  present(MOTION_CHILD_ID, S_MOTION);

#ifdef BATT_SENSOR
  present(BATT_SENSOR, S_POWER);
#endif

  isMetric = getConfig().isMetric;
#ifdef MY_DEBUG
  Serial.print(F("isMetric: ")); Serial.println(isMetric);
#endif
  sendTempHumidityMeasurement(false);
  sendLightLevelMeasurement(false);
  sendBattLevel(false);
}

/***********************************************
/* Setup HTU21d
 ***********************************************/
void setup_htu21d() {
  myHumidity.begin();
#ifdef MY_DEBUG  
  Serial.println("Setup temp/humid sensor completed");
#endif
}


/***********************************************
/* Setup TLS2561
 ***********************************************/
void setup_tls2561() {
 
  if (myLight.begin()) {
    Serial.println(F("Found light sensor"));
  } else {
    Serial.println(F("Light Sensor not found - cont. anyway"));
  }
  myLight.setGain(TSL2561_GAIN_0X);          // set 16x gain (for dim situations)
  
  // Changing the integration time gives you a longer time over which to sense light
  // longer timelines are slower, but are good in very low light situtations!
  //tsl.setTiming(TSL2561_INTEGRATIONTIME_13MS);  // shortest integration time (bright light)
  myLight.setTiming(TSL2561_INTEGRATIONTIME_101MS);  // medium integration time (medium light)
  //tsl.setTiming(TSL2561_INTEGRATIONTIME_402MS);  // longest integration time (dim light)
  
}

/***********************************************
 *
 *  Main loop function
 *
 ***********************************************/
void loop()     
{     
  tempMeasureCount++;
  lightMeasureCount++;
  sendBattery++;
  bool forceTransmit = false;

  if (motionDetected) {
    sendMotion(false);  // do not force transmission unless it motion status has changed
    motionDetected = false;
  }
  else {
    
    // I do the battery check at the beginning
    if (sendBattery > 60) {
       sendBattLevel(forceTransmit); // Not needed to send battery info that often
       sendBattery = 0;
    }
    
    if ((lightMeasureCount > FORCE_TRANSMIT_INTERVAL) || (tempMeasureCount > FORCE_TRANSMIT_INTERVAL) ) { // force a transmission
      forceTransmit = true; 
      tempMeasureCount = 0;
      lightMeasureCount = 0;
    }
  
    // Get & send sensor data
    sendTempHumidityMeasurement(forceTransmit);
    sendLightLevelMeasurement(forceTransmit);
    sendMotion(forceTransmit);
  } 
  wait(100);  // I don't know whether that is really required; however I have the impression that shutting down the radio leads to
                 // problems in the communication when using signatures
  
  if (sleep(INTERRUPT,RISING, MEASURE_INTERVAL)) {
    motionDetected = true;
  }
}

/*********************************************
 *
 * Sends state of motion sensor
 *
 * Parameters
 * - force : Forces transmission of a value (even if it's the same as previous measurement)
 *
 *********************************************/
void sendMotion(bool force) {
 
  bool tx = force;
  
  // Read digital motion value
  bool tripped = digitalRead(MOTION_SENSOR) == HIGH; 
  Serial.print(F("Tripped: ")); Serial.println(tripped);
  
  if (lastTripped != tripped) tx = true;
  if (tx) {
    resend(msg.set(tripped?"1":"0"),repeats);  // Send tripped value to gw 
    lastTripped = tripped;
  }
}

/*********************************************
 *
 * Sends temperature and humidity from HTU21D sensor
 *
 * Parameters
 * - force : Forces transmission of a value (even if it's the same as previous measurement)
 *
 *********************************************/
void sendTempHumidityMeasurement(bool force) 
{
    bool tx = force;
    
    float hum = myHumidity.readHumidity();
    float temp = myHumidity.readTemperature();
    
    Serial.print(F("lastTemperature: ")); Serial.println(lastTemperature);
    Serial.print(F("lastHumidity: ")); Serial.println(lastHumidity);
    
    float diffTemp = abs(lastTemperature - temp);
    float diffHum = abs(lastHumidity - hum);

#ifdef MY_DEBUG
    Serial.print(F("TempDiff :"));Serial.println(diffTemp);
    Serial.print(F("HumDiff  :"));Serial.println(diffHum); 
#endif

    if (isnan(diffHum)) tx = true; 
    if (diffTemp > TEMP_TRANSMIT_THRESHOLD) tx = true;
    if (diffHum >= HUMI_TRANSMIT_THRESHOLD) tx = true;

    if (tx) {
      tempMeasureCount = 0;
      resend(msgTemp.setSensor(TEMP_CHILD_ID).set(temp,1),repeats); 
      resend(msgHum.setSensor(HUM_CHILD_ID).set(hum,1),repeats); 
      lastTemperature = temp;
      lastHumidity = hum;   
    }
}


/*********************************************
 *
 * Sends light level from TLS6512 sensor
 *
 * Parameters
 * - force : Forces transmission of a value (even if it's the same as previous measurement)
 *
 *********************************************/
void sendLightLevelMeasurement(bool force) {
  bool tx = force;
  
  uint32_t lum = myLight.getFullLuminosity();
  uint16_t ir, full;
  ir = lum >> 16;
  full = lum & 0xFFFF;
  
  Serial.print(F("IR: ")); Serial.print(ir);   Serial.print(F("\t\t"));
  Serial.print(F("Full: ")); Serial.print(full);   Serial.print(F("\t"));
  Serial.print(F("Visible: ")); Serial.print(full - ir);   Serial.print(F("\t"));
  
  double lux = myLight.calculateLux(full, ir);
  Serial.print(F("Lux: ")); Serial.println(lux);
  float diffLux = abs(lastLight - lux);
#ifdef MY_DEBUG
    Serial.print(F("Lux difference since last measurement: ")); Serial.println((float)diffLux/abs(lastLight));    
#endif
    if (isnan(diffLux)) tx = true; 
    if (diffLux/abs(lastLight)  >= LIGHT_TRANSMIT_THRESHOLD) tx = true;

    if (tx) {
      lightMeasureCount = 0;
      resend(msgLight.setSensor(LIGHT_CHILD_ID).set(lux,1),repeats);
      lastLight = lux;
    }
}


/*********************************************
 * Prints error on I2C comm bus
 *********************************************/
void printError(byte error)
  // If there's an I2C error, this function will
  // print out an explanation.
{
  Serial.print(F("I2C error: "));
  Serial.print(error,DEC);
  Serial.print(F(", "));
  
  switch(error)
  {
    case 0:
      Serial.println(F("success"));
      break;
    case 1:
      Serial.println(F("data too long for transmit buffer"));
      break;
    case 2:
      Serial.println(F("received NACK on address (disconnected?)"));
      break;
    case 3:
      Serial.println(F("received NACK on data"));
      break;
    case 4:
      Serial.println(F("other error"));
      break;
    default:
      Serial.println(F("unknown error"));
  }
}


/********************************************
 *
 * Sends battery information (battery percentage)
 *
 * Parameters
 * - force : Forces transmission of a value
 *
 *******************************************/
void sendBattLevel(bool force)
{
  if (force) lastBattery = -1;
  long batteryV =  analogRead(BATTERY_SENSE_PIN);  
  for (int i = 1; i<5; i++) {
    long newSample = analogRead(BATTERY_SENSE_PIN); //readVcc();
    batteryV -= batteryV / (i+1);
    batteryV += newSample / (i+1);   
  }
   
   // 10M, 2,86M 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
   // ((10+4,7)/4,7)*1.1 = 3.4404255
   // 3.4404255/1023 = Volts per bit = 0.003630748

  long vcc  = batteryV * 3.3630748;
  if (vcc != lastBattery) {
    lastBattery = vcc;

#ifdef BATT_SENSOR
    resend(msgBatt.set(vcc),repeats);
#endif
    // Calculate on the fully charged cell. Since I have a step-up in place I go as low as possible no offset for minimum
   sendBatteryLevel(  ((vcc-MIN_VOLTAGE)*10.0)/((MAX_VOLTAGE-MIN_VOLTAGE)*10.0) *100.0);
  }
}


/********************************************
 *
 * Send message, resend on error
 *
 * Parameters
 * - msg : message to send
 * - repeats: number of repetitions
 *
 *******************************************/
void resend(MyMessage &msg, int repeats)
{
  int repeat = 1;
  int repeatdelay = 0;
  boolean sendOK = false;

  while ((sendOK == false) and (repeat < repeats)) {
    if (send(msg)) {
      sendOK = true;
    } else {
      sendOK = false;
      Serial.print(F("Send ERROR "));
      Serial.println(repeat);
      repeatdelay += random(50,200);
    } 
    repeat++; 
    delay(repeatdelay);
  }
}


/*******************************************
 *
 * Internal battery ADC measuring 
 *
 *******************************************/
long readVcc() {
  // Read 1.1V reference against AVcc
  // set the reference to Vcc and the measurement to the internal 1.1V reference
  #if defined(__AVR_ATmega32U4__) || defined(__AVR_ATmega1280__) || defined(__AVR_ATmega2560__)
    ADMUX = _BV(REFS0) | _BV(MUX4) | _BV(MUX3) | _BV(MUX2) | _BV(MUX1);
  #elif defined (__AVR_ATtiny24__) || defined(__AVR_ATtiny44__) || defined(__AVR_ATtiny84__)
    ADMUX = _BV(MUX5) | _BV(MUX0);
  #elif defined (__AVR_ATtiny25__) || defined(__AVR_ATtiny45__) || defined(__AVR_ATtiny85__)
    ADcdMUX = _BV(MUX3) | _BV(MUX2);
  #else
    ADMUX = _BV(REFS0) | _BV(MUX3) | _BV(MUX2) | _BV(MUX1);
  #endif  
 
  delay(2); // Wait for Vref to settle
  ADCSRA |= _BV(ADSC); // Start conversion
  while (bit_is_set(ADCSRA,ADSC)); // measuring
 
  uint8_t low  = ADCL; // must read ADCL first - it then locks ADCH  
  uint8_t high = ADCH; // unlocks both
 
  long result = (high<<8) | low;
 
  result = 1125300L / result; // Calculate Vcc (in mV); 1125300 = 1.1*1023*1000
  return result; // Vcc in millivolts
}

[tomkxy]

I have just collected the log from the sensor node. I also removed a repeater node which I had out of the communication chain.

From the log it seems that the node requests a nonce but does not receive it, although the gateway seems to send one...

Increasing MY_VERIFICATION_TIMEOUT_MS to 15000 did change anything.

Starting sensor (RNNNAA, 2.0.0-beta)
Radio init successful.
Multisensor Sketch Type A - Battery Powered Temp/Humid/Light/Presence1.3
Setup temp/humid sensor completed
Found light sensor
 - Online!
Skipping security for command 3 type 16
send: 26-26-0-0 s=255,c=3,t=16,pt=0,l=0,sg=0,st=ok:
Nonce requested from 0. Waiting...
Timeout waiting for nonce!
sign fail
send: 26-26-0-0 s=255,c=3,t=11,pt=0,l=25,sg=0,st=ok:Multisensor Sketch Type A
Skipping security for command 3 type 16
send: 26-26-0-0 s=255,c=3,t=16,pt=0,l=0,sg=0,st=ok:
Nonce requested from 0. Waiting...
Timeout waiting for nonce!
sign fail
send: 26-26-0-0 s=255,c=3,t=12,pt=0,l=3,sg=0,st=ok:1.3
Skipping security for command 3 type 16
send: 26-26-0-0 s=1,c=3,t=16,pt=0,l=0,sg=0,st=ok:
Nonce requested from 0. Waiting...
Timeout waiting for nonce!
sign fail
send: 26-26-0-0 s=1,c=0,t=6,pt=0,l=0,sg=0,st=ok:
Skipping security for command 3 type 16
send: 26-26-0-0 s=2,c=3,t=16,pt=0,l=0,sg=0,st=ok:
Nonce requested from 0. Waiting...
Timeout waiting for nonce!
sign fail
send: 26-26-0-0 s=2,c=0,t=7,pt=0,l=0,sg=0,st=ok:
Skipping security for command 3 type 16
send: 26-26-0-0 s=3,c=3,t=16,pt=0,l=0,sg=0,st=ok:
Nonce requested from 0. Waiting...
Message to send could not be signed!
sign fail
send: 26-26-0-0 s=3,c=0,t=16,pt=0,l=0,sg=0,st=ok:
Skipping security for command 3 type 16
send: 26-26-0-0 s=4,c=3,t=16,pt=0,l=0,sg=0,st=ok:
Nonce requested from 0. Waiting...
Message to send could not be signed!
sign fail
send: 26-26-0-0 s=4,c=0,t=1,pt=0,l=0,sg=0,st=ok:
Skipping security for command 3 type 16
send: 26-26-0-0 s=199,c=3,t=16,pt=0,l=0,sg=0,st=ok:
Nonce requested from 0. Waiting...
Timeout waiting for nonce!
sign fail
send: 26-26-0-0 s=199,c=0,t=13,pt=0,l=0,sg=0,st=ok:
isMetric: 1
lastTemperature: -100.00
lastHumidity: -100.00
TempDiff :127.42
HumDiff  :120.93
Skipping security for command 3 type 16
send: 26-26-0-0 s=1,c=3,t=16,pt=0,l=0,sg=0,st=ok:
Nonce requested from 0. Waiting...
Timeout waiting for nonce!
sign fail
send: 26-26-0-0 s=1,c=1,t=0,pt=7,l=5,sg=0,st=ok:27.4
Skipping security for command 3 type 16
send: 26-26-0-0 s=2,c=3,t=16,pt=0,l=0,sg=0,st=ok:
Nonce requested from 0. Waiting...
Timeout waiting for nonce!
sign fail
send: 26-26-0-0 s=2,c=1,t=1,pt=7,l=5,sg=0,st=ok:20.9
IR: 1		Full: 2	Visible: 1	Lux: 1.00
Lux difference since last measurement: 1.00
Skipping security for command 3 type 16
send: 26-26-0-0 s=3,c=3,t=16,pt=0,l=0,sg=0,st=ok:
Nonce requested from 0. Waiting...
Skipping security for command 3 type 17
read: 0-0-26 s=255,c=3,t=17,pt=6,l=25,sg=0:5333F4601AD619250DDA35ADEBB1E46F78EB96A1D769F33114
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 1A002EE125030000803F01
Current nonce: 5333F4601AD619250DDA35ADEBB1E46F78EB96A1D769F33114AAAAAAAAAAAAAA
HMAC: 51A6B54EB9C0BAF3A4F982216BC4764F2DD2810D74392BC952DDAA976C78A051
Signature in message: 01A6B54EB9C0BAF3A4F982216BC4764F2DD2810D
Message signed
Message to send has been signed
send: 26-26-0-0 s=3,c=1,t=37,pt=7,l=5,sg=1,st=ok:1.0
Skipping security for command 3 type 16
send: 26-26-0-0 s=199,c=3,t=16,pt=0,l=0,sg=0,st=ok:
Nonce requested from 0. Waiting...
Message to send could not be signed!
sign fail
send: 26-26-0-0 s=199,c=1,t=38,pt=4,l=4,sg=0,st=ok:1274
Skipping security for command 3 type 16
send: 26-26-0-0 s=255,c=3,t=16,pt=0,l=0,sg=0,st=ok:
Nonce requested from 0. Waiting...
Message to send could not be signed!
sign fail
send: 26-26-0-0 s=255,c=3,t=0,pt=1,l=1,sg=0,st=ok:90
Signing required
Skipping security for command 3 type 15
send: 26-26-0-0 s=255,c=3,t=15,pt=0,l=2,sg=0,st=ok:


Waiting for GW to send signing preferences...
Skipping security for command 3 type 15
read: 0-0-26 s=255,c=3,t=15,pt=0,l=2,sg=0:


Mark node 0 as one that require signed messages
Mark node 0 as one that do not require whitelisting
Skipping security for command 3 type 16
send: 26-26-0-0 s=255,c=3,t=16,pt=0,l=0,sg=0,st=ok:
Nonce requested from 0. Waiting...
Timeout waiting for nonce!
sign fail
send: 26-26-0-0 s=255,c=0,t=17,pt=0,l=10,sg=0,st=ok:2.0.0-beta
Skipping security for command 3 type 16
send: 26-26-0-0 s=255,c=3,t=16,pt=0,l=0,sg=0,st=ok:
Nonce requested from 0. Waiting...
Skipping security for command 3 type 17
read: 0-0-26 s=255,c=3,t=17,pt=6,l=25,sg=0:BDFF3B5B9BC735ADF4C3375DE3B98A0BD45BCB30469DC8D4F3
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 1A000E2306FF00
Current nonce: BDFF3B5B9BC735ADF4C3375DE3B98A0BD45BCB30469DC8D4F3AAAAAAAAAAAAAA
HMAC: 6B2DE4B7DCB4F5D4691AD3979CEA4D6DD80D8E1D0D8A659906D9F0B0B9497C66
Signature in message: 012DE4B7DCB4F5D4691AD3979CEA4D6DD80D8E1D0D8A6599
Message signed
Message to send has been signed
send: 26-26-0-0 s=255,c=3,t=6,pt=1,l=1,sg=1,st=ok:0
Init complete, id=26, parent=0, distance=1
lastTemperature: 27.42
lastHumidity: 20.93
TempDiff :0.04
HumDiff  :0.43
IR: 1		Full: 2	Visible: 1	Lux: 1.00
Lux difference since last measurement: 0.00
Tripped: 1
Skipping security for command 3 type 16
send: 26-26-0-0 s=4,c=3,t=16,pt=0,l=0,sg=0,st=ok:
Nonce requested from 0. Waiting...
Message to send could not be signed!
sign fail
send: 26-26-0-0 s=4,c=1,t=16,pt=0,l=1,sg=0,st=ok:1

[Anticimex]

Try increasing the timeout for the nonce. I don't know if MQTT logic results in a longer turnaround time for message processing.

[tomkxy]

@Anticimex I increased MY_VERIFICATION_TIMEOUT_MS to 15s. Isn't that the nonce timeout?

[Anticimex]

@tomkxy yes

[Anticimex]

@Anticimex nonce requested from node 0 looks suspicious. Is that the correct node id?

[tomkxy]

@Anticimex Isn't node 0 the gateway node id? If not that might be something to follow up on.

[Anticimex]

Ah, it's the GW. But I see from gw log that you get st=fail on the nonce so the GW does try to send it but your node does not receive it. So you have communication problems. Bear in mind that with signing, the full payload size is used, which puts maximum strain on the rf link so you have to have a solid coverage.

[tomkxy]

@Anticimex Both node were lying side by side. And I had my small network working perfectly on an older dev branch. So I don't think it can be due to coverage or distance.
Arghhh: I an only post once within 2 minutes...

[Anticimex]

@tomkxy well, your logs indicate signing works as it's supposed to. But the nonce fails to arrive, and this is also indicated by st=fail, so you have a radio issue. You probably get problems without signing as well if you transmit full length messages.

[Anticimex]

@tomkxy try moving your nodes further apart. It is sometimes hard to predict rf performance based on placement.

[tomkxy]

@Anticimex I will try it further apart. But I have other nodes having the same problem and they are sitting exactly where they were before the upgrade. The only thing I changed for the sensors is to re-compile with the latest development branch for the sensor nodes.

Only the MQTTClientGateway was running a sketch based on a rather "old" version. So that upgrade is significant.

[Anticimex]

Depending on the "leap" you have taken some changes in the rf stack could have affected things. The signing solution have been changed but it has not affected payload sizes so I do not think signing is causing this (other than forcing maximum payload sizes which it has all along).

[tomkxy]

@Anticimex I just tried to disable signing on the gateway and on the sensor and it works like a charme.
So I still hope there is some issue either in my sketch (defines etc.) or a bug. Without signing I do not consider MySensors for me as an option.

[Anticimex]

@tomkxy like I said, from the logs I see nothing wrong with signing. But your nonce is not coming through due to rf issue. I have verified signing on development branch myself (since I developed it) so I am confident it works. But it is well known that rf performance is decreasing with increased message size and I assume you don't use full size transmissions with signing disabled. So I would suggest you check rf decoupling, PA levels and antennae. It is also known that keeping radios too close can cause bursts which appear as failed transmissions but I am no specialist in those areas. Signing assume a ideal transport mechanisms, so you have to ensure there are no st=fail:s for signing related messages. The signing backend cannot handle those for you.

[tomkxy]

@Anticimex thanks for your support. Don't get me wrong I think MySensors and the whole signing concept is great. It is just somehow frustrating to see how a whole installation - even small until now - which worked for more than half a year is just breaking down while not having a glue what I can do about it.

What in particular are you referring to with reference to rf decoupling?

Just wondering how does your config look like?
What radios? What configs?

[hek]

Are you using an amplified radio on the gateway? If so, what is your PA level set to?

[Anticimex]

@tomkxy I use rf24 with default settings (except some moved io pins) and a PA-enhanced radio on the GW. But getting the rf24 to behave can be tricky. And the larger the message, the trickier it gets. Unfortunately this means it gets trickiest with signing enabled as it makes most messages very large (thus making them more sensitive to rf disturbance). Unfortunately, it is not much I can do about it from a signing perspective. Reducing the message size for signatures and nonces or adding fault tolerance to the security messages compromises security quality, and I already to that with the truncation of the signatures (due to rf24 limitations) so I don't want to "nerf" if further. So the signing solution is quite rf sensitive. But the way I see it, that just serves as a good measure for the overall quality of the rf network. If it works with shorter messages, sooner or later, maybe you add a node that transmits longer messages and start to get issues. With signing enabled, you are forced to root out any lingering rf issues immediately, and is saved from unpleasant surprises later on. But of course I understand the frustration, having experienced it myself several times. But st=fail is not a signing problem, it is a rf problem. So I am afraid I am not the best resource to provide answers. @tekka has made an excellent pull request where he has optimized the rf24 stack significantly. Perhaps applying it could help solve your rf issue: https://github.com/mysensors/Arduino/pull/392

[tomkxy]

@Anticimex I fully agree to your judgement that the problem is not due to the signing as such. However, I also do not believe in the RF24 issue. I tried with a CUSTOM child and using the max payload size available which without signing went through.

I think there might be an issue related to the changed code pathes which is caused by "injecting" signing or a define or whatsoever in my sketch is wrong after the upgrade.

I tried @tekka pull request with the result that nothing arrived at the gateway at all.

Do you know why hardware signing is not supported in the MQTTClientGateway?

[Anticimex]

@tomkxy Both hardware and software signing has no knowledge about MQTT. They only handle signatures of messages passed between gw and nodes. How the gw communicates with controller is irrelevant. Unless MQTT messes up how gw adresses nodes, I cannot see how signing could not work for MQTT. And if it does, it is a bug in MQTT implementation and not signing.

[tomkxy]

@Anticimex I did not want to suggest that it is a bug in signing, I just referred to the comment in the W5100MQTTClientGateway sketch saying "Hardware SHA204 signing is currently not supported" and was wondering whether you know why.
Sorry for bothering you on that. As I said I agree that the problem must somehow be related to transmission.

[hek]

@tomkxy said:

"Hardware SHA204 signing is currently not supported

Hmm.. must be a copy-paste error. I cannot recall any reason why it wouldn't be supported.

[Anticimex]

@tomkxy it does? That's a surprise for me. I see no reason for why it should not be supported. Perhaps the guy who did the initial implementation of it did not have atsha204 on the existing target hw, but I cannot imagine a reason for it not being supported for MQTT. Currently the only target architecture that does not support hw signing is esp I believe. At least I do not think it will work as the low level io looks different and the driver is not adapted to handle it.

[Anticimex]

It is interesting that you could get your own "big" message through, but it could be depending on how it actually look. A nonce is pure random and therefore more sensitive to noise (perhaps, I'm not an expert on rf). And I have no knowledge of MQTT at all either but if it affects signing, I probably need to read up on it. @hek perhaps know if I need to I have assumed with signing support that a gw communicates with all nodes the same way, MQTT or not.

[hek]

@Anticimex said:

I have assumed with signing support that a gw communicates with all nodes the same way, MQTT or not.

Yes, correct. The used gateway transport shouldn't affect anything.

[tomkxy]

@hek @Anticimex Ok. I switched to hardware signing. HMACs are being generated. So that is ok. When I yesterday saw the issue with the nonce and the comment in the header I switched to soft signing assuming unsupported hardware signing could have caused that.

@hek what is exactly the define

/ W5100 Ethernet module SPI enable (optional if using a shield/module that manages SPI_EN signal)
#define MY_W5100_SPI_EN 4  ```

for. I am using an Arduino Mega and I remember that with my old sketch I did not need to use Soft SPI. Is this define on a Mega necessary and if yes pin 4 correct?

[hek]

The comment says it all. If you have a W5100 module with a SPI-enable pin (not many of them have this) you don't need to enable the Soft-spi for the radio (If I remember correctly it is disabled automatically if the MY_W5100_SPI_EN is defined).

4 is the (default) pin where you should connect it to on your Arduino board. You can change this to fit your setup.

[tomkxy]

@hek Thanks!

After uploading to the Mega I receive intermittent the following error during initialization:

0;255;3;0;9;read register, reg=6, value=0
0;255;3;0;9;Sanity check failed: RF_SETUP register=0 instead of 39, check wiring, replace module or non-P version
0;255;3;0;9;Radio init failed. Check wiring.

Most of the time unplugging the Mega from power it goes away. This happens with two different modulesm one with external antenna and one without. Any idea?

[tomkxy]

@Anticimex I am still digging.... Now I figured the following:

The moment I disable MY_SIGNING_REQUEST_SIGNATURES on the sensor node while still having it on the gateway enabled sensor data is received and properly processed on gateway.

I am now a bit puzzled. Am I right assuming that if MY_SIGNING_REQUEST_SIGNATURES is enabled on gateway that sensors nodes need to sign messages to the gateway?

[Anticimex]

@tomkxy no. GW will only require signatures from nodes that require signatures. Else it would require it from every node.

[tomkxy]

@Anticimex @Hek I hacked now my sketches and tested the following scenarios:

1. sending a full payload from the sensor to the gateway in form of a nonce response
   -> it was received by the gateway and dropped -> ok
2. doing the same as above but from the gateway to a node (the node was in a _process() loop) -> transmission failure

So it seems that the sending side from the gateway to the sensor makes trouble, or the other way round receiving on the sensor node. I have not enough know regarding RF communication but this kind of asymetry seems to be strange.
Any idea what I can try or who might be able to help?

[Anticimex]

@tomkxy it is not totally strange that TX and RX performance differ. You could try to move your node around a bit and see if it is affected by location. Fiddling a bit with the transmission strength could also be a thing to try.

[tomkxy]

@Anticimex I expanded on my previous experiment. I do not require full payload. If I just transmit one byte, most of the transmissions fail.

So I need to investigate the sending node which is a Arduino Mega with an Ethernet shield...

[hek]

If you're using the 3v3 line on the mega, think again. When I tried that, I got very much transmission failures. It's crap. Use a regulator from the 5V rail.

[tomkxy]

@Anticimex @Hek thanks a lot for your support. This is very much appreciated.

I did now the following:

• solder a 4.7uf directly on the radio
• changed to the 5v power rail from the Mega, utilizing a regulator
• moved both nodes farer away

Results are much better but still not as reliable as I would need. One node acting as repeater does not get any response to its "parent" broadcasts (need to investigate this).

After some research I read that the Mega is probably not the best combination due to its current supply.
What would be a suitable alternative to the Mega (>32kb memory) which provides more reliably power?

[tomkxy]

Finally, I have everything working again. Again a big thanks to @hek and @Anticimex .

As lessons learnt, I did the following:

• Solder 4.7uf directly on the radio
• Changed to the 5v power rail from the Mega, utilizing a regulator
• Put a 100 uf between 5v and gnd on the Mega
• Moved both nodes farer away (when I was testing I had same lying side by side which obviously created interferences)
• Switched the RF24 channel utilizing a channel which was not so polluted by all the Wifis around me

[Anticimex]

Great news!

[noelgeorgi]

@tomkxy there's an android app named wifi analyser and use that to check the crowded wifi channels and set the rf24 channel to the least crowded one.... wish i had an SDR for more hacking and learning