Signing: no active verification session?

tomkxy

I have a node who is supposed to work as an irrigation controller running on batteries. Every 10 minutes it wakes up and sends a time request to the GW which is routed through to my controller. The nodes stays awake for some seconds.
Whenever the controller sees a time request from that node it will send the actual time and any required status changes to the actuator. I switch on now signatures which I have for all my nodes.

For the time request I see the following output, no active verification session and verify fail.

Skipping security for command 3 type 17
read: 0-0-32 s=255,c=3,t=17,pt=6,l=25,sg=0:250CBDC35C4580E545FD62FF251E4965AC05F25190E60179D4
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 2000060301FF
Current nonce: 250CBDC35C4580E545FD62FF251E4965AC05F25190E60179D4AAAAAAAAAAAAAA
HMAC: 036B39C46890F5068DE6FECE4D80612DD0BEA3710BA8B08E635B49AC34BF43A4
Signature in message: 016B39C46890F5068DE6FECE4D80612DD0BEA3710BA8B08E63
Message signed
Message to send has been signed
send: 32-32-0-0 s=255,c=3,t=1,pt=0,l=0,sg=1,st=ok:
Requesting time from Gateway:
No active verification session
Signature verification failed!
verify fail

What does no active verification session mean?

tomkxy

I investigated a bit further and somehow I think it is really strange.
Below are excerpts from the sketch

void receiveTime(time_t newTime)
{
  DEBUG_PRINTLN(F("Time value received and updated..."));
  setTime(newTime);
  RTC.set(newTime);
  DEBUG_PRINT(F("Time set to: "));
  printTime(now());  
  timeReceived = true;
}

void loop() {
    .....

     Serial.println(F("------------- Start request time ------------"));
      requestTime();
      wait(LISTEN_TIME);
     Serial.println(F("------------- End request time ------------"));

...
}

Corresponding log

------------- Start request time ------------
Skipping security for command 3 type 16
send: 32-32-0-0 s=255,c=3,t=16,pt=0,l=0,sg=0,st=ok:
Nonce requested from 0. Waiting...
Skipping security for ACK on command 1 type 2
read: 0-0-32 s=0,c=1,t=2,pt=2,l=2,sg=0:1
Skipping security for command 3 type 17
read: 0-0-32 s=255,c=3,t=17,pt=6,l=25,sg=0:B49BE88B3491B3BAFB7766016E5EB7F64517EBC26A46DE39D2
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 2000060301FF
Current nonce: B49BE88B3491B3BAFB7766016E5EB7F64517EBC26A46DE39D2AAAAAAAAAAAAAA
HMAC: 009218BA7BE0554C08B5E1A1C12CC48696C69C4875F538271D07A8236668C3B1
Signature in message: 019218BA7BE0554C08B5E1A1C12CC48696C69C4875F538271D
Message signed
Message to send has been signed
send: 32-32-0-0 s=255,c=3,t=1,pt=0,l=0,sg=1,st=ok:
Skipping security for command 3 type 16
read: 0-0-32 s=255,c=3,t=16,pt=0,l=0,sg=0:
Signing backend: ATSHA204
SHA256: 434C82D79B6968444017921515AF3ECD0713FAEDD028C7134A2D8504A37477E2
Transmittng nonce
Skipping security for command 3 type 17
send: 32-32-0-0 s=255,c=3,t=17,pt=6,l=25,sg=0,st=ok:434C82D79B6968444017921515AF3ECD0713FAEDD028C7134A
Skipping security for command 3 type 16
read: 0-0-32 s=0,c=3,t=16,pt=0,l=0,sg=0:
Signing backend: ATSHA204
SHA256: 7A1D8F10E0768C3F3D2856ADC86EEE086285312C3532300104A2D81F79D6A20F
Transmittng nonce
Skipping security for command 3 type 17
send: 32-32-0-0 s=255,c=3,t=17,pt=6,l=25,sg=0,st=ok:7A1D8F10E0768C3F3D2856ADC86EEE086285312C3532300104
Signature in message: 0109B52E8590A8DA9BFEFC7C3C6A29BF7C0EF8B6D1E686DB
Message to process: 00200E01020030
Current nonce: 7A1D8F10E0768C3F3D2856ADC86EEE086285312C3532300104AAAAAAAAAAAAAA
HMAC: 73C7B30C578D19518A4244D729B8D0554885B354413DAF41ABE16AEAE535021A
Signature bad: 01C7B30C578D19518A4244D729B8D0554885B354413DAF41
Signature verification failed!
verify fail
No active verification session
Signature verification failed!
verify fail
------------- End request time ------------

At the beginning of the loop I have a transmission of a status to the controller which arrives at my controller and is processed there correctly. So it is not an issue with the key. Also transmissions as such seems to ok. I see no fails.

What is puzzling me are the skipping security log outputs in combination with asking for the nonce anyway.

I already looked into the MySensors code and set the MY_VERIFICATION_TIMEOUT_MS to 60000 which should is more than enough.

@Anticimex May be you can have a look?

tomkxy

I am able now to reproduce it with a stripped down sketch. Corresponding log below.
I have to admit I am still on a mid march version of the development branch.

/**
 * 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 - Thomas Bowman Mørch
 * 
 * DESCRIPTION
 * Default sensor sketch for Sensebender Micro module
 * Act as a temperature / humidity sensor by default.
 *
 * If A0 is held low while powering on, it will enter testmode, which verifies all on-board peripherals
 *  
 * Battery voltage is as battery percentage (Internal message), and optionally as a sensor value (See defines below)
 *
 *
 * Version 1.3 - Thomas Bowman Mørch
 * Improved transmission logic, eliminating spurious transmissions (when temperatuere / humidity fluctuates 1 up and down between measurements) 
 * Added OTA boot mode, need to hold A1 low while applying power. (uses slightly more power as it's waiting for bootloader messages)
 * 
 * Version 1.4 - Thomas Bowman Mørch
 * 
 * Corrected division in the code deciding whether to transmit or not, that resulted in generating an integer. Now it's generating floats as expected.
 * Simplified detection for OTA bootloader, now detecting if MY_OTA_FIRMWARE_FEATURE is defined. If this is defined sensebender automaticly waits 300mS after each transmission
 * Moved Battery status messages, so they are transmitted together with normal sensor updates (but only every 60th minute)
 * 
 */
 
#define MY_DEBUG_VERBOSE_SIGNING
// Enable debug prints to serial monitor
#define MY_DEBUG 
//#define MY_DEBUG_VERBOSE_RF24
 
#define MY_SIGNING_FEATURE
#define MY_SIGNING_ATSHA204
//#define MY_SIGNING_SOFT
#define MY_SIGNING_ATSHA204_PIN A3
#define MY_SIGNING_REQUEST_SIGNATURES
#define MY_VERIFICATION_TIMEOUT_MS 3000

// Enable debug prints to serial monitor
#define MY_DEBUG 

// Define a static node address, remove if you want auto address assignment
#define MY_NODE_ID 32

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

// Enable to support OTA for this node (needs DualOptiBoot boot-loader to fully work)
//#define MY_OTA_FIRMWARE_FEATURE

#include <SPI.h>
#include <MySensor.h>
#include <Wire.h>
#include <Time.h> 
#ifndef MY_OTA_FIRMWARE_FEATURE
#include "drivers/SPIFlash/SPIFlash.cpp"
#endif
#include <EEPROM.h>  
#include <sha204_lib_return_codes.h>
#include <sha204_library.h>

bool           timeReceived = false;

void receiveTime(time_t newTime)
{
  Serial.println(F("Time value received and updated..."));
}


/****************************************************
 *
 * Setup code 
 *
 ****************************************************/
void setup() {
  
  Serial.begin(115200);
}



void presentation()  {
  sendSketchInfo("Sensebender Micro", "1.5");
  present(0, S_SPRINKLER);
}


/***********************************************
 *
 *  Main loop function
 *
 ***********************************************/
void loop() {
   timeReceived = false;
   int cnt = 0;
   while ( (cnt++ < 3) && (!timeReceived)) {
     Serial.println(F("------------- Start request time ------------"));
      requestTime();
      wait(30000);
      Serial.println(F("------------- End request time ------------"));
    }     
  sleep(5000);
}

Starting sensor (RNNNAA, 2.0.0-beta)
Radio init successful.
Signing required
Skipping security for command 3 type 15
send: 32-32-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-32 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: 32-32-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-32 s=255,c=3,t=17,pt=6,l=25,sg=0:C93DE1DDE5B0920941AEC959B56806F9DB5760CE28378D850D
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 2000560011FF322E302E302D62657461
Current nonce: C93DE1DDE5B0920941AEC959B56806F9DB5760CE28378D850DAAAAAAAAAAAAAA
HMAC: 52CD5A75EBB5ACE46978B44CB11C071777918812FB85AFECB5EBC5783EF42AF3
Signature in message: 01CD5A75EBB5ACE46978B44CB11C07
Message signed
Message to send has been signed
send: 32-32-0-0 s=255,c=0,t=17,pt=0,l=10,sg=1,st=ok:2.0.0-beta
Skipping security for command 3 type 16
send: 32-32-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-32 s=255,c=3,t=17,pt=6,l=25,sg=0:D390179DFC9905FBA5C73E059DCF77C61BE6A4E4AD35007F25
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 20000E2306FF00
Current nonce: D390179DFC9905FBA5C73E059DCF77C61BE6A4E4AD35007F25AAAAAAAAAAAAAA
HMAC: C6378D8AC74E7958BACAF95DF52E6F1BCE4D5314CFB6B90A657005CC6BB08151
Signature in message: 01378D8AC74E7958BACAF95DF52E6F1BCE4D5314CFB6B90A
Message signed
Message to send has been signed
send: 32-32-0-0 s=255,c=3,t=6,pt=1,l=1,sg=1,st=ok:0
Skipping security for command 3 type 16
send: 32-32-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-32 s=255,c=3,t=17,pt=6,l=25,sg=0:A8A2545D212BD482C0594E7B920E3038D52F5DD1FCB58BCDCB
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 20008E030BFF53656E736562656E646572204D6963726F
Current nonce: A8A2545D212BD482C0594E7B920E3038D52F5DD1FCB58BCDCBAAAAAAAAAAAAAA
HMAC: 83AD73B79B57D6595E7A090CA9DBDA2AFE0A97458A55AD30690680918D6791CE
Signature in message: 01AD73B79B57D659
Message signed
Message to send has been signed
send: 32-32-0-0 s=255,c=3,t=11,pt=0,l=17,sg=1,st=ok:Sensebender Micro
Skipping security for command 3 type 16
send: 32-32-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-32 s=255,c=3,t=17,pt=6,l=25,sg=0:A1B246219385A0349910D612ABD02EB2026EAB4D6600EBE514
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 20001E030CFF312E35
Current nonce: A1B246219385A0349910D612ABD02EB2026EAB4D6600EBE514AAAAAAAAAAAAAA
HMAC: 021DBEA454ACA67617AAD08A5EAA2DB9946C291FD78C30389DE56FB9E3A97B87
Signature in message: 011DBEA454ACA67617AAD08A5EAA2DB9946C291FD78C
Message signed
Message to send has been signed
send: 32-32-0-0 s=255,c=3,t=12,pt=0,l=3,sg=1,st=ok:1.5
Skipping security for command 3 type 16
send: 32-32-0-0 s=0,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-32 s=255,c=3,t=17,pt=6,l=25,sg=0:971D30F276321AF56AFD2CEB4465E5C28EBD9CB59E624713CD
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 200006001F00
Current nonce: 971D30F276321AF56AFD2CEB4465E5C28EBD9CB59E624713CDAAAAAAAAAAAAAA
HMAC: 94C8DD65A1208C2D4C21BF5D9F58DA01C2DB05C18F91AE448913AFA6727B78E3
Signature in message: 01C8DD65A1208C2D4C21BF5D9F58DA01C2DB05C18F91AE4489
Message signed
Message to send has been signed
send: 32-32-0-0 s=0,c=0,t=31,pt=0,l=0,sg=1,st=ok:
Init complete, id=32, parent=0, distance=1
------------- Start request time ------------
Skipping security for command 3 type 16
send: 32-32-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-32 s=255,c=3,t=17,pt=6,l=25,sg=0:FCDA9EE51C911344D49467AEB096FFB8A9DF13AE012688ADBA
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 2000060301FF
Current nonce: FCDA9EE51C911344D49467AEB096FFB8A9DF13AE012688ADBAAAAAAAAAAAAAAA
HMAC: B6670E3B04096492ABC6C15713814E0E07376E8F94BBB180160CEA25B0A62F11
Signature in message: 01670E3B04096492ABC6C15713814E0E07376E8F94BBB18016
Message signed
Message to send has been signed
send: 32-32-0-0 s=255,c=3,t=1,pt=0,l=0,sg=1,st=ok:
Skipping security for command 3 type 16
read: 0-0-32 s=255,c=3,t=16,pt=0,l=0,sg=0:
Signing backend: ATSHA204
SHA256: F61319A4255AB3948ADB0B4B5B77349562760D497710D1A19C4A30A4279686C4
Transmittng nonce
Skipping security for command 3 type 17
send: 32-32-0-0 s=255,c=3,t=17,pt=6,l=25,sg=0,st=ok:F61319A4255AB3948ADB0B4B5B77349562760D497710D1A19C
Skipping security for command 3 type 16
read: 0-0-32 s=0,c=3,t=16,pt=0,l=0,sg=0:
Signing backend: ATSHA204
SHA256: B675E5E4870FC6BC6E9F34177C08517F4800678E2BDE81B69C386C20D24CF76C
Transmittng nonce
Skipping security for command 3 type 17
send: 32-32-0-0 s=255,c=3,t=17,pt=6,l=25,sg=0,st=ok:B675E5E4870FC6BC6E9F34177C08517F4800678E2BDE81B69C
Signature in message: 016E70FB42D1089C83D06371BCD9B977F0D1E4D9C6B32DB2
Message to process: 00200E01020030
Current nonce: B675E5E4870FC6BC6E9F34177C08517F4800678E2BDE81B69CAAAAAAAAAAAAAA
HMAC: 0CCB84B1D3B5324B12BEDC7DF4066BDF531A3372DD505E87B1178F02E65D7092
Signature bad: 01CB84B1D3B5324B12BEDC7DF4066BDF531A3372DD505E87
Signature verification failed!
verify fail
No active verification session
Signature verification failed!
verify fail

Anduril

@tomkxy said:

I have to admit I am still on a mid march version of the development branch.

So my first recommendation would be to download newest dev branch. Maybe it was kind of bug that is fixed now. No matter, it will not do any harm.

tomkxy

@Anduril I just upgraded to the latest version. I am rather hesitant with upgrades - although I know this is a dev branch - because you never know what kind of other issues you get.

Same behavior after the upgrade (Gateway and node upgraded.)

Anticimex

@tomkxy command 16 is a nonce request and 17 a nonce response. It reports skipping security for these as they are part of the security handshaking, and signing those would cause a recursive loop.
What I suspect you get here is a collision where both gw and node wants to send signed messages to each other and. I also notice from your log that at the end if it, it receives two nonces after each other. I suspect your gw transmit two messages in succession without allowing the first (signed) message to be fully processed before requesting to send another one.
This can be consider a limitation of the signing framework, but I designed it to be as responsive as possible. Therefore, when you send a message and want it to be signed, the library returns before the full exchange has completed. More to the point, the node sending the signed message will only do so after the nonce response arrives. But when you "send" the message from your node, you get control back as soon as the request for the nonce went out. So if you just go on to send more, then a new nonce will be requested and the old signing session will go "out of date". So you might need to delay your second message to accommodate for this.
I will see if I can make some API to query the status of a signing session to determine if it is allowed to send more messages or not.

Anticimex

@tomkxy I looked in the code, and I was wrong. The node that signs will stall and wait for a nonce to arrive before signing. What we have here, I suspect is two nodes trying to send signed data to each other at the "same" time.

tomkxy

@Anticimex Thanks for your reply. Highly appreciated!
My use case is that the controller sends upon reception of a time request a time response and pending state changes. There is no wait in between. If I understood you correctly this could be reason.
I will change the controller to have a wait in between both messages. I will report results back.

Anticimex

@tomkxy No worries, and now I will ask for some help in return :)
I have no hw currently you see so I have no means for verifying atsha or soft signing.
But I have made a PR with various improvements:
https://github.com/mysensors/Arduino/pull/454

If you would be so kind to test it I would be grateful. Even more so if you tried soft signing as well.
It should permit simultaneous signing sessions at both ends now, and performance for atsha signing should have been improved.

tomkxy

@Anticimex How can I merge the commits of your pull requests into my clone of the development branch?
If I install the code at my gateway and node. Are "older nodes" (mid march state of dev branch" supposed to work?
Do you have any particular tests in mind?

tomkxy

@Anticimex Inserting a wait in between consecutive sends at the controller seem to fix it.

I merged your pull request into my local copy. Are there specific cases you want me to test?

Anticimex

@tomkxy thanks. Well, try removing your delay for starters. Might not be needed anymore. Apart from that, just that it still manages to sign and verify messages.

tomkxy

@Anticimex Will do it tomorrow and let you know.

tomkxy

Ok, I concluded my tests.

The setup I used was as follows:

One node running the sketch as listed above. The sketch just send a time request to the controller. The controller send a time response back and depending on the controller state an additional message carrying the new state.
A MQTTClientGateway using ATSHA204 signing
Gateway and node were either on current deveopment branch (clone from yesterday) or on pull request branch

Summary:

ATSHA204 signing work
Signing in pull request code and current development branch seems not to be compatible
Signing through repeater worked (repeater on old dev branch version)
Possible issue with soft signing and ATSHA204 signing (will re-run test)
Signing Code in pull request made by wait statements between sends in controller code obsolete

I need to split the Test Details over several posts due to size restrictions,

Test Details:

TEST 1

Node is using ATSHA204 signing
Controller has time delays between time response send and state message
Only node upgraded - gateway on current development branch

RESULT:

Message from node did not went through gateway (I would reason that probably signing not compatible between pull request and development branch ?)

Log file from node (Note: that no message "Time value received and updated" occurs)

——— LOG file

Starting sensor (RNNNAA, 2.0.0-beta)
Radio init successful.
Signing required
Skipping security for command 3 type 15
send: 32-32-24-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-24-32 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: 32-32-24-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-24-32 s=255,c=3,t=17,pt=6,l=25,sg=0:5C6D5380AA71742E8676754178E292A5EF45D9AF4AC1DFBDAF
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 2000560011FF322E302E302D62657461
Current nonce: 5C6D5380AA71742E8676754178E292A5EF45D9AF4AC1DFBDAFAAAAAAAAAAAAAA
HMAC: 88E620D12206F54747A0913982E7B536D2FA54B23365E938944D79A7785FA653
Signature in message: 01E620D12206F54747A0913982E7B5
Message signed
Message to send has been signed
send: 32-32-24-0 s=255,c=0,t=17,pt=0,l=10,sg=1,st=ok:2.0.0-beta
Skipping security for command 3 type 16
send: 32-32-24-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-24-32 s=255,c=3,t=17,pt=6,l=25,sg=0:E9823769510CC4E9DB319047430608FC46E072E1C85DC1729C
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 20000E2306FF18
Current nonce: E9823769510CC4E9DB319047430608FC46E072E1C85DC1729CAAAAAAAAAAAAAA
HMAC: 3AFE900842CA69B839436A9417E03B7A1B9F56C86947503DA8211384BD380BA8
Signature in message: 01FE900842CA69B839436A9417E03B7A1B9F56C86947503D
Message signed
Message to send has been signed
send: 32-32-24-0 s=255,c=3,t=6,pt=1,l=1,sg=1,st=ok:24
Skipping security for command 3 type 16
send: 32-32-24-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-24-32 s=255,c=3,t=17,pt=6,l=25,sg=0:62A476471D816BD32D881C6F0F93EECC6F3D10C30FE36C4034
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 20008E030BFF53656E736562656E646572204D6963726F
Current nonce: 62A476471D816BD32D881C6F0F93EECC6F3D10C30FE36C4034AAAAAAAAAAAAAA
HMAC: DD2922863F989B9FA66A9DCC91C6C68693976C111246A758F2A9D3B35DE4C6C8
Signature in message: 012922863F989B9F
Message signed
Message to send has been signed
send: 32-32-24-0 s=255,c=3,t=11,pt=0,l=17,sg=1,st=ok:Sensebender Micro
Skipping security for command 3 type 16
send: 32-32-24-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-24-32 s=255,c=3,t=17,pt=6,l=25,sg=0:E5EB28E56178B7A9EA9C6CF6ED4942C7CFCBE36CE8F770E9CD
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 20001E030CFF312E35
Current nonce: E5EB28E56178B7A9EA9C6CF6ED4942C7CFCBE36CE8F770E9CDAAAAAAAAAAAAAA
HMAC: EE80E376A9134A53E582798BE1B82D0626B749A0B3AB40B146ECBD046A704FE7
Signature in message: 0180E376A9134A53E582798BE1B82D0626B749A0B3AB
Message signed
Message to send has been signed
send: 32-32-24-0 s=255,c=3,t=12,pt=0,l=3,sg=1,st=ok:1.5
Skipping security for command 3 type 16
send: 32-32-24-0 s=0,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-24-32 s=255,c=3,t=17,pt=6,l=25,sg=0:086BCF8D9E1FCE7E31DBC460DBBDA3F192423DEB1D7AED29B4
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 200006001F00
Current nonce: 086BCF8D9E1FCE7E31DBC460DBBDA3F192423DEB1D7AED29B4AAAAAAAAAAAAAA
HMAC: B304BBD4ED2EFC5EEE8345711D1FA7D4ED7DDCB433B93902B35E408732F52CE6
Signature in message: 0104BBD4ED2EFC5EEE8345711D1FA7D4ED7DDCB433B93902B3
Message signed
Message to send has been signed
send: 32-32-24-0 s=0,c=0,t=31,pt=0,l=0,sg=1,st=ok:
Init complete, id=32, parent=24, distance=2
------------- Start request time ------------
Skipping security for command 3 type 16
send: 32-32-24-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-24-32 s=255,c=3,t=17,pt=6,l=25,sg=0:05804055A92D47DDECE52E060847E918F2D259E02E53B239DF
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 2000060301FF
Current nonce: 05804055A92D47DDECE52E060847E918F2D259E02E53B239DFAAAAAAAAAAAAAA
HMAC: 860F685BD22C9A93712755D7536E6B1192BA7B5F3BA19B36DA4B18EE80A83912
Signature in message: 010F685BD22C9A93712755D7536E6B1192BA7B5F3BA19B36DA
Message signed
Message to send has been signed
send: 32-32-24-0 s=255,c=3,t=1,pt=0,l=0,sg=1,st=ok:
------------- End request time ------------
------------- Start request time ------------
Skipping security for command 3 type 16
send: 32-32-24-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: 32-32-24-0 s=255,c=3,t=1,pt=0,l=0,sg=1,st=ok:
------------- End request time ------------
------------- Start request time ------------
Skipping security for command 3 type 16
send: 32-32-24-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-24-32 s=255,c=3,t=17,pt=6,l=25,sg=0:13F748758F5F525808686913EB32CB1301A347DA71BCEC0E24
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 2000060301FF
Current nonce: 13F748758F5F525808686913EB32CB1301A347DA71BCEC0E24AAAAAAAAAAAAAA
HMAC: DCE1C3919B3F1438EA00F8736994F5BE4EE8FCE197782A006C313B0053B1F4AC
Signature in message: 01E1C3919B3F1438EA00F8736994F5BE4EE8FCE197782A006C
Message signed
Message to send has been signed
send: 32-32-24-0 s=255,c=3,t=1,pt=0,l=0,sg=1,st=ok:
------------- End request time ------------
------------- Start request time ------------
Skipping security for command 3 type 16
send: 32-32-24-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-24-32 s=255,c=3,t=17,pt=6,l=25,sg=0:0E77297DB0F5BB24C127F55A7722A26F2B9F5D82CD3527B2C4
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 2000060301FF
Current nonce: 0E77297DB0F5BB24C127F55A7722A26F2B9F5D82CD3527B2C4AAAAAAAAAAAAAA
HMAC: A07FE5FAD14B49598D4D000B1496AFB1B745140C095C7CDB2041B51C3BAF166A
Signature in message: 017FE5FAD14B49598D4D000B1496AFB1B745140C095C7CDB20
Message signed
Message to send has been signed
send: 32-32-24-0 s=255,c=3,t=1,pt=0,l=0,sg=1,st=ok:
------------- End request time ------------
------------- Start request time ------------
Skipping security for command 3 type 16
send: 32-32-24-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-24-32 s=255,c=3,t=17,pt=6,l=25,sg=0:CC2B7F584284438EE577F13911AA5BD6B13F11CF19C072C280
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 2000060301FF
Current nonce: CC2B7F584284438EE577F13911AA5BD6B13F11CF19C072C280AAAAAAAAAAAAAA
HMAC: 1EE99C23EAF302945390304E8DDF21EFEB1509D482E729E94129DDB14DBEFF72
Signature in message: 01E99C23EAF302945390304E8DDF21EFEB1509D482E729E941
Message signed
Message to send has been signed
send: 32-32-24-0 s=255,c=3,t=1,pt=0,l=0,sg=1,st=ok:
------------- End request time ------------
------------- Start request time ------------
Skipping security for command 3 type 16
send: 32-32-24-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-24-32 s=255,c=3,t=17,pt=6,l=25,sg=0:B3B1641F1EFA3E6AC55BCDD8762BBA30684E2E95B5D360534A
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 2000060301FF
Current nonce: B3B1641F1EFA3E6AC55BCDD8762BBA30684E2E95B5D360534AAAAAAAAAAAAAAA
HMAC: 2FBF0526DA75A1730B06B42A114A51D0844A7F5D708ED88CD0BF205367D6436E
Signature in message: 01BF0526DA75A1730B06B42A114A51D0844A7F5D708ED88CD0
Message signed
Message to send has been signed
send: 32-32-24-0 s=255,c=3,t=1,pt=0,l=0,sg=1,st=ok:
------------- End request time ------------
------------- Start request time ------------
Skipping security for command 3 type 16
send: 32-32-24-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-24-32 s=255,c=3,t=17,pt=6,l=25,sg=0:F2F1E9F252998B73BB5ACDFCB5EABD1CCE80FC922B02AD2708
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 2000060301FF
Current nonce: F2F1E9F252998B73BB5ACDFCB5EABD1CCE80FC922B02AD2708AAAAAAAAAAAAAA
HMAC: AF64B1BBCCBA140CC7D888379C5AB5AEEE32A7EF53DCF8E5D381D8BBF10C0EB8
Signature in message: 0164B1BBCCBA140CC7D888379C5AB5AEEE32A7EF53DCF8E5D3
Message signed
Message to send has been signed
send: 32-32-24-0 s=255,c=3,t=1,pt=0,l=0,sg=1,st=ok:
------------- End request time ------------
------------- Start request time ------------
Skipping security for command 3 type 16
send: 32-32-24-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-24-32 s=255,c=3,t=17,pt=6,l=25,sg=0:70EEB8AB6758247D2BDE15C3E3ECF736A26896507A578451B5
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 2000060301FF
Current nonce: 70EEB8AB6758247D2BDE15C3E3ECF736A26896507A578451B5AAAAAAAAAAAAAA
HMAC: 0188F0C5B3E33EA5F367AC3C8A5147000EEAFBC632221B0A2C68A6E912E6502F
Signature in message: 0188F0C5B3E33EA5F367AC3C8A5147000EEAFBC632221B0A2C
Message signed
Message to send has been signed
send: 32-32-24-0 s=255,c=3,t=1,pt=0,l=0,sg=1,st=ok:

tomkxy

Continuation of test details:

TEST 2

Node is using ATSHA204 signing
Controller has time delays between time response send and state message
Node and gateway on current development branch

RESULT:

As already confirmed yesterday time responses received back from controller

Log file from node

Starting sensor (RNNNAA, 2.0.0-beta)
Radio init successful.
Signing required
Skipping security for command 3 type 15
send: 32-32-24-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-24-32 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: 32-32-24-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-24-32 s=255,c=3,t=17,pt=6,l=25,sg=0:E6FA71F94B26770A2F95CA73CE0AD5BAF5E20FBE47DCD15009
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 2000560011FF322E302E302D62657461
Current nonce: E6FA71F94B26770A2F95CA73CE0AD5BAF5E20FBE47DCD15009AAAAAAAAAAAAAA
HMAC: 35D8295F4A9EFEA36A8B1127EE44374F7778E6960F1F4FCAE5DA2E2ACF66BDF3
Signature in message: 01D8295F4A9EFEA36A8B1127EE4437
Message signed
Message to send has been signed
send: 32-32-24-0 s=255,c=0,t=17,pt=0,l=10,sg=1,st=ok:2.0.0-beta
Skipping security for command 3 type 16
send: 32-32-24-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-24-32 s=255,c=3,t=17,pt=6,l=25,sg=0:5B94347F2300D7469FA9450BABBD441CA0B6A794E9F6EF4A19
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 20000E2306FF18
Current nonce: 5B94347F2300D7469FA9450BABBD441CA0B6A794E9F6EF4A19AAAAAAAAAAAAAA
HMAC: 7C724399F2861D355FC195EEFB19BCA69045B6316065DCA698866C3DB0DD2D30
Signature in message: 01724399F2861D355FC195EEFB19BCA69045B6316065DCA6
Message signed
Message to send has been signed
send: 32-32-24-0 s=255,c=3,t=6,pt=1,l=1,sg=1,st=ok:24
Skipping security for command 3 type 16
send: 32-32-24-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-24-32 s=255,c=3,t=17,pt=6,l=25,sg=0:EA257A1C0F67F106E0D689CB816EE42309368549BF801263EB
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 20008E030BFF53656E736562656E646572204D6963726F
Current nonce: EA257A1C0F67F106E0D689CB816EE42309368549BF801263EBAAAAAAAAAAAAAA
HMAC: 1B730087D4F021A92E687301D293893EEF26C59A1DC76783D137A098C0F3BC8A
Signature in message: 01730087D4F021A9
Message signed
Message to send has been signed
send: 32-32-24-0 s=255,c=3,t=11,pt=0,l=17,sg=1,st=ok:Sensebender Micro
Skipping security for command 3 type 16
send: 32-32-24-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-24-32 s=255,c=3,t=17,pt=6,l=25,sg=0:9E3CB2E54C67294BA2FDE0D8581ED4657FAC24C8193898C432
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 20001E030CFF312E35
Current nonce: 9E3CB2E54C67294BA2FDE0D8581ED4657FAC24C8193898C432AAAAAAAAAAAAAA
HMAC: 4044546C809C92399B8695C6065EEB614E694B8A99ECEB9604D529E3932E515D
Signature in message: 0144546C809C92399B8695C6065EEB614E694B8A99EC
Message signed
Message to send has been signed
send: 32-32-24-0 s=255,c=3,t=12,pt=0,l=3,sg=1,st=ok:1.5
Skipping security for command 3 type 16
send: 32-32-24-0 s=0,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-24-32 s=255,c=3,t=17,pt=6,l=25,sg=0:BE44D9741A571A265776618132F4C67D297170489FE1A5DE49
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 200006001F00
Current nonce: BE44D9741A571A265776618132F4C67D297170489FE1A5DE49AAAAAAAAAAAAAA
HMAC: 9146A18E9CFF81636145160052F05583773C17F3CD652323EDED7C8450A3B375
Signature in message: 0146A18E9CFF81636145160052F05583773C17F3CD652323ED
Message signed
Message to send has been signed
send: 32-32-24-0 s=0,c=0,t=31,pt=0,l=0,sg=1,st=ok:
Init complete, id=32, parent=24, distance=2
------------- Start request time ------------
Skipping security for command 3 type 16
send: 32-32-24-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-24-32 s=255,c=3,t=17,pt=6,l=25,sg=0:1DE6CEC94F13A3620D3E8A158E57D9383678CD139DA8B886FC
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 2000060301FF
Current nonce: 1DE6CEC94F13A3620D3E8A158E57D9383678CD139DA8B886FCAAAAAAAAAAAAAA
HMAC: 377976A6BAC3CD3D095B7E327F83FA8536BC0BF49ADF91F58D7A2FAD6C8B18B7
Signature in message: 017976A6BAC3CD3D095B7E327F83FA8536BC0BF49ADF91F58D
Message signed
Message to send has been signed
send: 32-32-24-0 s=255,c=3,t=1,pt=0,l=0,sg=1,st=ok:
Skipping security for command 3 type 16
read: 0-24-32 s=255,c=3,t=16,pt=0,l=0,sg=0:
Signing backend: ATSHA204
SHA256: F08C3C1E3DA5AB87B604B516A44D243622A4C14EBA8EDF79EF46DFF2A40040A6
Transmittng nonce
Skipping security for command 3 type 17
send: 32-32-24-0 s=255,c=3,t=17,pt=6,l=25,sg=0,st=ok:F08C3C1E3DA5AB87B604B516A44D243622A4C14EBA8EDF79EF
Signature in message: 01B251AE4BE20816354DE00A0FA2B6
Message to process: 0020560301FF31343635323833343332
Current nonce: F08C3C1E3DA5AB87B604B516A44D243622A4C14EBA8EDF79EFAAAAAAAAAAAAAA
HMAC: C4B251AE4BE20816354DE00A0FA2B6410F3EDCF014E9D7D85776384A1175F56A
Signature OK
read: 0-24-32 s=255,c=3,t=1,pt=0,l=10,sg=0:1465283432
Time value received and updated...
Skipping security for command 3 type 16
read: 0-24-32 s=0,c=3,t=16,pt=0,l=0,sg=0:
Signing backend: ATSHA204
SHA256: 9FC72D6C543D8F4B63D4D3D000A3FFB94CCC89FB7A446D5177699E115CA56A95
Transmittng nonce
Skipping security for command 3 type 17
send: 32-32-24-0 s=255,c=3,t=17,pt=6,l=25,sg=0,st=ok:9FC72D6C543D8F4B63D4D3D000A3FFB94CCC89FB7A446D5177
Signature in message: 010A2ACC376944024575A028BC722E7C8602F182B9F82794
Message to process: 00200E01020030
Current nonce: 9FC72D6C543D8F4B63D4D3D000A3FFB94CCC89FB7A446D5177AAAAAAAAAAAAAA
HMAC: 820A2ACC376944024575A028BC722E7C8602F182B9F82794C912D83A19E1CC33
Signature OK
read: 0-24-32 s=0,c=1,t=2,pt=0,l=1,sg=0:0
Skipping security for command 3 type 16
read: 0-24-32 s=0,c=3,t=16,pt=0,l=0,sg=0:
Signing backend: ATSHA204
SHA256: 7D55FD16CF971E9702AA53D575A406123F64FBA233C904C40748B2535A26A548
Transmittng nonce
Skipping security for command 3 type 17
send: 32-32-24-0 s=255,c=3,t=17,pt=6,l=25,sg=0,st=ok:7D55FD16CF971E9702AA53D575A406123F64FBA233C904C407
Signature in message: 01971DE8FC789C9C773C89261EE7C7E06A646C4479B53844
Message to process: 00200E01180038
Current nonce: 7D55FD16CF971E9702AA53D575A406123F64FBA233C904C407AAAAAAAAAAAAAA
HMAC: FF971DE8FC789C9C773C89261EE7C7E06A646C4479B538444A52BF2C7285EF87
Signature OK
read: 0-24-32 s=0,c=1,t=24,pt=0,l=1,sg=0:8
------------- End request time ------------
------------- Start request time ------------
Skipping security for command 3 type 16
send: 32-32-24-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-24-32 s=255,c=3,t=17,pt=6,l=25,sg=0:A0334E2B3A18F6C64907210670EBEDCC48B089713E321CD8AC
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 2000060301FF
Current nonce: A0334E2B3A18F6C64907210670EBEDCC48B089713E321CD8ACAAAAAAAAAAAAAA
HMAC: 9D86902DC3D6F353A34805DB53C4D23E525A2A6563E2D0715B0AF8857C2490B2
Signature in message: 0186902DC3D6F353A34805DB53C4D23E525A2A6563E2D0715B
Message signed
Message to send has been signed
send: 32-32-24-0 s=255,c=3,t=1,pt=0,l=0,sg=1,st=ok:
Skipping security for command 3 type 16
read: 0-24-32 s=255,c=3,t=16,pt=0,l=0,sg=0:
Signing backend: ATSHA204
SHA256: FFDDC014EDB87ECF5EC8AB75688B5C2C64B96A01C717491D0C108FF81049EB73
Transmittng nonce
Skipping security for command 3 type 17
send: 32-32-24-0 s=255,c=3,t=17,pt=6,l=25,sg=0,st=ok:FFDDC014EDB87ECF5EC8AB75688B5C2C64B96A01C717491D0C
Signature in message: 0176C6F293A06DE6ED24828FE89FF7
Message to process: 0020560301FF31343635323833343635
Current nonce: FFDDC014EDB87ECF5EC8AB75688B5C2C64B96A01C717491D0CAAAAAAAAAAAAAA
HMAC: B876C6F293A06DE6ED24828FE89FF728E34B135B52E48615A22C6F76CF3C4A99
Signature OK
read: 0-24-32 s=255,c=3,t=1,pt=0,l=10,sg=0:1465283465
Time value received and updated...
Skipping security for command 3 type 16
read: 0-24-32 s=0,c=3,t=16,pt=0,l=0,sg=0:
Signing backend: ATSHA204
SHA256: 8DBF6695277390951AD9DF479264D55207682E6CD178BC06CA31ECB596904B4A
Transmittng nonce
Skipping security for command 3 type 17
send: 32-32-24-0 s=255,c=3,t=17,pt=6,l=25,sg=0,st=ok:8DBF6695277390951AD9DF479264D55207682E6CD178BC06CA
Signature in message: 01409B6BF1B3B666DAB81D1845A04A98C4D111779492F2E0
Message to process: 00200E01020030
Current nonce: 8DBF6695277390951AD9DF479264D55207682E6CD178BC06CAAAAAAAAAAAAAAA
HMAC: D3409B6BF1B3B666DAB81D1845A04A98C4D111779492F2E0EE294358EC49179B
Signature OK
read: 0-24-32 s=0,c=1,t=2,pt=0,l=1,sg=0:0
------------- End request time ------------
------------- Start request time ------------
Skipping security for command 3 type 16
send: 32-32-24-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-24-32 s=255,c=3,t=17,pt=6,l=25,sg=0:3A6C12FD7546268F0D41B0D329AE91D21077965C09045B5A1A
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 2000060301FF
Current nonce: 3A6C12FD7546268F0D41B0D329AE91D21077965C09045B5A1AAAAAAAAAAAAAAA
HMAC: 90168F16ECBE84D86D9D029F9FB8B2FEA7B23017BC17DFD794B74FBFE30367AC
Signature in message: 01168F16ECBE84D86D9D029F9FB8B2FEA7B23017BC17DFD794
Message signed
Message to send has been signed
send: 32-32-24-0 s=255,c=3,t=1,pt=0,l=0,sg=1,st=ok:
Skipping security for command 3 type 16
read: 0-24-32 s=255,c=3,t=16,pt=0,l=0,sg=0:
Signing backend: ATSHA204
SHA256: 1AF497E7C0AF46E1E9CE4606052BA4D6EB40B9509E2F08ADFDA855C348197072
Transmittng nonce
Skipping security for command 3 type 17
send: 32-32-24-0 s=255,c=3,t=17,pt=6,l=25,sg=0,st=ok:1AF497E7C0AF46E1E9CE4606052BA4D6EB40B9509E2F08ADFD
Signature in message: 0119794623B47138C025DF9F233ECD
Message to process: 0020560301FF31343635323833343937
Current nonce: 1AF497E7C0AF46E1E9CE4606052BA4D6EB40B9509E2F08ADFDAAAAAAAAAAAAAA
HMAC: 9F19794623B47138C025DF9F233ECDBAF4A9894997361464CFCCA972AE4989A8
Signature OK
read: 0-24-32 s=255,c=3,t=1,pt=0,l=10,sg=0:1465283497
Time value received and updated...
Skipping security for command 3 type 16
read: 0-24-32 s=0,c=3,t=16,pt=0,l=0,sg=0:
Signing backend: ATSHA204
SHA256: 58F999A6FC7F4688CC738CD2BC8B959844C8E71A0E9DC4FC0AAE473224D1C0B5
Transmittng nonce
Skipping security for command 3 type 17
send: 32-32-24-0 s=255,c=3,t=17,pt=6,l=25,sg=0,st=ok:58F999A6FC7F4688CC738CD2BC8B959844C8E71A0E9DC4FC0A
Signature in message: 01CC16B0D5685A602160700EF75089F6073C80F21534F93E
Message to process: 00200E01020030
Current nonce: 58F999A6FC7F4688CC738CD2BC8B959844C8E71A0E9DC4FC0AAAAAAAAAAAAAAA
HMAC: 69CC16B0D5685A602160700EF75089F6073C80F21534F93E2000948D7E8BC997
Signature OK
read: 0-24-32 s=0,c=1,t=2,pt=0,l=1,sg=0:0
------------- End request time ------------
------------- Start request time ------------
Skipping security for command 3 type 16
send: 32-32-24-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-24-32 s=255,c=3,t=17,pt=6,l=25,sg=0:E75AE3FF33609B318F5189128FA4244BFA8B1E70359812C2C0
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 2000060301FF
Current nonce: E75AE3FF33609B318F5189128FA4244BFA8B1E70359812C2C0AAAAAAAAAAAAAA
HMAC: B6FB768F1A2BB917329A5BE007BAF736AAB801FBD7AAF5E797DA258B335844D2
Signature in message: 01FB768F1A2BB917329A5BE007BAF736AAB801FBD7AAF5E797
Message signed
Message to send has been signed
send: 32-32-24-0 s=255,c=3,t=1,pt=0,l=0,sg=1,st=ok:
Skipping security for command 3 type 16
read: 0-24-32 s=255,c=3,t=16,pt=0,l=0,sg=0:
Signing backend: ATSHA204
SHA256: 741733AB092E579BEBBFC59DC028F867F81D96CBC7E5C252D1C92A4F695C64E9
Transmittng nonce
Skipping security for command 3 type 17
send: 32-32-24-0 s=255,c=3,t=17,pt=6,l=25,sg=0,st=ok:741733AB092E579BEBBFC59DC028F867F81D96CBC7E5C252D1
Signature in message: 0147B776D9FE233CCD972679DF861A
Message to process: 0020560301FF31343635323833353335
Current nonce: 741733AB092E579BEBBFC59DC028F867F81D96CBC7E5C252D1AAAAAAAAAAAAAA
HMAC: 3047B776D9FE233CCD972679DF861A18DBF50268777FAAABC8B57D9AD4E0FDD6
Signature OK
read: 0-24-32 s=255,c=3,t=1,pt=0,l=10,sg=0:1465283535
Time value received and updated...
Skipping security for command 3 type 16
read: 0-24-32 s=0,c=3,t=16,pt=0,l=0,sg=0:
Signing backend: ATSHA204
SHA256: D84DC5731286B20B4E7A145AD56E6CC01D4F4BC50D2CF1F15EF2C61031B3ADB4
Transmittng nonce
Skipping security for command 3 type 17
send: 32-32-24-0 s=255,c=3,t=17,pt=6,l=25,sg=0,st=ok:D84DC5731286B20B4E7A145AD56E6CC01D4F4BC50D2CF1F15E
Signature in message: 0165AC479F9655E4A5AA8BBCEEFBADFD8A5A82098F785DA8
Message to process: 00200E01020030
Current nonce: D84DC5731286B20B4E7A145AD56E6CC01D4F4BC50D2CF1F15EAAAAAAAAAAAAAA
HMAC: 6265AC479F9655E4A5AA8BBCEEFBADFD8A5A82098F785DA83869EDCF9A3C9AE5
Signature OK
read: 0-24-32 s=0,c=1,t=2,pt=0,l=1,sg=0:0
------------- End request time ------------
------------- Start request time ------------
Skipping security for command 3 type 16
send: 32-32-24-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-24-32 s=255,c=3,t=17,pt=6,l=25,sg=0:2B043E5A9822F872642044D993996C219D7387ADED3FCBEAAC
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 2000060301FF
Current nonce: 2B043E5A9822F872642044D993996C219D7387ADED3FCBEAACAAAAAAAAAAAAAA
HMAC: 232BC7F7C4BDBA0D41559AF67DD47FA212AC12EB8B06401C2C23A7AF0172436D
Signature in message: 012BC7F7C4BDBA0D41559AF67DD47FA212AC12EB8B06401C2C
Message signed
Message to send has been signed
send: 32-32-24-0 s=255,c=3,t=1,pt=0,l=0,sg=1,st=ok:
Skipping security for command 3 type 16
read: 0-24-32 s=255,c=3,t=16,pt=0,l=0,sg=0:
Signing backend: ATSHA204
SHA256: BE203E8DCB145A7AEA98A3E7BA43D8D4837A9FD9572D54B220C4DCE37C9CC8B8
Transmittng nonce
Skipping security for command 3 type 17
send: 32-32-24-0 s=255,c=3,t=17,pt=6,l=25,sg=0,st=ok:BE203E8DCB145A7AEA98A3E7BA43D8D4837A9FD9572D54B220
Signature in message: 010DB59D0F3452D2785F69172BB6D9
Message to process: 0020560301FF31343635323833353638
Current nonce: BE203E8DCB145A7AEA98A3E7BA43D8D4837A9FD9572D54B220AAAAAAAAAAAAAA
HMAC: BC0DB59D0F3452D2785F69172BB6D931F071F8599B4B1685E921800ED64A2ED5
Signature OK
read: 0-24-32 s=255,c=3,t=1,pt=0,l=10,sg=0:1465283568
Time value received and updated...
Skipping security for command 3 type 16
read: 0-24-32 s=0,c=3,t=16,pt=0,l=0,sg=0:
Signing backend: ATSHA204
SHA256: 466900BD4216412DF7B918A01726A585D404BF70647DAABA7C43A272142381CE
Transmittng nonce
Skipping security for command 3 type 17
send: 32-32-24-0 s=255,c=3,t=17,pt=6,l=25,sg=0,st=ok:466900BD4216412DF7B918A01726A585D404BF70647DAABA7C
Signature in message: 011633DF1C1E5CE5BC498D0713D4375337AB1686E6930D72
Message to process: 00200E01020030
Current nonce: 466900BD4216412DF7B918A01726A585D404BF70647DAABA7CAAAAAAAAAAAAAA
HMAC: 301633DF1C1E5CE5BC498D0713D4375337AB1686E6930D729761FA1833B50550
Signature OK
read: 0-24-32 s=0,c=1,t=2,pt=0,l=1,sg=0:0

TEST 3

Node is using ATSHA204 signing
Controller has time delays between time response send and state message
Gateway and Node on pull request node
By accident repeater is being used by node (repeater on mid march version of development branch)

RESULT:

OK

Log file form node

Starting sensor (RNNNAA, 2.0.0-beta)
Radio init successful.
Signing required
Skipping security for command 3 type 15
send: 32-32-24-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-24-32 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: 32-32-24-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-24-32 s=255,c=3,t=17,pt=6,l=25,sg=0:7FFE40154EF5EDC50456162DDF2DDE74267E32EC275FBD7EAB
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 2000560011FF322E302E302D62657461
Current nonce: 7FFE40154EF5EDC50456162DDF2DDE74267E32EC275FBD7EABAAAAAAAAAAAAAA
HMAC: 6A3AA858C7AEFC6C4BE07D05196BE89BE52C70C4799E42B73B8CDF83C0A57B92
Signature in message: 013AA858C7AEFC6C4BE07D05196BE8
Message signed
Message to send has been signed
send: 32-32-24-0 s=255,c=0,t=17,pt=0,l=10,sg=1,st=ok:2.0.0-beta
Skipping security for command 3 type 16
send: 32-32-24-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-24-32 s=255,c=3,t=17,pt=6,l=25,sg=0:19C213A19C060D9AF53333025D95CC0D47E102D7534F6853C2
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 20000E2306FF18
Current nonce: 19C213A19C060D9AF53333025D95CC0D47E102D7534F6853C2AAAAAAAAAAAAAA
HMAC: 3748905CBC38DCEA925EB2919C91D1C62C10766F1FAC36B3278246D5B71F3699
Signature in message: 0148905CBC38DCEA925EB2919C91D1C62C10766F1FAC36B3
Message signed
Message to send has been signed
send: 32-32-24-0 s=255,c=3,t=6,pt=1,l=1,sg=1,st=ok:24
Skipping security for command 3 type 16
send: 32-32-24-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-24-32 s=255,c=3,t=17,pt=6,l=25,sg=0:C4F140A7704F93F1ADDD92E353B52F64262D51F18C0E31E984
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 20008E030BFF53656E736562656E646572204D6963726F
Current nonce: C4F140A7704F93F1ADDD92E353B52F64262D51F18C0E31E984AAAAAAAAAAAAAA
HMAC: 438D4A7A4DC4F81D813B776C408D28D330712BDFF9D6918CA5F5D399A39DCC62
Signature in message: 018D4A7A4DC4F81D
Message signed
Message to send has been signed
send: 32-32-24-0 s=255,c=3,t=11,pt=0,l=17,sg=1,st=ok:Sensebender Micro
Skipping security for command 3 type 16
send: 32-32-24-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-24-32 s=255,c=3,t=17,pt=6,l=25,sg=0:6F36BDDE3BFC831A66DD1401932B313456C23E3E43A1043ED2
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 20001E030CFF312E35
Current nonce: 6F36BDDE3BFC831A66DD1401932B313456C23E3E43A1043ED2AAAAAAAAAAAAAA
HMAC: 539E7375EDC9460D6C1CB93108B7AF3D8681F8DBBA12FF7D4F8EBD789674C526
Signature in message: 019E7375EDC9460D6C1CB93108B7AF3D8681F8DBBA12
Message signed
Message to send has been signed
send: 32-32-24-0 s=255,c=3,t=12,pt=0,l=3,sg=1,st=ok:1.5
Skipping security for command 3 type 16
send: 32-32-24-0 s=0,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-24-32 s=255,c=3,t=17,pt=6,l=25,sg=0:FF294B857B47AE22B3A8FDCB6C8900057722A43EAB7C76FEB1
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 200006001F00
Current nonce: FF294B857B47AE22B3A8FDCB6C8900057722A43EAB7C76FEB1AAAAAAAAAAAAAA
HMAC: 1984DB5AA5D62F10664670E558ED2127B3076B8E53594970FCB19090D4114346
Signature in message: 0184DB5AA5D62F10664670E558ED2127B3076B8E53594970FC
Message signed
Message to send has been signed
send: 32-32-24-0 s=0,c=0,t=31,pt=0,l=0,sg=1,st=ok:
Init complete, id=32, parent=24, distance=2
------------- Start request time ------------
Skipping security for command 3 type 16
send: 32-32-24-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-24-32 s=255,c=3,t=17,pt=6,l=25,sg=0:346DB0580D3B78948D4642890DEE3BF8B713278F9035F1010E
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 2000060301FF
Current nonce: 346DB0580D3B78948D4642890DEE3BF8B713278F9035F1010EAAAAAAAAAAAAAA
HMAC: 7D563A98EB3A82BD356405D848810D80E85B41B13BD5EF160EDC28D0D8410A3B
Signature in message: 01563A98EB3A82BD356405D848810D80E85B41B13BD5EF160E
Message signed
Message to send has been signed
send: 32-32-24-0 s=255,c=3,t=1,pt=0,l=0,sg=1,st=ok:
Skipping security for command 3 type 16
read: 0-24-32 s=255,c=3,t=16,pt=0,l=0,sg=0:
Signing backend: ATSHA204
SHA256: F8D84FE5212ADCDAA5DE824AAEC0D1D4EBA27A873C7A27FD6573312A0120144D
Transmittng nonce
Skipping security for command 3 type 17
send: 32-32-24-0 s=255,c=3,t=17,pt=6,l=25,sg=0,st=ok:F8D84FE5212ADCDAA5DE824AAEC0D1D4EBA27A873C7A27FD65
Signature in message: 01061F649DC8230A23A693B2BD13EF
Message to process: 0020560301FF31343635323834333532
Current nonce: F8D84FE5212ADCDAA5DE824AAEC0D1D4EBA27A873C7A27FD65AAAAAAAAAAAAAA
HMAC: 9B061F649DC8230A23A693B2BD13EF482A0FD3D935AC12CAB83BAEE20AF7AFA6
Signature OK
read: 0-24-32 s=255,c=3,t=1,pt=0,l=10,sg=0:1465284352
Time value received and updated...
Skipping security for command 3 type 16
read: 0-24-32 s=0,c=3,t=16,pt=0,l=0,sg=0:
Signing backend: ATSHA204
SHA256: C8D54FA98921070C459C82FA52F15F4588E6B8C7CBFA98E4ABCD41C842152E8E
Transmittng nonce
Skipping security for command 3 type 17
send: 32-32-24-0 s=255,c=3,t=17,pt=6,l=25,sg=0,st=ok:C8D54FA98921070C459C82FA52F15F4588E6B8C7CBFA98E4AB
Signature in message: 014449082B9AD2C9C678F3CAB3EF978885420D7F5DFC872F
Message to process: 00200E01180038
Current nonce: C8D54FA98921070C459C82FA52F15F4588E6B8C7CBFA98E4ABAAAAAAAAAAAAAA
HMAC: 0B4449082B9AD2C9C678F3CAB3EF978885420D7F5DFC872F934FD46509728350
Signature OK
read: 0-24-32 s=0,c=1,t=24,pt=0,l=1,sg=0:8
------------- End request time ------------
------------- Start request time ------------
Skipping security for command 3 type 16
send: 32-32-24-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-24-32 s=255,c=3,t=17,pt=6,l=25,sg=0:ADE703FCA7389B894F9C6967C8556AE9332EC8819CC1403F4B
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 2000060301FF
Current nonce: ADE703FCA7389B894F9C6967C8556AE9332EC8819CC1403F4BAAAAAAAAAAAAAA
HMAC: 85FCF9EB6F02220B9C7C541F0E4A39F96E0763ED8EC4B513D608B022A5FD743F
Signature in message: 01FCF9EB6F02220B9C7C541F0E4A39F96E0763ED8EC4B513D6
Message signed
Message to send has been signed
send: 32-32-24-0 s=255,c=3,t=1,pt=0,l=0,sg=1,st=ok:
Skipping security for command 3 type 16
read: 0-24-32 s=255,c=3,t=16,pt=0,l=0,sg=0:
Signing backend: ATSHA204
SHA256: 160BFFD15040AAB68A664D1E717A13F713EB4427DF9D5BB85F69BEDCDE371A10
Transmittng nonce
Skipping security for command 3 type 17
send: 32-32-24-0 s=255,c=3,t=17,pt=6,l=25,sg=0,st=ok:160BFFD15040AAB68A664D1E717A13F713EB4427DF9D5BB85F
Signature in message: 016D402871BF2F0955767FF9BD4D04
Message to process: 0020560301FF31343635323834333832
Current nonce: 160BFFD15040AAB68A664D1E717A13F713EB4427DF9D5BB85FAAAAAAAAAAAAAA
HMAC: B16D402871BF2F0955767FF9BD4D043224B3161ABD93A483898CBE5B034DB929
Signature OK
read: 0-24-32 s=255,c=3,t=1,pt=0,l=10,sg=0:1465284382
Time value received and updated...
------------- End request time ------------
------------- Start request time ------------
Skipping security for command 3 type 16
send: 32-32-24-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-24-32 s=255,c=3,t=17,pt=6,l=25,sg=0:20FE53ECF79ADB4E40AAEFC7822710105C7273500280542C6C
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 2000060301FF
Current nonce: 20FE53ECF79ADB4E40AAEFC7822710105C7273500280542C6CAAAAAAAAAAAAAA
HMAC: C206D0F84D4BD17A4F91FEEC96A68FC08809FB764657A78B30BAA156811CAB35
Signature in message: 0106D0F84D4BD17A4F91FEEC96A68FC08809FB764657A78B30
Message signed
Message to send has been signed
send: 32-32-24-0 s=255,c=3,t=1,pt=0,l=0,sg=1,st=ok:
Skipping security for command 3 type 16
read: 0-24-32 s=255,c=3,t=16,pt=0,l=0,sg=0:
Signing backend: ATSHA204
SHA256: 26C55258CC012D74F2C67E21D8EEBDD1E360F39E6F15C0C84603D5AE48CF0441
Transmittng nonce
Skipping security for command 3 type 17
send: 32-32-24-0 s=255,c=3,t=17,pt=6,l=25,sg=0,st=ok:26C55258CC012D74F2C67E21D8EEBDD1E360F39E6F15C0C846
Signature in message: 019BDFBD6FB58C08DC10D5CFF9F809
Message to process: 0020560301FF31343635323834343133
Current nonce: 26C55258CC012D74F2C67E21D8EEBDD1E360F39E6F15C0C846AAAAAAAAAAAAAA
HMAC: A99BDFBD6FB58C08DC10D5CFF9F8097420DEE280B27A9CE5ACA2EC0D1120FF98
Signature OK
read: 0-24-32 s=255,c=3,t=1,pt=0,l=10,sg=0:1465284413
Time value received and updated...

verify fail

tomkxy

Continuation of test details

TEST 4

Node is using soft signing, GW ATSHA204 signing
Node and gateway on pull request code
Controller has time delays between time response send and state message

RESULT:

Failed

Note: I just realized that I have in the beginning a couple of transmission errors which is due to he fact that I needed to bring the node and gateway probably to close together in order to get the gateway logs.
I will repeat this test!

Log file form node

Starting sensor (RNNNAS, 2.0.0-beta)
Radio init successful.
Signing required
Skipping security for command 3 type 15
send: 32-32-24-0 s=255,c=3,t=15,pt=0,l=2,sg=0,st=fail:
Waiting for GW to send signing preferences...
Skipping security for command 3 type 16
send: 32-32-24-0 s=255,c=3,t=16,pt=0,l=0,sg=0,st=fail:
Failed to transmit nonce request!
sign fail
send: 32-32-24-0 s=255,c=0,t=17,pt=0,l=10,sg=0,st=fail:2.0.0-beta
Skipping security for command 3 type 16
send: 32-32-24-0 s=255,c=3,t=16,pt=0,l=0,sg=0,st=fail:
Failed to transmit nonce request!
sign fail
send: 32-32-24-0 s=255,c=3,t=6,pt=1,l=1,sg=0,st=fail:24
Skipping security for command 3 type 16
send: 32-32-24-0 s=255,c=3,t=16,pt=0,l=0,sg=0,st=fail:
find parent
send: 32-32-255-255 s=255,c=3,t=7,pt=0,l=0,sg=0,st=bc:
Skipping security for command 3 type 8
read: 0-0-32 s=255,c=3,t=8,pt=1,l=1,sg=0:0
parent=0, d=1
Failed to transmit nonce request!
sign fail
send: 0-32-0-32 s=255,c=3,t=8,pt=1,l=1,sg=0,st=ok:0
Skipping security for command 3 type 16
send: 32-32-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-32 s=255,c=3,t=17,pt=6,l=25,sg=0:9D0A6F87CD7824856F6C5F86135DF9C205A52172154E2ECAA8
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204Soft
Message to process: 20001E030CFF312E35
Current nonce: 9D0A6F87CD7824856F6C5F86135DF9C205A52172154E2ECAA8AAAAAAAAAAAAAA
HMAC: 1B03C1339C72E52DE7ADA8312983CE2853E8E4CF7A88C262250900388FFDD1F8
Signature in message: 0103C1339C72E52DE7ADA8312983CE2853E8E4CF7A88
Message signed
Message to send has been signed
send: 32-32-0-0 s=255,c=3,t=12,pt=0,l=3,sg=1,st=ok:1.5
Skipping security for command 3 type 16
send: 32-32-0-0 s=0,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-32 s=255,c=3,t=17,pt=6,l=25,sg=0:F6B9819CA822EECEE953357A43742393B952BB5C152C601208
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204Soft
Message to process: 200006001F00
Current nonce: F6B9819CA822EECEE953357A43742393B952BB5C152C601208AAAAAAAAAAAAAA
HMAC: A74B8E7B71B7F614D6E4DA7E1817459E5F15C26D5A75CA57B1723E9EEC5FC248
Signature in message: 014B8E7B71B7F614D6E4DA7E1817459E5F15C26D5A75CA57B1
Message signed
Message to send has been signed
send: 32-32-0-0 s=0,c=0,t=31,pt=0,l=0,sg=1,st=ok:
Init complete, id=32, parent=0, distance=1
------------- Start request time ------------
Skipping security for command 3 type 16
send: 32-32-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-32 s=255,c=3,t=17,pt=6,l=25,sg=0:D84804E29BF6B78CC1F7823E860D19378D399472D3D3A43D6F
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204Soft
Message to process: 2000060301FF
Current nonce: D84804E29BF6B78CC1F7823E860D19378D399472D3D3A43D6FAAAAAAAAAAAAAA
HMAC: CE335FA0706A8C57678547FA4DD9528BDE7AA9401607B3920C79DB515C630B46
Signature in message: 01335FA0706A8C57678547FA4DD9528BDE7AA9401607B3920C
Message signed
Message to send has been signed
send: 32-32-0-0 s=255,c=3,t=1,pt=0,l=0,sg=1,st=ok:

Log file from gateway:

0;255;3;0;9;Starting gateway (RNNGAA, 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;Attempting MQTT connection...
0;255;3;0;9;MQTT connected
0;255;3;0;9;Skipping security for command 3 type 16
0;255;3;0;9;read: 32-32-0 s=255,c=3,t=16,pt=0,l=0,sg=0:
0;255;3;0;9;Signing backend: ATSHA204
0;255;3;0;9;SHA256: 1F0846076C5AD7D094CA224A960CF66CB67F5E6CB4BD0EEDD2EE290975E1CAAD
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-32-32 s=255,c=3,t=17,pt=6,l=25,sg=0,st=ok:1F0846076C5AD7D094CA224A960CF66CB67F5E6CB4BD0EEDD2
0;255;3;0;9;Signature in message: 01E921AD315EFBDA944E6F9F1A7FB21BFD2FD798E2C212CB0E
0;255;3;0;9;Message to process: 2000060301FF
0;255;3;0;9;Current nonce: 1F0846076C5AD7D094CA224A960CF66CB67F5E6CB4BD0EEDD2AAAAAAAAAAAAAA
0;255;3;0;9;HMAC: 7C952EBD4EE51B758DA5BFA19E14F01DA5CD375882CE6CAA316F5A5117BA8A54
0;255;3;0;9;Signature bad: 01952EBD4EE51B758DA5BFA19E14F01DA5CD375882CE6CAA31
0;255;3;0;9;Signature verification failed!
0;255;3;0;9;verify fail

TEST 5

ATSHA204 signing
Node and gateway on pull request code
Removed delays between send in controller

RESULT:

OK

Starting sensor (RNNNAA, 2.0.0-beta)
Radio init successful.
Signing required
Skipping security for command 3 type 15
send: 32-32-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-32 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: 32-32-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-32 s=255,c=3,t=17,pt=6,l=25,sg=0:FE59BF15C57BFEE2694AC0808D7E9C1F92739CBD6188E1674E
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 2000560011FF322E302E302D62657461
Current nonce: FE59BF15C57BFEE2694AC0808D7E9C1F92739CBD6188E1674EAAAAAAAAAAAAAA
HMAC: D627F8CC1ED41A9CC0067FFCA8F2DE919BB51348B20748E8E2406BAF2C96BD76
Signature in message: 0127F8CC1ED41A9CC0067FFCA8F2DE
Message signed
Message to send has been signed
send: 32-32-0-0 s=255,c=0,t=17,pt=0,l=10,sg=1,st=ok:2.0.0-beta
Skipping security for command 3 type 16
send: 32-32-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-32 s=255,c=3,t=17,pt=6,l=25,sg=0:A630B1C776C8759946C7F58EA263CA7683B59D828F8161B78F
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 20000E2306FF00
Current nonce: A630B1C776C8759946C7F58EA263CA7683B59D828F8161B78FAAAAAAAAAAAAAA
HMAC: F4D362400F33CCE581E3A97E40CF7F1AE74ACAB8ED2E97A21E10E4A43B9B619A
Signature in message: 01D362400F33CCE581E3A97E40CF7F1AE74ACAB8ED2E97A2
Message signed
Message to send has been signed
send: 32-32-0-0 s=255,c=3,t=6,pt=1,l=1,sg=1,st=ok:0
Skipping security for command 3 type 16
send: 32-32-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-32 s=255,c=3,t=17,pt=6,l=25,sg=0:CA7A11B0F5EE59A28ADCA0AC74FEFCFD59F430893E548992A9
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 20008E030BFF53656E736562656E646572204D6963726F
Current nonce: CA7A11B0F5EE59A28ADCA0AC74FEFCFD59F430893E548992A9AAAAAAAAAAAAAA
HMAC: 50EBEE0FCE4DDE0CCF63294D4DD6D142D958B9763F206A42219D7B701D184C1D
Signature in message: 01EBEE0FCE4DDE0C
Message signed
Message to send has been signed
send: 32-32-0-0 s=255,c=3,t=11,pt=0,l=17,sg=1,st=ok:Sensebender Micro
Skipping security for command 3 type 16
send: 32-32-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-32 s=255,c=3,t=17,pt=6,l=25,sg=0:C505BE34F06A7DF14012B6096C41268BF35B06A0C14D276F70
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 20001E030CFF312E35
Current nonce: C505BE34F06A7DF14012B6096C41268BF35B06A0C14D276F70AAAAAAAAAAAAAA
HMAC: 7DB23045C8B4AE6AE1D49263C36B204781530088F9D6D082B3C11F01C991573A
Signature in message: 01B23045C8B4AE6AE1D49263C36B204781530088F9D6
Message signed
Message to send has been signed
send: 32-32-0-0 s=255,c=3,t=12,pt=0,l=3,sg=1,st=ok:1.5
Skipping security for command 3 type 16
send: 32-32-0-0 s=0,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-32 s=255,c=3,t=17,pt=6,l=25,sg=0:5F3E459CE02B989081990670A0EFC390FB800F5083B961806B
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 200006001F00
Current nonce: 5F3E459CE02B989081990670A0EFC390FB800F5083B961806BAAAAAAAAAAAAAA
HMAC: C233B208BCB7B838FD0E2643453510BA9D4B4CA507626C646569B4723508C7E6
Signature in message: 0133B208BCB7B838FD0E2643453510BA9D4B4CA507626C6465
Message signed
Message to send has been signed
send: 32-32-0-0 s=0,c=0,t=31,pt=0,l=0,sg=1,st=ok:
Init complete, id=32, parent=0, distance=1
------------- Start request time ------------
Skipping security for command 3 type 16
send: 32-32-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-32 s=255,c=3,t=17,pt=6,l=25,sg=0:5284D3E4DDB1653B612D386C5639215EB2D586CD13F538E44C
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 2000060301FF
Current nonce: 5284D3E4DDB1653B612D386C5639215EB2D586CD13F538E44CAAAAAAAAAAAAAA
HMAC: 64324E13B3D277F3DAD2F213854702DDC1C56290462A44387C16B9B05C927EB3
Signature in message: 01324E13B3D277F3DAD2F213854702DDC1C56290462A44387C
Message signed
Message to send has been signed
send: 32-32-0-0 s=255,c=3,t=1,pt=0,l=0,sg=1,st=ok:
Skipping security for command 3 type 16
read: 0-0-32 s=255,c=3,t=16,pt=0,l=0,sg=0:
Signing backend: ATSHA204
SHA256: 051A42C2D547A6501D825592655382F46097B940CB2A9BC7862764640382A6F4
Transmittng nonce
Skipping security for command 3 type 17
send: 32-32-0-0 s=255,c=3,t=17,pt=6,l=25,sg=0,st=ok:051A42C2D547A6501D825592655382F46097B940CB2A9BC786
Signature in message: 013DA95E35B18396C1610C640882FC
Message to process: 0020560301FF31343635323836313037
Current nonce: 051A42C2D547A6501D825592655382F46097B940CB2A9BC786AAAAAAAAAAAAAA
HMAC: 083DA95E35B18396C1610C640882FC8F7A73BB2F36C4CCB622978F14F8DCF88E
Signature OK
read: 0-0-32 s=255,c=3,t=1,pt=0,l=10,sg=0:1465286107
Time value received and updated...
Skipping security for command 3 type 16
read: 0-0-32 s=0,c=3,t=16,pt=0,l=0,sg=0:
Signing backend: ATSHA204
SHA256: 064A0459AAB0F53006E4E0648F9F547E24E39CDEF29299DE10FB759CD49CD6AE
Transmittng nonce
Skipping security for command 3 type 17
send: 32-32-0-0 s=255,c=3,t=17,pt=6,l=25,sg=0,st=ok:064A0459AAB0F53006E4E0648F9F547E24E39CDEF29299DE10
Signature in message: 01E1A03B9429A6DBFF20E6D19D1E68C07E7CC238E3EC7893
Message to process: 00200E01020030
Current nonce: 064A0459AAB0F53006E4E0648F9F547E24E39CDEF29299DE10AAAAAAAAAAAAAA
HMAC: C1E1A03B9429A6DBFF20E6D19D1E68C07E7CC238E3EC78930184BD18F0823FF6
Signature OK
read: 0-0-32 s=0,c=1,t=2,pt=0,l=1,sg=0:0
Skipping security for command 3 type 16
read: 0-0-32 s=0,c=3,t=16,pt=0,l=0,sg=0:
Signing backend: ATSHA204
SHA256: 0D27D0A1761710382B1527AB510AAFBDF7E965AD4453E1451085252F4C422575
Transmittng nonce
Skipping security for command 3 type 17
send: 32-32-0-0 s=255,c=3,t=17,pt=6,l=25,sg=0,st=ok:0D27D0A1761710382B1527AB510AAFBDF7E965AD4453E14510
Signature in message: 01BB1C2ABEF5EDB609FC783D2D4068632EA4CFFB49AE2C06
Message to process: 00200E01180038
Current nonce: 0D27D0A1761710382B1527AB510AAFBDF7E965AD4453E14510AAAAAAAAAAAAAA
HMAC: 00BB1C2ABEF5EDB609FC783D2D4068632EA4CFFB49AE2C06F614377BE7576BEC
Signature OK
read: 0-0-32 s=0,c=1,t=24,pt=0,l=1,sg=0:8

TEST 6

Node is using soft signing, GW ATSHA204 signing
Node and gateway on development branch
Controller has time delays between time response send and state message

RESULT:

As expected from the tests I did yesterday this test failed

Log from node

Starting sensor (RNNNAA, 2.0.0-beta)
Radio init successful.
Signing required
Skipping security for command 3 type 15
send: 32-32-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-32 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: 32-32-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-32 s=255,c=3,t=17,pt=6,l=25,sg=0:21F62EF9ADA09F07E5AB18EFA404E54CB1504EE3DA5FF1516E
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 2000560011FF322E302E302D62657461
Current nonce: 21F62EF9ADA09F07E5AB18EFA404E54CB1504EE3DA5FF1516EAAAAAAAAAAAAAA
HMAC: 1F7E4DF2B93FF4A998032FB88764F4027068F54496697E385F7E1278F3BD7BC8
Signature in message: 017E4DF2B93FF4A998032FB88764F4
Message signed
Message to send has been signed
send: 32-32-0-0 s=255,c=0,t=17,pt=0,l=10,sg=1,st=ok:2.0.0-beta
Skipping security for command 3 type 16
send: 32-32-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-32 s=255,c=3,t=17,pt=6,l=25,sg=0:42C03767A6A847595911A4ABADCE7129FEC4AC76952DDAEAD5
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 20000E2306FF00
Current nonce: 42C03767A6A847595911A4ABADCE7129FEC4AC76952DDAEAD5AAAAAAAAAAAAAA
HMAC: 4067930A19F2FF7ECDFB2442F8F9475BA30AF732AA5469A49F18D32ABF89D341
Signature in message: 0167930A19F2FF7ECDFB2442F8F9475BA30AF732AA5469A4
Message signed
Message to send has been signed
send: 32-32-0-0 s=255,c=3,t=6,pt=1,l=1,sg=1,st=ok:0
Skipping security for command 3 type 16
send: 32-32-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-32 s=255,c=3,t=17,pt=6,l=25,sg=0:BB9F341EBAD0551B8541AF7A7274CBE08EAE92E6914D64CF21
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 20008E030BFF53656E736562656E646572204D6963726F
Current nonce: BB9F341EBAD0551B8541AF7A7274CBE08EAE92E6914D64CF21AAAAAAAAAAAAAA
HMAC: 32623A195B988A45DD84948CD3D037D5F1A2C30570FC0667DEAE2C1A5F6E3870
Signature in message: 01623A195B988A45
Message signed
Message to send has been signed
send: 32-32-0-0 s=255,c=3,t=11,pt=0,l=17,sg=1,st=ok:Sensebender Micro
Skipping security for command 3 type 16
send: 32-32-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-32 s=255,c=3,t=17,pt=6,l=25,sg=0:797BDE0D89EE433BD1105F135F7BC4117889EC9164CC7440B6
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 20001E030CFF312E35
Current nonce: 797BDE0D89EE433BD1105F135F7BC4117889EC9164CC7440B6AAAAAAAAAAAAAA
HMAC: 4014EF97E0847D1320268E43F84DD28DE1B30700DBCC2F3D73E55BE76C86A865
Signature in message: 0114EF97E0847D1320268E43F84DD28DE1B30700DBCC
Message signed
Message to send has been signed
send: 32-32-0-0 s=255,c=3,t=12,pt=0,l=3,sg=1,st=ok:1.5
Skipping security for command 3 type 16
send: 32-32-0-0 s=0,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-32 s=255,c=3,t=17,pt=6,l=25,sg=0:6928BF0F14662D30151049D54DC559D9980BDC58D05E4FCC11
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 200006001F00
Current nonce: 6928BF0F14662D30151049D54DC559D9980BDC58D05E4FCC11AAAAAAAAAAAAAA
HMAC: FB7B393036440F4EE838209F596F20A779319E4EA41E775D7B49A118AD405B61
Signature in message: 017B393036440F4EE838209F596F20A779319E4EA41E775D7B
Message signed
Message to send has been signed
send: 32-32-0-0 s=0,c=0,t=31,pt=0,l=0,sg=1,st=ok:
Init complete, id=32, parent=0, distance=1
------------- Start request time ------------
Skipping security for command 3 type 16
send: 32-32-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-32 s=255,c=3,t=17,pt=6,l=25,sg=0:F1F6E026C9E12A1482F9E0629B219C299702775062CAE96EFC
Nonce received from 0. Proceeding with signing...
Signing backend: ATSHA204
Message to process: 2000060301FF
Current nonce: F1F6E026C9E12A1482F9E0629B219C299702775062CAE96EFCAAAAAAAAAAAAAA
HMAC: B3F8B969384698B445CC9B94A3F9D632B2BC00282376066306277239A8781164
Signature in message: 01F8B969384698B445CC9B94A3F9D632B2BC00282376066306
Message signed
Message to send has been signed
send: 32-32-0-0 s=255,c=3,t=1,pt=0,l=0,sg=1,st=ok:
Skipping security for command 3 type 16
read: 0-0-32 s=255,c=3,t=16,pt=0,l=0,sg=0:
Signing backend: ATSHA204
SHA256: BEA0F900BC32AC08474C32CE30CF7FD09424EE6FD7F56493DE6A79995E23E3F3
Transmittng nonce
Skipping security for command 3 type 17
send: 32-32-0-0 s=255,c=3,t=17,pt=6,l=25,sg=0,st=ok:BEA0F900BC32AC08474C32CE30CF7FD09424EE6FD7F56493DE
Skipping security for command 3 type 16
read: 0-0-32 s=0,c=3,t=16,pt=0,l=0,sg=0:
Signing backend: ATSHA204
SHA256: 93D42A3EB88FECBA7026EA0CA7B96D4CEEF9CC84238EF7628AC1C6133C3657F5
Transmittng nonce
Skipping security for command 3 type 17
send: 32-32-0-0 s=255,c=3,t=17,pt=6,l=25,sg=0,st=fail:93D42A3EB88FECBA7026EA0CA7B96D4CEEF9CC84238EF7628A
Skipping security for command 3 type 16
read: 0-0-32 s=0,c=3,t=16,pt=0,l=0,sg=0:
Signing backend: ATSHA204
SHA256: C8C7D4569B16DD09FB5BAFB89FB78FA51E5BF8FEF98ED1F9764E547AE3B8B4BF
Transmittng nonce
Skipping security for command 3 type 17
send: 32-32-0-0 s=255,c=3,t=17,pt=6,l=25,sg=0,st=ok:C8C7D4569B16DD09FB5BAFB89FB78FA51E5BF8FEF98ED1F976
Signature in message: 0126AF027E257738CFD55BE17BEDEAA3E525ED70ABB279D8
Message to process: 00200E01180038
Current nonce: C8C7D4569B16DD09FB5BAFB89FB78FA51E5BF8FEF98ED1F976AAAAAAAAAAAAAA
HMAC: 3F7E76453D012BADF96D39903092EB63E39B4C6A9DB91307F18E79BB50D58446
Signature bad: 017E76453D012BADF96D39903092EB63E39B4C6A9DB91307
Signature verification failed!
verify fail
No active verification session
Signature verification failed!

Anticimex

@tomkxy When you use soft signing, have you personalized that node with the same HMAC key? Soft signing on development stores this in EEPROM. It has to match what the other node has in the ATSHA204.

tomkxy

@Anticimex said:

@tomkxy When you use soft signing, have you personalized that node with the same HMAC key? Soft signing on development stores this in EEPROM. It has to match what the other node has in the ATSHA204.

Yes, while I was writing this occurred to me. That's the reason why I will repeat that test.

Anticimex

@tomkxy Ok cool. Thanks a LOT for your testing. From what I can see, you end up with something totally functional (for atsha at least)?
No additional delays, signing works (hopefully quicker), and node and gw can exchange signed messages without collisions/dropped messages due to sign fail, etc?

tomkxy

@Anticimex Ok. I repeated the the soft signing tests: Both, gateway and node on soft signing works.
Putting node on ATSHA204 signing while gateway is still on soft signing fails.

Apart from that issue, the implementation seems to work and improves obviously on the timing issue I had.

Signing: no active verification session?

15

11.7k

11.2k

113.0k