[SOLVED] MySigning cannot write hmac key to eeprom of standalone ATmega328p (sign verify fail)



  • Hey everybody,

    today I tried to use MySigning with a SerialGateway and a BinarySwitchSleepSensor but it didn't work.

    The SerialGateway is an Arduino Nano and the sensor node is an ATmega328p@1Mhz on a Breadboard. The Nano is powered by USB and the ATmega is powered by battery (2 AA cells).

    Arduino Nano SerialGateway:

    #define MY_DEBUG
    
    #define MY_RADIO_NRF24
    #define MY_RF24_PA_LEVEL RF24_PA_MAX
    #define MY_RF24_CHANNEL 71
    
    #define MY_GATEWAY_SERIAL
    
    #if F_CPU == 8000000L
    #define MY_BAUD_RATE 115200
    #endif
    
    #define MY_DEFAULT_LED_BLINK_PERIOD 300
    
    #define MY_SIGNING_SOFT
    #define MY_SIGNING_REQUEST_SIGNATURES
    #define MY_SIGNING_GW_REQUEST_SIGNATURES_FROM_ALL 
    #include <MySensors.h>
    
    void setup()
    {
    }
    
    void presentation()
    {
    }
    
    void loop()
    {
    }
    

    ATmega node:

    #define MY_NODE_ID 1
    
    #define MY_DEBUG
    
    #define MY_RADIO_NRF24
    #define MY_RF24_PA_LEVEL RF24_PA_MAX
    #define MY_RF24_CHANNEL 71
    
    #define MY_SIGNING_SOFT
    #define MY_SIGNING_REQUEST_SIGNATURES
    #include <MySensors.h>
    #include <Vcc.h>
    
    #define PRIMARY_CHILD_ID 0
    
    #define PRIMARY_BUTTON_PIN 3
    
    int oldBatteryPcnt = 0;
    
    const float VccMin   = 1.9;
    const float VccMax   = 3.3;
    // Measured Vcc by multimeter divided by reported Vcc
    const float VccCorrection = 1.0 / 1.0;
    
    Vcc vcc(VccCorrection);
    
    MyMessage msg(PRIMARY_CHILD_ID, V_TRIPPED);
    
    void setup()
    {
      pinMode(PRIMARY_BUTTON_PIN, INPUT);
    
      digitalWrite(PRIMARY_BUTTON_PIN, HIGH);
    
      analogReference(INTERNAL);
    }
    
    void presentation()
    {
      present(PRIMARY_CHILD_ID, S_DOOR);
    }
    
    void loop()
    {
      uint8_t value;
      static uint8_t sentValue = 2;
    
      sleep(5);
    
      value = digitalRead(PRIMARY_BUTTON_PIN);
    
      if (value != sentValue) {
        send(msg.set(value == HIGH));
        sentValue = value;
      }
    
      int batteryPcnt = vcc.Read_Perc(VccMin, VccMax);
      if (oldBatteryPcnt != batteryPcnt) {
        sendBatteryLevel(batteryPcnt);
        oldBatteryPcnt = batteryPcnt;
      }
    
      sleep(PRIMARY_BUTTON_PIN - 2, CHANGE, 0);
    }
    

    I exactly followed these instructions and everything seemed to be fine. But there is no communication between the gateway and the node after the initial find parent request is answered by the gateway:

    0;255;3;0;9;MCO:BGN:INIT GW,CP=RNNGAS-,VER=2.1.1
    0;255;3;0;9;TSM:INIT
    0;255;3;0;9;TSF:WUR:MS=0
    0;255;3;0;9;TSM:INIT:TSP OK
    0;255;3;0;9;TSM:INIT:GW MODE
    0;255;3;0;9;TSM:READY:ID=0,PAR=0,DIS=0
    0;255;3;0;9;MCO:REG:NOT NEEDED
    0;255;3;0;14;Gateway startup complete.
    0;255;0;0;18;2.1.1
    0;255;3;0;9;MCO:BGN:STP
    0;255;3;0;9;MCO:BGN:INIT OK,TSP=1
    0;255;3;0;9;TSF:MSG:READ,1-1-255,s=255,c=3,t=7,pt=0,l=0,sg=0:
    0;255;3;0;9;TSF:MSG:BC
    0;255;3;0;9;TSF:MSG:FPAR REQ,ID=1
    0;255;3;0;9;TSF:PNG:SEND,TO=0
    0;255;3;0;9;TSF:CKU:OK
    0;255;3;0;9;TSF:MSG:GWL OK
    0;255;3;0;9;TSF:MSG:SEND,0-0-1-1,s=255,c=3,t=8,pt=1,l=1,sg=0,ft=0,st=OK:0
    

    If I remove the sleep instruction at the end of the node script I don't have this problem anymore but then I get a "sign verify fail" message.

    I already checked the keys in the EEPROM with the SecurityPersonalizer.ino and they are still there. So nothing has overwritten the EEPROM.

    If I completly remove the MySigning code everything just works fine:

    0;255;3;0;9;MCO:BGN:INIT GW,CP=RNNGA--,VER=2.1.1
    0;255;3;0;9;TSM:INIT
    0;255;3;0;9;TSF:WUR:MS=0
    0;255;3;0;9;TSM:INIT:TSP OK
    0;255;3;0;9;TSM:INIT:GW MODE
    0;255;3;0;9;TSM:READY:ID=0,PAR=0,DIS=0
    0;255;3;0;9;MCO:REG:NOT NEEDED
    0;255;3;0;14;Gateway startup complete.
    0;255;0;0;18;2.1.1
    0;255;3;0;9;MCO:BGN:STP
    0;255;3;0;9;MCO:BGN:INIT OK,TSP=1
    0;255;3;0;9;TSF:MSG:READ,1-1-255,s=255,c=3,t=7,pt=0,l=0,sg=0:
    0;255;3;0;9;TSF:MSG:BC
    0;255;3;0;9;TSF:MSG:FPAR REQ,ID=1
    0;255;3;0;9;TSF:PNG:SEND,TO=0
    0;255;3;0;9;TSF:CKU:OK
    0;255;3;0;9;TSF:MSG:GWL OK
    0;255;3;0;9;TSF:MSG:SEND,0-0-1-1,s=255,c=3,t=8,pt=1,l=1,sg=0,ft=0,st=OK:0
    0;255;3;0;9;TSF:MSG:READ,1-1-0,s=255,c=3,t=24,pt=1,l=1,sg=0:1
    0;255;3;0;9;TSF:MSG:PINGED,ID=1,HP=1
    0;255;3;0;9;TSF:MSG:SEND,0-0-1-1,s=255,c=3,t=25,pt=1,l=1,sg=0,ft=0,st=OK:1
    0;255;3;0;9;TSF:MSG:READ,1-1-0,s=255,c=3,t=15,pt=6,l=2,sg=0:0100
    0;255;3;0;9;TSF:MSG:SEND,0-0-1-1,s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=OK:0100
    0;255;3;0;9;TSF:MSG:READ,1-1-0,s=255,c=0,t=17,pt=0,l=5,sg=0:2.1.1
    1;255;0;0;17;2.1.1
    0;255;3;0;9;TSF:MSG:READ,1-1-0,s=255,c=3,t=6,pt=1,l=1,sg=0:0
    1;255;3;0;6;0
    0;255;3;0;9;TSF:MSG:READ,1-1-0,s=0,c=0,t=0,pt=0,l=0,sg=0:
    1;0;0;0;0;
    0;255;3;0;9;TSF:MSG:READ,1-1-0,s=255,c=3,t=26,pt=1,l=1,sg=0:2
    0;255;3;0;9;TSF:MSG:SEND,0-0-1-1,s=255,c=3,t=27,pt=1,l=1,sg=0,ft=0,st=OK:1
    0;255;3;0;9;TSF:MSG:READ,1-1-0,s=0,c=1,t=16,pt=1,l=1,sg=0:0
    1;0;1;0;16;0
    0;255;3;0;9;TSF:MSG:READ,1-1-0,s=255,c=3,t=0,pt=1,l=1,sg=0:69
    1;255;3;0;0;69
    

    I hope somebody can help me :+1:

    Edit: Now the communication problem is solved but I still get the "sign verify fail" message. Debug output of the node:

    0 MCO:BGN:INIT NODE,CP=RNNNAS-,VER=2.1.1
    32 TSM:INIT
    49 TSF:WUR:MS=0
    81 TSM:INIT:TSP OK
    98 TSM:INIT:STATID=1
    131 TSF:SID:OK,ID=1
    147 TSM:FPAR
    196 TSF:MSG:SEND,1-1-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK:
    1064 TSF:MSG:READ,0-0-1,s=255,c=3,t=8,pt=1,l=1,sg=1:0
    1114 TSF:MSG:FPAR OK,ID=0,D=1
    2293 TSM:FPAR:OK
    2310 TSM:ID
    2326 TSM:ID:OK
    2342 TSM:UPL
    2359 TSF:MSG:SEND,1-1-0-0,s=255,c=3,t=24,pt=1,l=1,sg=0,ft=0,st=OK:1
    2441 TSF:MSG:READ,0-0-1,s=255,c=3,t=25,pt=1,l=1,sg=1:1
    2506 TSF:MSG:PONG RECV,HP=1
    2539 TSM:UPL:OK
    2555 TSM:READY:ID=1,PAR=0,DIS=1
    2588 TSF:MSG:SEND,1-1-0-0,s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=OK:0101
    2686 TSF:MSG:READ,0-0-1,s=255,c=3,t=15,pt=6,l=2,sg=0:0101
    2752 TSF:MSG:SEND,1-1-0-0,s=255,c=3,t=16,pt=0,l=0,sg=0,ft=0,st=OK:
    2834 TSF:MSG:READ,0-0-1,s=255,c=3,t=17,pt=6,l=25,sg=0:EB2599F19FCF3F8046FFF401B88BA0A57A489EAB20B62AC91C
    4227 TSF:MSG:SEND,1-1-0-0,s=255,c=0,t=17,pt=0,l=5,sg=1,ft=0,st=OK:2.1.1
    4308 TSF:MSG:SEND,1-1-0-0,s=255,c=3,t=16,pt=0,l=0,sg=1,ft=0,st=OK:
    4390 TSF:MSG:READ,0-0-1,s=255,c=3,t=17,pt=6,l=25,sg=1:12E9344AAEB6BF1A064AFD2E13081D1924A3D6B6758AD68595
    5783 TSF:MSG:SEND,1-1-0-0,s=255,c=3,t=6,pt=1,l=1,sg=1,ft=0,st=OK:0
    7880 TSF:MSG:SEND,1-1-0-0,s=0,c=3,t=16,pt=0,l=0,sg=1,ft=0,st=OK:
    7962 TSF:MSG:READ,0-0-1,s=255,c=3,t=17,pt=6,l=25,sg=1:708B63BB7A30C43B18B20E73F8CEA18B2343238077ED5F341F
    9355 TSF:MSG:SEND,1-1-0-0,s=0,c=0,t=0,pt=0,l=0,sg=1,ft=0,st=OK:
    9420 MCO:REG:REQ
    9453 TSF:MSG:SEND,1-1-0-0,s=255,c=3,t=26,pt=1,l=1,sg=1,ft=0,st=OK:2
    9535 TSF:MSG:READ,0-0-1,s=255,c=3,t=16,pt=0,l=0,sg=1:
    9830 TSF:MSG:SEND,1-1-0-0,s=255,c=3,t=17,pt=6,l=25,sg=1,ft=0,st=OK:EC89D0D3CE5C8BA3F0C559BEB77D7B1181D7D1BD753BD3AC6B
    9961 TSF:MSG:READ,0-0-1,s=255,c=3,t=27,pt=1,l=1,sg=1:1
    11288 !TSF:MSG:SIGN VERIFY FAIL
    11337 MCO:BGN:STP
    11354 MCO:BGN:INIT OK,TSP=1
    11386 MCO:SLP:MS=5,SMS=0,I1=255,M1=255,I2=255,M2=255
    11452 MCO:SLP:TPD
    11468 MCO:SLP:WUP=-1
    11501 TSF:MSG:SEND,1-1-0-0,s=0,c=3,t=16,pt=0,l=0,sg=1,ft=0,st=OK:
    11583 TSF:MSG:READ,0-0-1,s=255,c=3,t=17,pt=6,l=25,sg=1:5B22EFBFFA514553827667BB7C406E63AB5216E72F520EF981
    12976 TSF:MSG:SEND,1-1-0-0,s=0,c=1,t=16,pt=1,l=1,sg=1,ft=0,st=OK:0
    13058 TSF:MSG:SEND,1-1-0-0,s=255,c=3,t=16,pt=0,l=0,sg=1,ft=0,st=OK:
    13139 TSF:MSG:READ,0-0-1,s=255,c=3,t=17,pt=6,l=25,sg=1:C2269B73674B275848348F737A6CA5F932E886E678EE086AC9
    14532 TSF:MSG:SEND,1-1-0-0,s=255,c=3,t=0,pt=1,l=1,sg=1,ft=0,st=OK:100
    14614 MCO:SLP:MS=0,SMS=0,I1=1,M1=1,I2=255,M2=255
    14680 MCO:SLP:TPD
    

  • Contest Winner

    @alexanderkind
    Hi,
    Can you please post the memory consumption report when you build the gateway sketch?
    I suspect it crashes due to stack being too small.



  • @Anticimex Do you mean this one?

    Sketch uses 18868 bytes (61%) of program storage space. Maximum is 30720 bytes.
    Global variables use 1182 bytes (57%) of dynamic memory, leaving 866 bytes for local variables. Maximum is 2048 bytes.
    

  • Contest Winner

    @alexanderkind yes. Does not look that bad. You could try with debugging disabled and see if it makes a difference. Apart from that, I don't really know what could be the issue, but the GW does not seem happy. The signing code has been verified though and should not be the cause of a crash in itself.



  • @Anticimex Unfortunately it doesn't made a difference. Maybe someone else already had this problem...


  • Contest Winner

    @alexanderkind could you post the debug from the node? Perhaps the GW is still alive but the node isn't. Do you have other nodes running? I notice that you enabled the request from all flag on the gateway.



  • @Anticimex Here it is:

    0 MCO:BGN:INIT NODE,CP=RNNNAS-,VER=2.1.1
    32 TSM:INIT
    49 TSF:WUR:MS=0
    81 TSM:INIT:TSP OK
    98 TSM:INIT:STATID=1
    131 TSF:SID:OK,ID=1
    147 TSM:FPAR
    196 TSF:MSG:SEND,1-1-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK:
    1064 TSF:MSG:READ,0-0-1,s=255,c=3,t=8,pt=1,l=1,sg=1:0
    1114 TSF:MSG:FPAR OK,ID=0,D=1
    2293 TSM:FPAR:OK
    2310 TSM:ID
    2326 TSM:ID:OK
    2342 TSM:UPL
    2359 TSF:MSG:SEND,1-1-0-0,s=255,c=3,t=24,pt=1,l=1,sg=0,ft=0,st=OK:1
    2441 TSF:MSG:READ,0-0-1,s=255,c=3,t=25,pt=1,l=1,sg=1:1
    2506 TSF:MSG:PONG RECV,HP=1
    2539 TSM:UPL:OK
    2555 TSM:READY:ID=1,PAR=0,DIS=1
    2588 TSF:MSG:SEND,1-1-0-0,s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=OK:0101
    2686 TSF:MSG:READ,0-0-1,s=255,c=3,t=15,pt=6,l=2,sg=0:0101
    2752 TSF:MSG:SEND,1-1-0-0,s=255,c=3,t=16,pt=0,l=0,sg=0,ft=0,st=OK:
    2834 TSF:MSG:READ,0-0-1,s=255,c=3,t=17,pt=6,l=25,sg=0:EB2599F19FCF3F8046FFF401B88BA0A57A489EAB20B62AC91C
    4227 TSF:MSG:SEND,1-1-0-0,s=255,c=0,t=17,pt=0,l=5,sg=1,ft=0,st=OK:2.1.1
    4308 TSF:MSG:SEND,1-1-0-0,s=255,c=3,t=16,pt=0,l=0,sg=1,ft=0,st=OK:
    4390 TSF:MSG:READ,0-0-1,s=255,c=3,t=17,pt=6,l=25,sg=1:12E9344AAEB6BF1A064AFD2E13081D1924A3D6B6758AD68595
    5783 TSF:MSG:SEND,1-1-0-0,s=255,c=3,t=6,pt=1,l=1,sg=1,ft=0,st=OK:0
    7880 TSF:MSG:SEND,1-1-0-0,s=0,c=3,t=16,pt=0,l=0,sg=1,ft=0,st=OK:
    7962 TSF:MSG:READ,0-0-1,s=255,c=3,t=17,pt=6,l=25,sg=1:708B63BB7A30C43B18B20E73F8CEA18B2343238077ED5F341F
    9355 TSF:MSG:SEND,1-1-0-0,s=0,c=0,t=0,pt=0,l=0,sg=1,ft=0,st=OK:
    9420 MCO:REG:REQ
    9453 TSF:MSG:SEND,1-1-0-0,s=255,c=3,t=26,pt=1,l=1,sg=1,ft=0,st=OK:2
    9535 TSF:MSG:READ,0-0-1,s=255,c=3,t=16,pt=0,l=0,sg=1:
    9830 TSF:MSG:SEND,1-1-0-0,s=255,c=3,t=17,pt=6,l=25,sg=1,ft=0,st=OK:EC89D0D3CE5C8BA3F0C559BEB77D7B1181D7D1BD753BD3AC6B
    9961 TSF:MSG:READ,0-0-1,s=255,c=3,t=27,pt=1,l=1,sg=1:1
    11288 !TSF:MSG:SIGN VERIFY FAIL
    11337 MCO:BGN:STP
    11354 MCO:BGN:INIT OK,TSP=1
    11386 MCO:SLP:MS=5,SMS=0,I1=255,M1=255,I2=255,M2=255
    11452 MCO:SLP:TPD
    11468 MCO:SLP:WUP=-1
    11501 TSF:MSG:SEND,1-1-0-0,s=0,c=3,t=16,pt=0,l=0,sg=1,ft=0,st=OK:
    11583 TSF:MSG:READ,0-0-1,s=255,c=3,t=17,pt=6,l=25,sg=1:5B22EFBFFA514553827667BB7C406E63AB5216E72F520EF981
    12976 TSF:MSG:SEND,1-1-0-0,s=0,c=1,t=16,pt=1,l=1,sg=1,ft=0,st=OK:0
    13058 TSF:MSG:SEND,1-1-0-0,s=255,c=3,t=16,pt=0,l=0,sg=1,ft=0,st=OK:
    13139 TSF:MSG:READ,0-0-1,s=255,c=3,t=17,pt=6,l=25,sg=1:C2269B73674B275848348F737A6CA5F932E886E678EE086AC9
    14532 TSF:MSG:SEND,1-1-0-0,s=255,c=3,t=0,pt=1,l=1,sg=1,ft=0,st=OK:100
    14614 MCO:SLP:MS=0,SMS=0,I1=1,M1=1,I2=255,M2=255
    14680 MCO:SLP:TPD
    

    The problem with the connection is gone. Now gateway and node are startig up correctly and are talking but I get the "sign verify fail" every time.


  • Contest Winner

    @alexanderkind could you enable the verbose signing debug flag on the node please?



  • @Anticimex Yeah of course:

    0 MCO:BGN:INIT NODE,CP=RNNNAS-,VER=2.1.1
    32 TSM:INIT
    49 TSF:WUR:MS=0
    81 TSM:INIT:TSP OK
    98 TSM:INIT:STATID=1
    131 TSF:SID:OK,ID=1
    147 TSM:FPAR
    163 Will not sign message for destination 255 as it does not require it
    278 TSF:MSG:SEND,1-1-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK:
    2375 !TSM:FPAR:NO REPLY
    2392 TSM:FPAR
    2408 Will not sign message for destination 255 as it does not require it
    2523 TSF:MSG:SEND,1-1-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK:
    4636 !TSM:FPAR:NO REPLY
    4653 TSM:FPAR
    4669 Will not sign message for destination 255 as it does not require it
    4800 TSF:MSG:SEND,1-1-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK:
    6897 !TSM:FPAR:NO REPLY
    6914 TSM:FPAR
    6930 Will not sign message for destination 255 as it does not require it
    7045 TSF:MSG:SEND,1-1-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK:
    9158 !TSM:FPAR:FAIL
    9175 TSM:FAIL:CNT=1
    9191 TSM:FAIL:PDT
    

    That's strange, isn't it? I will try it without the request from all flag on the gateway but I thought it would be right to set it if I want signing for all nodes. (At the moment I'm just experimenting with one node.)



  • @Anticimex Sorry. It was my fault. Now it should be correct. Here is the new debug output:

    0 MCO:BGN:INIT NODE,CP=RNNNAS-,VER=2.1.1
    32 TSM:INIT
    49 TSF:WUR:MS=0
    81 TSM:INIT:TSP OK
    98 TSM:INIT:STATID=1
    131 TSF:SID:OK,ID=1
    147 TSM:FPAR
    163 Will not sign message for destination 255 as it does not require it
    278 TSF:MSG:SEND,1-1-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK:
    737 TSF:MSG:READ,0-0-1,s=255,c=3,t=8,pt=1,l=1,sg=1:0
    802 Skipping security for command 3 type 8
    851 TSF:MSG:FPAR OK,ID=0,D=1
    2375 TSM:FPAR:OK
    2392 TSM:ID
    2408 TSM:ID:OK
    2424 TSM:UPL
    2441 Skipping security for command 3 type 24
    2490 TSF:MSG:SEND,1-1-0-0,s=255,c=3,t=24,pt=1,l=1,sg=0,ft=0,st=OK:1
    2572 TSF:MSG:READ,0-0-1,s=255,c=3,t=25,pt=1,l=1,sg=1:1
    2637 Skipping security for command 3 type 25
    2686 TSF:MSG:PONG RECV,HP=1
    2719 TSM:UPL:OK
    2736 TSM:READY:ID=1,PAR=0,DIS=1
    2768 Signing required
    2801 Skipping security for command 3 type 15
    2850 TSF:MSG:SEND,1-1-0-0,s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=OK:0101
    2932 Waiting for GW to send signing preferences...
    2998 TSF:MSG:READ,0-0-1,s=255,c=3,t=15,pt=6,l=2,sg=0:0101
    3063 Skipping security for command 3 type 15
    3112 Mark node 0 as one that require signed messages
    3162 Mark node 0 as one that do not require whitelisting
    3227 Skipping security for command 3 type 16
    3293 TSF:MSG:SEND,1-1-0-0,s=255,c=3,t=16,pt=0,l=0,sg=0,ft=0,st=OK:
    3358 Nonce requested from 0. Waiting...
    3407 TSF:MSG:READ,0-0-1,s=255,c=3,t=17,pt=6,l=25,sg=0:03AC0D8B3CB5CB15A89C1CA0D34A23A3CD126BB074F8B86363
    3538 Skipping security for command 3 type 17
    3588 Nonce received from 0.
    3620 Proceeding with signing...
    Message to process: 01002E0011FF322E312E31
    Current nonce: 03AC0D8B3CB5CB15A89C1CA0D34A23A3CD126BB074F8B86363AAAAAAAAAAAAAA
    HMAC: 42A3503DBB004E69A9D9F7D28B95840D053FC9392FA07DEEB0F7DF77FDE96F28
    Signature in message: 01A3503DBB004E69A9D9F7D28B95840D053FC939
    5062 Message signed
    5160 Message to send has been signed
    5193 TSF:MSG:SEND,1-1-0-0,s=255,c=0,t=17,pt=0,l=5,sg=1,ft=0,st=OK:2.1.1
    5292 Skipping security for command 3 type 16
    5341 TSF:MSG:SEND,1-1-0-0,s=255,c=3,t=16,pt=0,l=0,sg=1,ft=0,st=OK:
    5423 Nonce requested from 0. Waiting...
    5472 TSF:MSG:READ,0-0-1,s=255,c=3,t=17,pt=6,l=25,sg=1:4C7070935D33A92B30B5C969B2D73AD1528B7715B3DDBCE1A3
    5586 Skipping security for command 3 type 17
    5636 Nonce received from 0.
    5668 Proceeding with signing...
    Message to process: 01000E2306FF00
    Current nonce: 4C7070935D33A92B30B5C969B2D73AD1528B7715B3DDBCE1A3AAAAAAAAAAAAAA
    HMAC: CB7D06543C6086C9CCB25CF7DB42F0A81613215486A512EDA03238F8E33D3C4D
    Signature in message: 017D06543C6086C9CCB25CF7DB42F0A81613215486A512ED
    7127 Message signed
    7208 Message to send has been signed
    7258 TSF:MSG:SEND,1-1-0-0,s=255,c=3,t=6,pt=1,l=1,sg=1,ft=0,st=OK:0
    9338 Skipping security for command 3 type 16
    9388 TSF:MSG:SEND,1-1-0-0,s=0,c=3,t=16,pt=0,l=0,sg=1,ft=0,st=OK:
    9469 Nonce requested from 0. Waiting...
    9502 TSF:MSG:READ,0-0-1,s=255,c=3,t=17,pt=6,l=25,sg=1:39A8009337CE6B2429675B3EE9D1FD11A12CB201C27B7AB731
    9633 Skipping security for command 3 type 17
    9682 Nonce received from 0.
    9715 Proceeding with signing...
    Message to process: 010006000000
    Current nonce: 39A8009337CE6B2429675B3EE9D1FD11A12CB201C27B7AB731AAAAAAAAAAAAAA
    HMAC: 925B0FAED6941FFC943824E7ADBC694D1521C515B5C28BB0445873043CE2A167
    Signature in message: 015B0FAED6941FFC943824E7ADBC694D1521C515B5C28BB044
    11157 Message signed
    11255 Message to send has been signed
    11304 TSF:MSG:SEND,1-1-0-0,s=0,c=0,t=0,pt=0,l=0,sg=1,ft=0,st=OK:
    11370 MCO:REG:REQ
    11403 Skipping security for command 3 type 26
    11452 TSF:MSG:SEND,1-1-0-0,s=255,c=3,t=26,pt=1,l=1,sg=1,ft=0,st=OK:2
    11534 TSF:MSG:READ,0-0-1,s=255,c=3,t=16,pt=0,l=0,sg=1:
    11599 Skipping security for command 3 type 16
    SHA256: 21F723FE2BC6B783D6180A5D5FD4FA6FEEBC9619DB03AC42F700000000000000
    11894 Skipping security for command 3 type 17
    12009 TSF:MSG:SEND,1-1-0-0,s=255,c=3,t=17,pt=6,l=25,sg=1,ft=0,st=OK:21F723FE2BC6B783D6180A5D5FD4FA6FEEBC9619DB03AC42F7
    12156 Transmitted nonce
    12173 TSF:MSG:READ,0-0-1,s=255,c=3,t=27,pt=1,l=1,sg=1:1
    Signature in message: 01F9F3C6AB0598E633E422941AED25C8326217E59EB80E2D
    Message to process: 00010E231BFF01
    Current nonce: 21F723FE2BC6B783D6180A5D5FD4FA6FEEBC9619DB03AC42F7AAAAAAAAAAAAAA
    HMAC: 4DB8C02FBF9752C441D02C31E770CC7D7E9559C3F0323EB5E85949DB55479125
    Signature bad: 01B8C02FBF9752C441D02C31E770CC7D7E9559C3F0323EB5
    13729 Signature verification failed!
    13828 !TSF:MSG:SIGN VERIFY FAIL
    13860 MCO:BGN:STP
    13893 MCO:BGN:INIT OK,TSP=1
    13926 MCO:SLP:MS=5,SMS=0,I1=255,M1=255,I2=255,M2=255
    13975 MCO:SLP:TPD
    14008 MCO:SLP:WUP=-1
    14024 Skipping security for command 3 type 16
    14090 TSF:MSG:SEND,1-1-0-0,s=0,c=3,t=16,pt=0,l=0,sg=1,ft=0,st=OK:
    14155 Nonce requested from 0. Waiting...
    14204 TSF:MSG:READ,0-0-1,s=255,c=3,t=17,pt=6,l=25,sg=1:9C129D83097B589C208D1C9C33B1950DC9EE1C258CF7A93E05
    14336 Skipping security for command 3 type 17
    14385 Nonce received from 0.
    14417 Proceeding with signing...
    Message to process: 01000E21100000
    Current nonce: 9C129D83097B589C208D1C9C33B1950DC9EE1C258CF7A93E05AAAAAAAAAAAAAA
    HMAC: EB1086A4ED61967A799188580A94ED63AF3FA19D416CDFEBD44533337287719C
    Signature in message: 011086A4ED61967A799188580A94ED63AF3FA19D416CDFEB
    15876 Message signed
    15958 Message to send has been signed
    16007 TSF:MSG:SEND,1-1-0-0,s=0,c=1,t=16,pt=1,l=1,sg=1,ft=0,st=OK:0
    16089 Skipping security for command 3 type 16
    16138 TSF:MSG:SEND,1-1-0-0,s=255,c=3,t=16,pt=0,l=0,sg=1,ft=0,st=OK:
    16220 Nonce requested from 0. Waiting...
    16269 TSF:MSG:READ,0-0-1,s=255,c=3,t=17,pt=6,l=25,sg=1:387EA66DC5039E8E6868373832492E019E1A5A055A01A69988
    16400 Skipping security for command 3 type 17
    16449 Nonce received from 0.
    16482 Proceeding with signing...
    Message to process: 01000E2300FF64
    Current nonce: 387EA66DC5039E8E6868373832492E019E1A5A055A01A69988AAAAAAAAAAAAAA
    HMAC: 33644999A7B56076EBC8E6C12C787406C9348F721D1B7AEC56F5430DC1A659CD
    Signature in message: 01644999A7B56076EBC8E6C12C787406C9348F721D1B7AEC
    17924 Message signed
    18022 Message to send has been signed
    18071 TSF:MSG:SEND,1-1-0-0,s=255,c=3,t=0,pt=1,l=1,sg=1,ft=0,st=OK:100
    18153 MCO:SLP:MS=0,SMS=0,I1=1,M1=1,I2=255,M2=255
    18202 MCO:SLP:TPD
    

  • Contest Winner

    @alexanderkind from your last log, I don't see the signing presentation data being exchanged so the node have not yet learned of the gw:s signing preferences.


  • Contest Winner

    @alexanderkind ok, everything points to that the GW and the node have different hmac keys. Are you absolutely positive that they are identical?
    You don't need to post them as proof, just make sure that every single bit is the same :)
    The security personalizer can be configured to dump them. Or you can dump eeprom by other means.



  • @Anticimex I will try to dump them with the security personalizer. I already did that earlier. Should be no problem. But I thought they were the same :confused:



  • @Anticimex You're definitely right. For some reason I can't write the key to the eeprom of the ATmega328p. If I upload the sketch and then try to dump the keys, there are only many F's. With the Arduino Nano Gateway everything works fine.

    You're great! I would have never thought that it could be such a problem :) But now I have to solve that :joy:


  • Contest Winner

    @alexanderkind well, sorry to hear that you have a problem with the eeprom. Glad to be able to help out in troubleshooting it.
    Perhaps you have some code on your node that writes to eeprom and happens to write to the wrong place? (only speculating). But now at least you have a reason for the the failed verifications. 👍



  • @Anticimex I think I will try that tomorrow. And I will set up the node with another Arduino Nano instead of the ATmega standalone to see if that works :+1:



  • @Anticimex I couldn't stop trying to fix the problem :) Now it's working. I had to set different fuses with avrdude because EESAVE wasn't enabled. So every upload with the Arduino IDE cleaned the eeprom :)


  • Contest Winner

    @alexanderkind great that the root cause was found! And now we have a forum thread for others to read in case they have the same problem! Thanks for reporting!


Log in to reply
 

Looks like your connection to MySensors Forum was lost, please wait while we try to reconnect.