Verify fail error after upgrading to Mysensors 2 and adding signing

[LastSamurai]

Hi,
I have a network of sensors and actors running mySensors. They were all running on MySensors Version 1.5 without problems. Today I decided to update to Version 2 (downloaded it directly from this site) and while I am at it to also add signing for security reasons.

What I did:

• Run the SecurityPersonalizer on my new gateway and creat a HMAC and serial key
• Burn the serial gateway sketch, disable the old gateway in domoticz and add the new one
• Taking all my nodes and with each: use the clearEEPROM sketch, use the securityPersonalizer sketch with my gateway HMAC key and burn the new update 2.0 sketch

These new sketches all contain:

// library settings
#define MY_RADIO_NRF24
#define MY_DEBUG    // Enables debug messages in the serial log
#define MY_DEBUG_VERBOSE_SIGNING //!< Enable signing related debug prints to serial monitor
#define MY_BAUD_RATE  9600 // Sets the serial baud rate for console and serial gateway
#define MY_SIGNING_SOFT // Enables software signing
#define MY_SIGNING_REQUEST_SIGNATURES // Always request signing from gateway
#define MY_SIGNING_SOFT_RANDOMSEED_PIN 7 // floating pin for randomness
#define MY_SIGNING_NODE_WHITELISTING {{.nodeId = GATEWAY_ADDRESS,.serial = {...}}} // gateway addres

#include <SPI.h>
#include <MyConfig.h>
#include <MySensors.h>
#include <Vcc.h>

where I inserted the actual nodeID of the gateway. The first few sensors worked without a problem.
Then I tried to add the 5th and got lots of errors like these (at the gateway):

0;255;3;0;9;TSP:MSG:READ 5-5-0 s=2,c=3,t=16,pt=0,l=0,sg=1:
0;255;3;0;9;TSP:MSG:SEND 0-0-5-5 s=255,c=3,t=17,pt=6,l=25,sg=1,ft=0,st=ok:68A3703BB316138732F15AB393198E8A977739D0377360080F
0;255;3;0;9;TSP:MSG:READ 5-5-0 s=2,c=0,t=30,pt=0,l=0,sg=1:
0;255;3;0;9;!TSP:MSG:SIGN verify fail

I ignored that one node and added others (my RGBW controllers) without a problem. Afterwards I retried the old nodes, but all senors had the same errors. One of the first sensors (that worked) had also stopped sending data, so I powercycled it and got the same kind of error on the gateway.
Any idea why this is happening, or how I can fix it? Would really love to use my sensors again

[LastSamurai]

Ok it definitly is a signing error. When I remove the signing related defines everything works just fine. Any idea how this could work on some nodes but not on others? Anything I can do to reset this or something?
It seems like all the actuators (RGBW controllers) are working just fine, while the sensors don't. Is signing always handled at the receiving side? Then perhaps something's wrong with the gateway handling the messages?

[LastSamurai]

PS I disabled the inclusion mode in my gateway sketch as I don't want to use additional buttons. Could not find much information about it. Is it only need with vera? Might that have anything to do with my problems?
Here is my gateway sketch, as it might matter for this problem:

  /**
 * 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.
 *
 *******************************
 *
 * DESCRIPTION
 * The ArduinoGateway prints data received from sensors on the serial link. 
 * The gateway accepts input on seral which will be sent out on radio network.
 *
 * The GW code is designed for Arduino Nano 328p / 16MHz
 *
 * Wire connections (OPTIONAL):
 * - Inclusion button should be connected between digital pin 3 and GND  
 * - RX/TX/ERR leds need to be connected between +5V (anode) and digital pin 6/5/4 with resistor 270-330R in a series
 *
 * LEDs (OPTIONAL):
 * - To use the feature, uncomment MY_LEDS_BLINKING_FEATURE 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 
 * 
 */

// Enable debug prints to serial monitor
#define MY_DEBUG 

#define MY_SIGNING_SOFT // Enables software signing
#define MY_SIGNING_REQUEST_SIGNATURES // Always request signing from nodes that support it
#define MY_SIGNING_SOFT_RANDOMSEED_PIN 7 // floating pin for randomness


// Enable and select radio type attached
#define MY_RADIO_NRF24
//#define MY_RADIO_RFM69

// Set LOW transmit power level as default, if you have an amplified NRF-module and
// power your radio separately with a good regulator you can turn up PA level. 
#define MY_RF24_PA_LEVEL RF24_PA_LOW

// Enable serial gateway
#define MY_GATEWAY_SERIAL

// Define a lower baud rate for Arduino's running on 8 MHz (Arduino Pro Mini 3.3V & SenseBender)
#if F_CPU == 8000000L
#define MY_BAUD_RATE 38400
#endif

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

// Inverses the behavior of leds
//#define MY_WITH_LEDS_BLINKING_INVERSE

// Enable inclusion mode
//#define MY_INCLUSION_MODE_FEATURE
// Enable Inclusion mode button on gateway
//#define MY_INCLUSION_BUTTON_FEATURE

// Inverses behavior of inclusion button (if using external pullup)
//#define MY_INCLUSION_BUTTON_EXTERNAL_PULLUP

// 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 4  // Error led pin
//#define MY_DEFAULT_RX_LED_PIN  6  // Receive led pin
//#define MY_DEFAULT_TX_LED_PIN  5  // the PCB, on board LED

#include <SPI.h>
#include <MySensors.h>  

void setup() { 
  // Setup locally attached sensors
}

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

void loop() { 
  // Send locally attached sensor data here 
}

[LastSamurai]

I kept testing today but I just can't find the error. The gateway is a arduino nano with an nrf24L01 and a capacitor on it, the node is (for this test) powered by the serial converter (so no power issue possible imo).
Here is the serial ouput of the gateway:

0;255;3;0;9;TSP:MSG:READ 7-7-255 s=255,c=3,t=7,pt=0,l=0,sg=0:
0;255;3;0;9;TSP:MSG:BC
0;255;3;0;9;TSP:MSG:FPAR REQ (sender=7)
0;255;3;0;9;TSP:CHKUPL:OK
0;255;3;0;9;TSP:MSG:GWL OK
0;255;3;0;9;Skipping security for command 3 type 8
0;255;3;0;9;TSP:MSG:SEND 0-0-7-7 s=255,c=3,t=8,pt=1,l=1,sg=0,ft=0,st=ok:0
0;255;3;0;9;TSP:MSG:READ 7-7-0 s=255,c=3,t=24,pt=1,l=1,sg=0:1
0;255;3;0;9;Skipping security for command 3 type 24
0;255;3;0;9;TSP:MSG:PINGED (ID=7, hops=1)
0;255;3;0;9;Skipping security for command 3 type 25
0;255;3;0;9;TSP:MSG:SEND 0-0-7-7 s=255,c=3,t=25,pt=1,l=1,sg=0,ft=0,st=ok:1
0;255;3;0;9;TSP:MSG:READ 7-7-0 s=255,c=3,t=15,pt=6,l=2,sg=0:0103
0;255;3;0;9;Skipping security for command 3 type 15
0;255;3;0;9;Mark node 7 as one that require signed messages
0;255;3;0;9;Mark node 7 as one that require whitelisting
0;255;3;0;9;Informing node 7 that we require signatures
0;255;3;0;9;Informing node 7 that we do not require whitelisting
0;255;3;0;9;Skipping security for command 3 type 15
0;255;3;0;9;TSP:MSG:SEND 0-0-7-7 s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=ok:0101
0;255;3;0;9;TSP:MSG:READ 7-7-0 s=255,c=3,t=16,pt=0,l=0,sg=0:
0;255;3;0;9;Skipping security for command 3 type 16
0;255;3;0;9;Signing backend: ATSHA204Soft
0;255;3;0;9;SHA256: A24DA19689737C3BEB0C86F14CB919B2D097F5E21D25221D9DAAAAAAAAAAAAAA
0;255;3;0;9;Skipping security for command 3 type 17
0;255;3;0;9;TSP:MSG:SEND 0-0-7-7 s=255,c=3,t=17,pt=6,l=25,sg=0,ft=0,st=ok:A24DA19689737C3BEB0C86F14CB919B2D097F5E21D25221D9D
0;255;3;0;9;Transmitted nonce
0;255;3;0;9;TSP:MSG:READ 7-7-0 s=255,c=0,t=17,pt=0,l=5,sg=1:2.0.0
0;255;3;0;9;Signature in message: 018B4E4C008BE642608CEB4B1C8C3494EF665BCC
0;255;3;0;9;Message to process: 07002E0011FF322E302E30
0;255;3;0;9;Current nonce: A24DA19689737C3BEB0C86F14CB919B2D097F5E21D25221D9DAAAAAAAAAAAAAA
0;255;3;0;9;HMAC: 7C1F7739216AA4DA8C9D958E9264B6F1D6DD6B1F6C982A8D4BFA454920FC9077
0;255;3;0;9;Signature bad: 011F7739216AA4DA8C9D958E9264B6F1D6DD6B1F
0;255;3;0;9;Signature verification failed!
0;255;3;0;9;!TSP:MSG:SIGN verify fail
0;255;3;0;9;TSP:MSG:READ 7-7-0 s=255,c=3,t=16,pt=0,l=0,sg=1:
0;255;3;0;9;Skipping security for command 3 type 16
0;255;3;0;9;Signing backend: ATSHA204Soft
0;255;3;0;9;SHA256: 24FB82DC1C25426EDE173B64983D76792BC70A1B1180F6A3A0AAAAAAAAAAAAAA
0;255;3;0;9;Skipping security for command 3 type 17
0;255;3;0;9;TSP:MSG:SEND 0-0-7-7 s=255,c=3,t=17,pt=6,l=25,sg=1,ft=0,st=ok:24FB82DC1C25426EDE173B64983D76792BC70A1B1180F6A3A0
0;255;3;0;9;Transmitted nonce
0;255;3;0;9;TSP:MSG:READ 7-7-0 s=255,c=3,t=6,pt=1,l=1,sg=1:0
0;255;3;0;9;Signature in message: 010BB5C49228ADC73E6DBFAF7E093916114F5B042721B30E
0;255;3;0;9;Message to process: 07000E2306FF00
0;255;3;0;9;Current nonce: 24FB82DC1C25426EDE173B64983D76792BC70A1B1180F6A3A0AAAAAAAAAAAAAA
0;255;3;0;9;HMAC: A00F640196345A62E72035E1C5762AD28873D76AF97FD063E8AC13034EC25F1F
0;255;3;0;9;Signature bad: 010F640196345A62E72035E1C5762AD28873D76AF97FD063
0;255;3;0;9;Signature verification failed!
0;255;3;0;9;!TSP:MSG:SIGN verify fail
0;255;3;0;9;TSP:MSG:READ 7-7-0 s=255,c=3,t=16,pt=0,l=0,sg=1:
0;255;3;0;9;Skipping security for command 3 type 16
0;255;3;0;9;Signing backend: ATSHA204Soft
0;255;3;0;9;SHA256: 50182401848176212805F65AB5B0AE2A0BE7F2D9A79D769523AAAAAAAAAAAAAA
0;255;3;0;9;Skipping security for command 3 type 17
0;255;3;0;9;TSP:MSG:SEND 0-0-7-7 s=255,c=3,t=17,pt=6,l=25,sg=1,ft=0,st=ok:50182401848176212805F65AB5B0AE2A0BE7F2D9A79D769523
0;255;3;0;9;Transmitted nonce
0;255;3;0;9;TSP:MSG:READ 7-7-0 s=255,c=3,t=11,pt=0,l=13,sg=1:Motion sensor
0;255;3;0;9;Signature in message: 0191403E21610DD5608BE01F
0;255;3;0;9;Message to process: 07006E030BFF4D6F74696F6E2073656E736F72
0;255;3;0;9;Current nonce: 50182401848176212805F65AB5B0AE2A0BE7F2D9A79D769523AAAAAAAAAAAAAA
0;255;3;0;9;HMAC: 15A978C98890CE4CBE86F67F5F4057E147F3988B0FFCE9BFC241062D90F31B99
0;255;3;0;9;Signature bad: 01A978C98890CE4CBE86F67F
0;255;3;0;9;Signature verification failed!
0;255;3;0;9;!TSP:MSG:SIGN verify fail
0;255;3;0;9;TSP:MSG:READ 7-7-0 s=255,c=3,t=16,pt=0,l=0,sg=1:
0;255;3;0;9;Skipping security for command 3 type 16
0;255;3;0;9;Signing backend: ATSHA204Soft
0;255;3;0;9;SHA256: 8D78F206161D498D2AF533E36466D79A80A16BE3680641DB2CAAAAAAAAAAAAAA
0;255;3;0;9;Skipping security for command 3 type 17
0;255;3;0;9;TSP:MSG:SEND 0-0-7-7 s=255,c=3,t=17,pt=6,l=25,sg=1,ft=0,st=ok:8D78F206161D498D2AF533E36466D79A80A16BE3680641DB2C
0;255;3;0;9;Transmitted nonce
0;255;3;0;9;TSP:MSG:READ 7-7-0 s=255,c=3,t=12,pt=0,l=13,sg=1:12112016 v2.0
0;255;3;0;9;Signature in message: 01148CFE3055E715CDF55847
0;255;3;0;9;Message to process: 07006E030CFF31323131323031362076322E30
0;255;3;0;9;Current nonce: 8D78F206161D498D2AF533E36466D79A80A16BE3680641DB2CAAAAAAAAAAAAAA
0;255;3;0;9;HMAC: AA3E80AB8CDA7A9EFEA69EED6AF28228FF716420D2DCB66768BEC5FE115F3AC7
0;255;3;0;9;Signature bad: 013E80AB8CDA7A9EFEA69EED
0;255;3;0;9;Signature verification failed!
0;255;3;0;9;!TSP:MSG:SIGN verify fail
0;255;3;0;9;TSP:MSG:READ 7-7-0 s=1,c=3,t=16,pt=0,l=0,sg=1:
0;255;3;0;9;Skipping security for command 3 type 16
0;255;3;0;9;Signing backend: ATSHA204Soft
0;255;3;0;9;SHA256: CE09F3DE8966D3C382539CD7BFB9CBC454FD31F19C196D5406AAAAAAAAAAAAAA
0;255;3;0;9;Skipping security for command 3 type 17
0;255;3;0;9;TSP:MSG:SEND 0-0-7-7 s=255,c=3,t=17,pt=6,l=25,sg=1,ft=0,st=ok:CE09F3DE8966D3C382539CD7BFB9CBC454FD31F19C196D5406
0;255;3;0;9;Transmitted nonce
0;255;3;0;9;TSP:MSG:READ 7-7-0 s=1,c=0,t=1,pt=0,l=0,sg=1:
0;255;3;0;9;Signature in message: 017F6CCB22459F1A4FF3AF6FD4E3F6C70EB0C91F5892FC29F8
0;255;3;0;9;Message to process: 070006000101
0;255;3;0;9;Current nonce: CE09F3DE8966D3C382539CD7BFB9CBC454FD31F19C196D5406AAAAAAAAAAAAAA
0;255;3;0;9;HMAC: 5F3E6394EFCEE3398BB752B3D456973AEC8076DDCC0C2F93CBB3BD6D7AF18730
0;255;3;0;9;Signature bad: 013E6394EFCEE3398BB752B3D456973AEC8076DDCC0C2F93CB
0;255;3;0;9;Signature verification failed!
0;255;3;0;9;!TSP:MSG:SIGN verify fail
0;255;3;0;9;TSP:MSG:READ 7-7-0 s=2,c=3,t=16,pt=0,l=0,sg=1:
0;255;3;0;9;Skipping security for command 3 type 16
0;255;3;0;9;Signing backend: ATSHA204Soft
0;255;3;0;9;SHA256: 1482709C4C43D1B2D5EAB889D4C1B05855F2974C0D3936DB92AAAAAAAAAAAAAA
0;255;3;0;9;Skipping security for command 3 type 17
0;255;3;0;9;TSP:MSG:SEND 0-0-7-7 s=255,c=3,t=17,pt=6,l=25,sg=1,ft=0,st=ok:1482709C4C43D1B2D5EAB889D4C1B05855F2974C0D3936DB92
0;255;3;0;9;Transmitted nonce
0;255;3;0;9;TSP:MSG:READ 7-7-0 s=2,c=0,t=30,pt=0,l=0,sg=1:
0;255;3;0;9;Signature in message: 01C37C0B8887E960E35140CD12267CB8ABA90164FEA684B599
0;255;3;0;9;Message to process: 070006001E02
0;255;3;0;9;Current nonce: 1482709C4C43D1B2D5EAB889D4C1B05855F2974C0D3936DB92AAAAAAAAAAAAAA
0;255;3;0;9;HMAC: 3ABC9EB0D19771DAA10E8F1889474FACE548BD967F3C3004839DD6F2C1934DD4
0;255;3;0;9;Signature bad: 01BC9EB0D19771DAA10E8F1889474FACE548BD967F3C300483
0;255;3;0;9;Signature verification failed!
0;255;3;0;9;!TSP:MSG:SIGN verify fail
0;255;3;0;9;TSP:MSG:READ 7-7-0 s=255,c=3,t=26,pt=1,l=1,sg=1:2
0;255;3;0;9;Skipping security for command 3 type 26
0;255;3;0;9;Skipping security for command 3 type 16
0;255;3;0;9;TSP:MSG:SEND 0-0-7-7 s=255,c=3,t=16,pt=0,l=0,sg=0,ft=0,st=ok:
0;255;3;0;9;Nonce requested from 7. Waiting...
0;255;3;0;9;TSP:MSG:READ 7-7-0 s=255,c=3,t=17,pt=6,l=25,sg=0:A19E9E4EFAE96827060ED83040AFB633A815E8495870624195
0;255;3;0;9;Skipping security for command 3 type 17
0;255;3;0;9;Nonce received from 7. Proceeding with signing...
0;255;3;0;9;Signing backend: ATSHA204Soft
0;255;3;0;9;Message to process: 00070E231BFF01
0;255;3;0;9;Current nonce: A19E9E4EFAE96827060ED83040AFB633A815E8495870624195AAAAAAAAAAAAAA
0;255;3;0;9;HMAC: 44A849FE35EB552B8FFFD210C031D7AC71DDA7FADF3C3AF265E38622D95A7FAD
0;255;3;0;9;SHA256: 58A4287A1B99DCFD03CD9A078A76376A15B479969CD55A1613872AB725083D5D
0;255;3;0;9;Signature salted with serial
0;255;3;0;9;Signature in message: 01A4287A1B99DCFD03CD9A078A76376A15B479969CD55A16
0;255;3;0;9;Message signed
0;255;3;0;9;Message to send has been signed
0;255;3;0;9;TSP:MSG:SEND 0-0-7-7 s=255,c=3,t=27,pt=1,l=1,sg=1,ft=0,st=ok:1
0;255;3;0;9;TSP:MSG:READ 7-7-0 s=255,c=3,t=17,pt=6,l=25,sg=0:0FB33D407719A2C3348B03F4F48F75C4B66E87A1F3653C4B54
0;255;3;0;9;Skipping security for command 3 type 17
0;255;3;0;9;Nonce received from 7. Proceeding with signing...
0;255;3;0;9;Signing backend: ATSHA204Soft
0;255;3;0;9;Message to process: 00070E231BFF01
0;255;3;0;9;Current nonce: 0FB33D407719A2C3348B03F4F48F75C4B66E87A1F3653C4B54AAAAAAAAAAAAAA
0;255;3;0;9;HMAC: 13FA6937C47252E91AA34C890876EC63D8AD43B7C2D9B54C311F0AA857C406C9
0;255;3;0;9;SHA256: D4F2ADFA1593EFF8101C899A864B7C4DD66057008CDA67AFAD1D9AAD42BE0903
0;255;3;0;9;Signature salted with serial
0;255;3;0;9;Signature in message: 01F2ADFA1593EFF8101C899A864B7C4DD66057008CDA67AF
0;255;3;0;9;Message signed
0;255;3;0;9;TSP:MSG:READ 7-7-0 s=255,c=3,t=16,pt=0,l=0,sg=1:
0;255;3;0;9;Skipping security for command 3 type 16
0;255;3;0;9;Signing backend: ATSHA204Soft
0;255;3;0;9;SHA256: C8E53D63D375EBE487B762FDAE850098F72DD6E1050D3EACEEAAAAAAAAAAAAAA
0;255;3;0;9;Skipping security for command 3 type 17
0;255;3;0;9;TSP:MSG:SEND 0-0-7-7 s=255,c=3,t=17,pt=6,l=25,sg=1,ft=0,st=ok:C8E53D63D375EBE487B762FDAE850098F72DD6E1050D3EACEE
0;255;3;0;9;Transmitted nonce
0;255;3;0;9;TSP:MSG:READ 7-7-0 s=255,c=3,t=0,pt=1,l=1,sg=1:100
0;255;3;0;9;Signature in message: 012656DE91852D936FD6A867EC4FEE7F4BA051C7E83714BF
0;255;3;0;9;Message to process: 07000E2300FF64
0;255;3;0;9;Current nonce: C8E53D63D375EBE487B762FDAE850098F72DD6E1050D3EACEEAAAAAAAAAAAAAA
0;255;3;0;9;HMAC: 07D2EF5EC009F774823072B3AB000347EF632A81AFF5ED827D0BD8E010DE96D1
0;255;3;0;9;Signature bad: 01D2EF5EC009F774823072B3AB000347EF632A81AFF5ED82
0;255;3;0;9;Signature verification failed!
0;255;3;0;9;!TSP:MSG:SIGN verify fail
0;255;3;0;9;TSP:MSG:READ 7-7-0 s=2,c=3,t=16,pt=0,l=0,sg=1:
0;255;3;0;9;Skipping security for command 3 type 16
0;255;3;0;9;Signing backend: ATSHA204Soft
0;255;3;0;9;SHA256: C8BF8D96E21999985B9B7FC6B6C6553C7B2BAAECD53A2701C1AAAAAAAAAAAAAA
0;255;3;0;9;Skipping security for command 3 type 17
0;255;3;0;9;TSP:MSG:SEND 0-0-7-7 s=255,c=3,t=17,pt=6,l=25,sg=1,ft=0,st=ok:C8BF8D96E21999985B9B7FC6B6C6553C7B2BAAECD53A2701C1
0;255;3;0;9;Transmitted nonce
0;255;3;0;9;TSP:MSG:READ 7-7-0 s=2,c=1,t=38,pt=7,l=5,sg=1:4.893
0;255;3;0;9;Signature in message: 01555853CF5D5DFB36F8755EFF6134CC52704850
0;255;3;0;9;Message to process: 07002EE1260241909C4003
0;255;3;0;9;Current nonce: C8BF8D96E21999985B9B7FC6B6C6553C7B2BAAECD53A2701C1AAAAAAAAAAAAAA
0;255;3;0;9;HMAC: 349777583766820BC0A8D034BE7E1EC6E1FD49AB7FB61FE400079CAB9999662E
0;255;3;0;9;Signature bad: 019777583766820BC0A8D034BE7E1EC6E1FD49AB
0;255;3;0;9;Signature verification failed!
0;255;3;0;9;!TSP:MSG:SIGN verify fail
0;255;3;0;9;TSP:SANCHK:OK
0;255;3;0;9;TSP:SANCHK:OK

And here from the node:

Starting sensor (RNNNAS, 2.0.0)
TSM:INIT
TSM:RADIO:OK
TSP:ASSIGNID:OK (ID=7)
TSM:FPAR
TSP:MSG:SEND 7-7-255-255 s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=bc:
TSM:FPAR
TSP:MSG:SEND 7-7-255-255 s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=bc:
TSP:MSG:READ 0-0-7 s=255,c=3,t=8,pt=1,l=1,sg=0:0
Skipping security for command 3 type 8
TSP:MSG:FPAR RES (ID=0, dist=0)
TSP:MSG:PAR OK (ID=0, dist=1)
TSM:FPAR:OK
TSM:ID
TSM:CHKID:OK (ID=7)
TSM:UPL
TSP:PING:SEND (dest=0)
Skipping security for command 3 type 24
TSP:MSG:SEND 7-7-0-0 s=255,c=3,t=24,pt=1,l=1,sg=0,ft=0,st=ok:1
TSP:MSG:READ 0-0-7 s=255,c=3,t=25,pt=1,l=1,sg=0:1
Skipping security for command 3 type 25
TSP:MSG:PONG RECV (hops=1)
TSP:CHKUPL:OK
TSM:UPL:OK
TSM:READY
Signing required
Whitelisting required
Skipping security for command 3 type 15
TSP:MSG:SEND 7-7-0-0 s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=ok:0103
Waiting for GW to send signing preferences...
TSP:MSG:READ 0-0-7 s=255,c=3,t=15,pt=6,l=2,sg=0:0101
Skipping security for command 3 type 15
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
TSP:MSG:SEND 7-7-0-0 s=255,c=3,t=16,pt=0,l=0,sg=0,ft=0,st=ok:
Nonce requested from 0. Waiting...
TSP:MSG:READ 0-0-7 s=255,c=3,t=17,pt=6,l=25,sg=0:A24DA19689737C3BEB0C86F14CB919B2D097F5E21D25221D9D
Skipping security for command 3 type 17
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204Soft
Message to process: 07002E0011FF322E302E30
Current nonce: A24DA19689737C3BEB0C86F14CB919B2D097F5E21D25221D9DAAAAAAAAAAAAAA
HMAC: ED8B4E4C008BE642608CEB4B1C8C3494EF665BCCC8E8F637408D8FDF1A462BD5
Signature in message: 018B4E4C008BE642608CEB4B1C8C3494EF665BCC
Message signed
Message to send has been signed
TSP:MSG:SEND 7-7-0-0 s=255,c=0,t=17,pt=0,l=5,sg=1,ft=0,st=ok:2.0.0
Skipping security for command 3 type 16
TSP:MSG:SEND 7-7-0-0 s=255,c=3,t=16,pt=0,l=0,sg=1,ft=0,st=ok:
Nonce requested from 0. Waiting...
TSP:MSG:READ 0-0-7 s=255,c=3,t=17,pt=6,l=25,sg=1:24FB82DC1C25426EDE173B64983D76792BC70A1B1180F6A3A0
Skipping security for command 3 type 17
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204Soft
Message to process: 07000E2306FF00
Current nonce: 24FB82DC1C25426EDE173B64983D76792BC70A1B1180F6A3A0AAAAAAAAAAAAAA
HMAC: A10BB5C49228ADC73E6DBFAF7E093916114F5B042721B30E3777795031D96B7C
Signature in message: 010BB5C49228ADC73E6DBFAF7E093916114F5B042721B30E
Message signed
Message to send has been signed
TSP:MSG:SEND 7-7-0-0 s=255,c=3,t=6,pt=1,l=1,sg=1,ft=0,st=ok:0
Skipping security for command 3 type 16
TSP:MSG:SEND 7-7-0-0 s=255,c=3,t=16,pt=0,l=0,sg=1,ft=0,st=ok:
Nonce requested from 0. Waiting...
TSP:MSG:READ 0-0-7 s=255,c=3,t=17,pt=6,l=25,sg=1:50182401848176212805F65AB5B0AE2A0BE7F2D9A79D769523
Skipping security for command 3 type 17
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204Soft
Message to process: 07006E030BFF4D6F74696F6E2073656E736F72
Current nonce: 50182401848176212805F65AB5B0AE2A0BE7F2D9A79D769523AAAAAAAAAAAAAA
HMAC: 1D91403E21610DD5608BE01FCB0562FC4E46DEAA27C41F2811E440512C233E78
Signature in message: 0191403E21610DD5608BE01F
Message signed
Message to send has been signed
TSP:MSG:SEND 7-7-0-0 s=255,c=3,t=11,pt=0,l=13,sg=1,ft=0,st=ok:Motion sensor
Skipping security for command 3 type 16
TSP:MSG:SEND 7-7-0-0 s=255,c=3,t=16,pt=0,l=0,sg=1,ft=0,st=ok:
Nonce requested from 0. Waiting...
TSP:MSG:READ 0-0-7 s=255,c=3,t=17,pt=6,l=25,sg=1:8D78F206161D498D2AF533E36466D79A80A16BE3680641DB2C
Skipping security for command 3 type 17
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204Soft
Message to process: 07006E030CFF31323131323031362076322E30
Current nonce: 8D78F206161D498D2AF533E36466D79A80A16BE3680641DB2CAAAAAAAAAAAAAA
HMAC: E4148CFE3055E715CDF55847EEB56C648691D320C49603982E0F1F0ADD69F8A2
Signature in message: 01148CFE3055E715CDF55847
Message signed
Message to send has been signed
TSP:MSG:SEND 7-7-0-0 s=255,c=3,t=12,pt=0,l=13,sg=1,ft=0,st=ok:12112016 v2.0
Skipping security for command 3 type 16
TSP:MSG:SEND 7-7-0-0 s=1,c=3,t=16,pt=0,l=0,sg=1,ft=0,st=ok:
Nonce requested from 0. Waiting...
TSP:MSG:READ 0-0-7 s=255,c=3,t=17,pt=6,l=25,sg=1:CE09F3DE8966D3C382539CD7BFB9CBC454FD31F19C196D5406
Skipping security for command 3 type 17
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204Soft
Message to process: 070006000101
Current nonce: CE09F3DE8966D3C382539CD7BFB9CBC454FD31F19C196D5406AAAAAAAAAAAAAA
HMAC: C17F6CCB22459F1A4FF3AF6FD4E3F6C70EB0C91F5892FC29F8BB379BD4A23474
Signature in message: 017F6CCB22459F1A4FF3AF6FD4E3F6C70EB0C91F5892FC29F8
Message signed
Message to send has been signed
TSP:MSG:SEND 7-7-0-0 s=1,c=0,t=1,pt=0,l=0,sg=1,ft=0,st=ok:
Skipping security for command 3 type 16
TSP:MSG:SEND 7-7-0-0 s=2,c=3,t=16,pt=0,l=0,sg=1,ft=0,st=ok:
Nonce requested from 0. Waiting...
TSP:MSG:READ 0-0-7 s=255,c=3,t=17,pt=6,l=25,sg=1:1482709C4C43D1B2D5EAB889D4C1B05855F2974C0D3936DB92
Skipping security for command 3 type 17
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204Soft
Message to process: 070006001E02
Current nonce: 1482709C4C43D1B2D5EAB889D4C1B05855F2974C0D3936DB92AAAAAAAAAAAAAA
HMAC: 8FC37C0B8887E960E35140CD12267CB8ABA90164FEA684B599FF267906A8A678
Signature in message: 01C37C0B8887E960E35140CD12267CB8ABA90164FEA684B599
Message signed
Message to send has been signed
TSP:MSG:SEND 7-7-0-0 s=2,c=0,t=30,pt=0,l=0,sg=1,ft=0,st=ok:
Request registration...
Skipping security for command 3 type 26
TSP:MSG:SEND 7-7-0-0 s=255,c=3,t=26,pt=1,l=1,sg=1,ft=0,st=ok:2
TSP:MSG:READ 0-0-7 s=255,c=3,t=16,pt=0,l=0,sg=0:
Skipping security for command 3 type 16
Signing backend: ATSHA204Soft
SHA256: 0FB33D407719A2C3348B03F4F48F75C4B66E87A1F3653C4B5400000000000000
Skipping security for command 3 type 17
TSP:MSG:SEND 7-7-0-0 s=255,c=3,t=17,pt=6,l=25,sg=0,ft=0,st=ok:0FB33D407719A2C3348B03F4F48F75C4B66E87A1F3653C4B54
Transmitted nonce
TSP:MSG:READ 0-0-7 s=255,c=3,t=27,pt=1,l=1,sg=1:1
Signature in message: 01A4287A1B99DCFD03CD9A078A76376A15B479969CD55A16
Message to process: 00070E231BFF01
Current nonce: 0FB33D407719A2C3348B03F4F48F75C4B66E87A1F3653C4B54AAAAAAAAAAAAAA
HMAC: 9DEC3241185CCF49FC1FCA484C94224F1AF5EA45048A50F140FFC1A10C40C068
Sender found in whitelist
SHA256: C6E69F64F0F7706724FDBADEF7D8D861404F4ACBDBC84655EFD14AC509D0A964
Signature bad: 01E69F64F0F7706724FDBADEF7D8D861404F4ACBDBC84655
Is the sender whitelisted and serial correct?
Signature verification failed!
!TSP:MSG:SIGN verify fail
Init complete, id=7, parent=0, distance=1, registration=1
Skipping security for command 3 type 16
TSP:MSG:SEND 7-7-0-0 s=255,c=3,t=16,pt=0,l=0,sg=1,ft=0,st=ok:
Nonce requested from 0. Waiting...
TSP:MSG:READ 0-0-7 s=255,c=3,t=17,pt=6,l=25,sg=1:C8E53D63D375EBE487B762FDAE850098F72DD6E1050D3EACEE
Skipping security for command 3 type 17
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204Soft
Message to process: 07000E2300FF64
Current nonce: C8E53D63D375EBE487B762FDAE850098F72DD6E1050D3EACEEAAAAAAAAAAAAAA
HMAC: AA2656DE91852D936FD6A867EC4FEE7F4BA051C7E83714BFF592127FCD68EDAD
Signature in message: 012656DE91852D936FD6A867EC4FEE7F4BA051C7E83714BF
Message signed
Message to send has been signed
TSP:MSG:SEND 7-7-0-0 s=255,c=3,t=0,pt=1,l=1,sg=1,ft=0,st=ok:100
Skipping security for command 3 type 16
TSP:MSG:SEND 7-7-0-0 s=2,c=3,t=16,pt=0,l=0,sg=1,ft=0,st=ok:
Nonce requested from 0. Waiting...
TSP:MSG:READ 0-0-7 s=255,c=3,t=17,pt=6,l=25,sg=1:C8BF8D96E21999985B9B7FC6B6C6553C7B2BAAECD53A2701C1
Skipping security for command 3 type 17
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204Soft
Message to process: 07002EE1260241909C4003
Current nonce: C8BF8D96E21999985B9B7FC6B6C6553C7B2BAAECD53A2701C1AAAAAAAAAAAAAA
HMAC: B3555853CF5D5DFB36F8755EFF6134CC527048508A8CDB66205F4DCA8F8B8C9A
Signature in message: 01555853CF5D5DFB36F8755EFF6134CC52704850
Message signed
Message to send has been signed
TSP:MSG:SEND 7-7-0-0 s=2,c=1,t=38,pt=7,l=5,sg=1,ft=0,st=ok:4.893

Only interesting error I found is "Is the sender whitelisted and serial correct?" and that one only once. The node contains that define:

#define MY_SIGNING_NODE_WHITELISTING {{.nodeId = GATEWAY_ADDRESS,.serial = {0x5B,0x96,0x29,0xDD,0x0F,0x80,0x80,0xC5,0x1B}}} // gateway address

which I copy and pasted from the initial setup with the personalizer sketch at the gateway.
Would be really great if someone could help me with this problem

[Anticimex]

What happens if you skip using whitelisting?

[Anticimex]

Another thing to test is to see if your EEPROM has been corrupted/overwritten. You can configure the SecurityPersonalizer to not write/update any keys (disable the STORE-defines) and see what the stored data is (if for instance the HMAC key was somehow altered).
From what I can see the nonces and signatures are exchanged correctly, and that leaves only the HMAC key and whitelisting operations as "unknowns". Whitelisting problems usually mean an incorrect serial used at the sender side compared to what the receiver has in it's list. You see the message when a node identifies the sender as one present in it's whitelist and the node is configure to have a whitelist.
In your logs above, the GW (which is in your nodes whitelist) only sends one signed message to the node, and this show on the sender (GW) side as:
0;255;3;0;9;Signature salted with serial
and at the receiver (node) as:
Sender found in whitelist

To me, it looks a lot like your HMAC has somehow been altered. Do you write to EEPROM in your sketches?

[LastSamurai]

Thanks @Anticimex

Skipping whitelisting changes nothing. None of my nodes write to EEPROM.
So I guess the HMAC is somehow wrong. I did not check it as my nodes haven't had the headers soldered on for serial connections, I program them directly via USBasp. I did just add the headers for one node but only got gibberish on the console. I'll try to check again tomorrow.

[Anticimex]

@LastSamurai ok, eeprom corruption or overwrite is the only plausible explanation I have from looking at your logs. Everything is the same between sender and receiver except the resulting hmac (signature) and the only part involved at that stage is the hmac key. And Judy one bit wrong will result in a completely different signature. In 2.0.0 version of the library, more data is used u the library in eeprom so if there is code that writes to eeprom which does not take into account the area reserved by the library it might inadvertently overwrite parts of eeprom used by the library. The soft serial and hmac keys are part of this. You could also try to just dump the eeprom using your programmer to verify that it contain the secrets you specified with the personalizer.

[LastSamurai]

@Anticimex I think you are right. I did upload the securityPersonalizer sketch but I guess it did not write anything. I just downloaded the EEPROM via AVRDUDESS and only got a whole bunch of 0xff's. Although I am not 100% sure if I did it right
My nodes have different fuse settings (running at 8MHz internal only and 1.8V brown out). 115200 serial doesn't seem to work reliably at that speed, so I normally changed the serial speed to 9600. Can there be any problem with that and the securityPersonalizer sketch? Can I just use a

#define MY_BAUD_RATE  9600

at the top of the sketch? Because when I tried it earlier I only got nonsense on the console. Ill try it again tomorrow though, perhaps I missed something.

[Anticimex]

@LastSamurai hm, I don't know to be honest. I have never tried to alter serial speed for the personalizer.

[LastSamurai]

I did just try it with another node and signing worked there without a problem. Even with the different serial speeds.
I noticed with that node that I did set the HMAC key, but not serial key for the node itselft (which then results in FFFFF.... I think). Might this cause the problems I mentioned? Might be some kind of bug (although one should really create a serial number for the nodes ; ) ).

[Anticimex]

@LastSamurai serial number is only used for whitelisting. If you use soft signing you need to configure the personalizer to store it and it should be unique for every sensor board. If any node (or gateway) require whitelisting, your node will use the serial as salt for the signature and the receiver will look up the serial in its local whitelist if it finds a match for the node ID of your node and do the responding salting to verify the signature.
I'm other words, if you use whitelisting, you have to match the whitelists with the serials of the nodes that communicate.
The signing documentation describes how to do this.

From your logs, however, I would say it is a hmac mismatch. The verbose debug will show if serials could have been the problem. Typically by asking if the sender is in the whitelist.