Singing 2.2.0

[Anticimex]

@alexsh1 either that or hack the library to ignore the checksum

[alexsh1]

@anticimex Would you please amend the header in your 2.1 to 2.2 migration procedure - I had to clean EEPROM completely. Just running personalisation did not work sadly.

[Anticimex]

@alexsh1 then that's a different problem. I have verified the migration procedure and it works. Please do read carefully that you need to re do it completely. Just running the vanilla personalizer won't do anything.

[alexsh1]

@anticimex My bad - you have actually said it at the top "This is because in 2.2, a checksum has been added to the security data in EEPROM to avoid usage of tampered or accidentally wiped data."

:(((

I need to get my reading glasses
Sorry

[alexsh1]

I still have singing failed for nodes:

25499 SGN:BND:NONCE=BA17A594E41FC5E68F148EF2F1A5546046BF1F21BDC14716AAAAAAAAAAAAAAAA
25667 SGN:BND:HMAC=EDF245616FD66545C50DB9BE8EA23A29678A9DDCEB8184AB83D6E02814CDC841
25675 !SGN:VER:FAIL
25679 !TSF:MSG:SIGN VERIFY FAIL
25681 SGN:SGN:NREQ=0
25688 TSF:MSG:SEND,15-15-0-0,s=255,c=3,t=11,pt=0,l=22,sg=0,ft=0,st=OK:BMP280 Pressure Sensor
25698 SGN:SGN:NREQ=0
25702 TSF:MSG:SEND,15-15-0-0,s=255,c=3,t=12,pt=0,l=3,sg=0,ft=0,st=OK:1.1
25710 SGN:SGN:NREQ=0
25714 TSF:MSG:SEND,15-15-0-0,s=0,c=0,t=8,pt=0,l=0,sg=0,ft=0,st=OK:
25720 SGN:SGN:NREQ=0
25724 TSF:MSG:SEND,15-15-0-0,s=1,c=0,t=6,pt=0,l=0,sg=0,ft=0,st=OK:
25733 SGN:SGN:NREQ=0
25737 TSF:MSG:SEND,15-15-0-0,s=2,c=0,t=13,pt=0,l=0,sg=0,ft=0,st=OK:
25743 MCO:REG:REQ
25745 SGN:SGN:NREQ=0
25749 TSF:MSG:SEND,15-15-0-0,s=255,c=3,t=26,pt=1,l=1,sg=0,ft=0,st=OK:2
25778 TSF:MSG:READ,0-0-15,s=255,c=3,t=16,pt=0,l=0,sg=1:
25784 SGN:SKP:MSG CMD=3,TYPE=16
25815 SGN:SGN:NREQ=0
25821 TSF:MSG:SEND,15-15-0-0,s=255,c=3,t=17,pt=6,l=25,sg=0,ft=0,st=OK:<NONCE>
25829 SGN:NCE:XMT,TO=15
26525 TSF:MSG:READ,0-0-15,s=255,c=3,t=27,pt=1,l=1,sg=1:1
26531 SGN:BND:NONCE=36CD915905040CCA50C73BDC3705A78E00174DBA190337E9B7AAAAAAAAAAAAAA
26699 SGN:BND:HMAC=130F6AB799336E062C72BBADFF4CEB7BE2A1B62B898162A489703804F493379F
26710 !SGN:VER:FAIL
26712 !TSF:MSG:SIGN VERIFY FAIL
26714 MCO:BGN:STP
Pressure Sensor BMP280 1.1

Personalisation has been re-done for both GW and nodes.
GW - Sensebender W5100
Node above - atmega328p

[Anticimex]

@alexsh1 can you show the log from startup?

[alexsh1]

@anticimex

Yes, please see below:

 
 __  __       ____
|  \/  |_   _/ ___|  ___ _ __  ___  ___  _ __ ___
| |\/| | | | \___ \ / _ \ `_ \/ __|/ _ \| `__/ __|
| |  | | |_| |___| |  __/ | | \__ \  _  | |  \__ \
|_|  |_|\__, |____/ \___|_| |_|___/\___/|_|  |___/
        |___/                      2.2.0

16 MCO:BGN:INIT NODE,CP=RNNNAS--,VER=2.2.0
71 SGN:PER:OK
96 SGN:INI:BND OK
98 TSM:INIT
100 TSF:WUR:MS=0
106 TSM:INIT:TSP OK
108 TSM:INIT:STATID=15
112 TSF:SID:OK,ID=15
114 TSM:FPAR
114 SGN:SGN:NREQ=255
153 TSF:MSG:SEND,15-15-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK:
403 TSF:MSG:READ,0-0-15,s=255,c=3,t=8,pt=1,l=1,sg=0:0
409 SGN:SKP:MSG CMD=3,TYPE=8
411 TSF:MSG:FPAR OK,ID=0,D=1
503 TSF:MSG:READ,11-11-15,s=255,c=3,t=8,pt=1,l=1,sg=0:1
509 SGN:SKP:MSG CMD=3,TYPE=8
2160 TSM:FPAR:OK
2160 TSM:ID
2162 TSM:ID:OK
2164 TSM:UPL
2166 SGN:SGN:NREQ=0
2170 TSF:MSG:SEND,15-15-0-0,s=255,c=3,t=24,pt=1,l=1,sg=0,ft=0,st=OK:1
2205 TSF:MSG:READ,0-0-15,s=255,c=3,t=25,pt=1,l=1,sg=0:1
2211 SGN:SKP:MSG CMD=3,TYPE=25
2215 TSF:MSG:PONG RECV,HP=1
2217 TSM:UPL:OK
2220 TSM:READY:ID=15,PAR=0,DIS=1
2224 SGN:PRE:SGN REQ
2226 SGN:PRE:WHI NREQ
2228 SGN:SGN:NREQ=0
2232 TSF:MSG:SEND,15-15-0-0,s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=OK:0101
2240 SGN:PRE:XMT,TO=0
2242 SGN:PRE:WAIT GW
2314 TSF:MSG:READ,0-0-15,s=255,c=3,t=15,pt=6,l=2,sg=0:0100
2320 SGN:SKP:MSG CMD=3,TYPE=15
2324 SGN:SGN:NREQ=0
2328 TSF:MSG:SEND,15-15-0-0,s=255,c=0,t=17,pt=0,l=5,sg=0,ft=0,st=OK:2.2.0
2336 SGN:SGN:NREQ=0
2340 TSF:MSG:SEND,15-15-0-0,s=255,c=3,t=6,pt=1,l=1,sg=0,ft=0,st=OK:0
4347 SGN:SGN:NREQ=0
4352 TSF:MSG:SEND,15-15-0-0,s=255,c=3,t=11,pt=0,l=22,sg=0,ft=0,st=OK:BMP280 Pressure Sensor
4362 SGN:SGN:NREQ=0
4366 TSF:MSG:SEND,15-15-0-0,s=255,c=3,t=12,pt=0,l=3,sg=0,ft=0,st=OK:1.1
4374 SGN:SGN:NREQ=0
4378 TSF:MSG:SEND,15-15-0-0,s=0,c=0,t=8,pt=0,l=0,sg=0,ft=0,st=OK:
4384 SGN:SGN:NREQ=0
4390 TSF:MSG:SEND,15-15-0-0,s=1,c=0,t=6,pt=0,l=0,sg=0,ft=0,st=OK:
4399 SGN:SGN:NREQ=0
4403 TSF:MSG:SEND,15-15-0-0,s=2,c=0,t=13,pt=0,l=0,sg=0,ft=0,st=OK:
4409 MCO:REG:REQ
4411 SGN:SGN:NREQ=0
4415 TSF:MSG:SEND,15-15-0-0,s=255,c=3,t=26,pt=1,l=1,sg=0,ft=0,st=OK:2
4442 TSF:MSG:READ,0-0-15,s=255,c=3,t=16,pt=0,l=0,sg=1:
4448 SGN:SKP:MSG CMD=3,TYPE=16
4478 SGN:SGN:NREQ=0
4485 TSF:MSG:SEND,15-15-0-0,s=255,c=3,t=17,pt=6,l=25,sg=0,ft=0,st=OK:<NONCE>
4493 SGN:NCE:XMT,TO=15
5181 TSF:MSG:READ,0-0-15,s=255,c=3,t=27,pt=1,l=1,sg=1:1
5187 SGN:BND:NONCE=3564FB9604A41E9487597BD96E22963F777D68B86F5BD036D5AAAAAAAAAAAAAA
5355 SGN:BND:HMAC=9E920342D7EC661149B9A58C9091CA252E607E2436229564764CBE4778F8BBE4
5363 !SGN:VER:FAIL
5365 !TSF:MSG:SIGN VERIFY FAIL
5369 MCO:BGN:STP
Pressure Sensor BMP280 1.1

[Anticimex]

@alexsh1 looks like a textbook example where sender and receiver disagree on what hmac key to use.

[alexsh1]

@anticimex Interesting. I am using the same HMAC key on both Sensebender GW and atmega328p.

No problem if I swap the gateway for Mega.

[alexsh1]

@anticimex GW has got a lot of these:

!SGN:NCE:GEN

[Anticimex]

@alexsh1 that indicate nonce generation fails. If you use soft signing it means the backend is not initialized.
If it is not, it is indicating checksum failed. This should be visible in the early init messages.
If you use atsha, it could indicate a dodgy device communication.

[alexsh1]

@anticimex Sensebender GW has got ATSHA204
A few of my nodes do have ATSHA204 as well
And a few others soft signing

All of them fail after clearing eeprom and new personalisation with the same HMAC

I understand the problem is the Sensebender
Could it be a timing issue on Sensebender GW (SAMD21)?

[Anticimex]

@alexsh1 if it is, it is new to me. SenseBender gw has been tested with signing. Perhaps @tbowmo might know if something changed in processor frequency on 2.2 that might affect timings in the atsha driver.

[alexsh1]

@anticimex

This is the GW log:

8858 TSF:MSG:READ,15-15-255,s=255,c=3,t=7,pt=0,l=0,sg=0:
18868 TSF:MSG:BC
18878 TSF:MSG:FPAR REQ,ID=15
18888 TSF:PNG:SEND,TO=0
18898 TSF:CKU:OK
18908 TSF:MSG:GWL OK
19394 SGN:SKP:MSG CMD=3,TYPE=8
19406 TSF:MSG:SEND,0-0-15-15,s=255,c=3,t=8,pt=1,l=1,sg=0,ft=0,st=OK:0
19416 TSF:MSG:READ,11-11-0,s=255,c=3,t=24,pt=1,l=1,sg=0:1
19426 TSF:MSG:PINGED,ID=11,HP=1
19441 SGN:SGN:NREQ=11
19453 TSF:MSG:SEND,0-0-11-11,s=255,c=3,t=25,pt=1,l=1,sg=0,ft=0,st=OK:1
24492 TSF:MSG:READ,15-15-255,s=255,c=3,t=7,pt=0,l=0,sg=0:
24502 TSF:MSG:BC
24512 TSF:MSG:FPAR REQ,ID=15
24522 TSF:CKU:OK,FCTRL
24532 TSF:MSG:GWL OK
25522 SGN:SKP:MSG CMD=3,TYPE=8
25534 TSF:MSG:SEND,0-0-15-15,s=255,c=3,t=8,pt=1,l=1,sg=0,ft=0,st=OK:0
26544 TSF:MSG:READ,15-15-0,s=255,c=3,t=24,pt=1,l=1,sg=0:1
26554 TSF:MSG:PINGED,ID=15,HP=1
26569 SGN:SKP:MSG CMD=3,TYPE=25
26581 TSF:MSG:SEND,0-0-15-15,s=255,c=3,t=25,pt=1,l=1,sg=0,ft=0,st=OK:1
26591 TSF:MSG:READ,6-6-0,s=1,c=3,t=16,pt=0,l=0,sg=1:
26601 !SGN:NCE:GEN
26611 TSF:MSG:READ,15-15-0,s=255,c=3,t=15,pt=6,l=2,sg=0:0101
26621 SGN:PRE:SGN REQ,FROM=15
26663 SGN:PRE:SGN NREQ,TO=15
26673 SGN:PRE:WHI NREQ,TO=15
26683 SGN:SKP:MSG CMD=3,TYPE=15
26695 TSF:MSG:SEND,0-0-15-15,s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=OK:0100
26705 SGN:PRE:XMT,TO=15
26715 TSF:MSG:READ,15-15-0,s=255,c=0,t=17,pt=0,l=5,sg=0:2.2.0
26725 TSF:MSG:READ,15-15-0,s=255,c=3,t=6,pt=1,l=1,sg=0:0
28734 TSF:MSG:READ,15-15-0,s=255,c=3,t=11,pt=0,l=22,sg=0:BMP280 Pressure Sensor
28748 TSF:MSG:READ,15-15-0,s=255,c=3,t=12,pt=0,l=3,sg=0:1.1
28760 TSF:MSG:READ,15-15-0,s=0,c=0,t=8,pt=0,l=0,sg=0:
28771 TSF:MSG:READ,15-15-0,s=1,c=0,t=6,pt=0,l=0,sg=0:
28782 TSF:MSG:READ,15-15-0,s=2,c=0,t=13,pt=0,l=0,sg=0:
28795 TSF:MSG:READ,15-15-0,s=255,c=3,t=26,pt=1,l=1,sg=0:2
28810 SGN:SKP:MSG CMD=3,TYPE=16
28822 TSF:MSG:SEND,0-0-15-15,s=255,c=3,t=16,pt=0,l=0,sg=0,ft=0,st=OK:
28832 SGN:SGN:NCE REQ,TO=15
28864 TSF:MSG:READ,15-15-0,s=255,c=3,t=17,pt=6,l=25,sg=0:<NONCE>
28874 SGN:NCE:FROM=15
28884 SGN:BND:NONCE=0000000000000000000000000000000000000000000000000000000000000000
29514 SGN:BND:HMAC=0000000000000000000000000000000000000000000000000000000000000000
29524 SGN:SGN:SGN

Something is just wrong - there are all zeros
I'll check once again the sketch and schematic.

[alexsh1]

@anticimex

I had to comment out this line

#define MY_SIGNING_ATSHA204_PIN   17

For SAMD21 it is connected to 20 (PA11) -> this corresponds to D0 arduino

However, the node still gives me a pain:

 
 __  __       ____
|  \/  |_   _/ ___|  ___ _ __  ___  ___  _ __ ___
| |\/| | | | \___ \ / _ \ `_ \/ __|/ _ \| `__/ __|
| |  | | |_| |___| |  __/ | | \__ \  _  | |  \__ \
|_|  |_|\__, |____/ \___|_| |_|___/\___/|_|  |___/
        |___/                      2.3.0-alpha

18 MCO:BGN:INIT NODE,CP=RNNNAS--,VER=2.3.0-alpha
73 SGN:PER:OK
106 SGN:INI:BND OK
108 TSM:INIT
108 TSF:WUR:MS=0
116 TSM:INIT:TSP OK
118 TSM:INIT:STATID=15
120 TSF:SID:OK,ID=15
122 TSM:FPAR
124 SGN:SGN:NREQ=255
161 TSF:MSG:SEND,15-15-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK:
561 TSF:MSG:READ,11-11-15,s=255,c=3,t=8,pt=1,l=1,sg=0:1
567 SGN:SKP:MSG CMD=3,TYPE=8
571 TSF:MSG:FPAR OK,ID=11,D=2
778 TSF:MSG:READ,0-0-15,s=255,c=3,t=8,pt=1,l=1,sg=0:0
784 SGN:SKP:MSG CMD=3,TYPE=8
788 TSF:MSG:FPAR OK,ID=0,D=1
2170 TSM:FPAR:OK
2170 TSM:ID
2172 TSM:ID:OK
2174 TSM:UPL
2177 SGN:SGN:NREQ=0
2181 TSF:MSG:SEND,15-15-0-0,s=255,c=3,t=24,pt=1,l=1,sg=0,ft=0,st=OK:1
2215 TSF:MSG:READ,0-0-15,s=255,c=3,t=25,pt=1,l=1,sg=0:1
2222 SGN:SKP:MSG CMD=3,TYPE=25
2226 TSF:MSG:PONG RECV,HP=1
2228 TSM:UPL:OK
2230 TSM:READY:ID=15,PAR=0,DIS=1
2234 SGN:PRE:SGN REQ
2236 SGN:PRE:WHI NREQ
2238 SGN:SGN:NREQ=0
2252 TSF:MSG:SEND,15-15-0-0,s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=OK:0101
2260 SGN:PRE:XMT,TO=0
2263 SGN:PRE:WAIT GW
2342 TSF:MSG:READ,0-0-15,s=255,c=3,t=15,pt=6,l=2,sg=0:0100
2349 SGN:SKP:MSG CMD=3,TYPE=15
2353 SGN:SGN:NREQ=0
2379 TSF:MSG:SEND,15-15-0-0,s=255,c=0,t=17,pt=0,l=11,sg=0,ft=0,st=OK:2.3.0-alpha
2387 SGN:SGN:NREQ=0
2392 TSF:MSG:SEND,15-15-0-0,s=255,c=3,t=6,pt=1,l=1,sg=0,ft=0,st=OK:0
4401 SGN:SGN:NREQ=0
4405 TSF:MSG:SEND,15-15-0-0,s=255,c=3,t=11,pt=0,l=22,sg=0,ft=0,st=OK:BMP280 Pressure Sensor
4415 SGN:SGN:NREQ=0
4419 TSF:MSG:SEND,15-15-0-0,s=255,c=3,t=12,pt=0,l=3,sg=0,ft=0,st=OK:1.1
4427 SGN:SGN:NREQ=0
4431 TSF:MSG:SEND,15-15-0-0,s=0,c=0,t=8,pt=0,l=0,sg=0,ft=0,st=OK:
4438 SGN:SGN:NREQ=0
4442 TSF:MSG:SEND,15-15-0-0,s=1,c=0,t=6,pt=0,l=0,sg=0,ft=0,st=OK:
4450 SGN:SGN:NREQ=0
4452 TSF:MSG:SEND,15-15-0-0,s=2,c=0,t=13,pt=0,l=0,sg=0,ft=0,st=OK:
4460 MCO:REG:REQ
4462 SGN:SGN:NREQ=0
4466 TSF:MSG:SEND,15-15-0-0,s=255,c=3,t=26,pt=1,l=1,sg=0,ft=0,st=OK:2
4493 TSF:MSG:READ,0-0-15,s=255,c=3,t=16,pt=0,l=0,sg=1:
4499 SGN:SKP:MSG CMD=3,TYPE=16
4530 SGN:SGN:NREQ=0
4542 TSF:MSG:SEND,15-15-0-0,s=255,c=3,t=17,pt=6,l=25,sg=0,ft=0,st=OK:<NONCE>
4550 SGN:NCE:XMT,TO=15
6475 SGN:SGN:NREQ=0
6477 TSF:MSG:SEND,15-15-0-0,s=255,c=3,t=26,pt=1,l=1,sg=0,ft=0,st=OK:2
6506 TSF:MSG:READ,0-0-15,s=255,c=3,t=16,pt=0,l=0,sg=1:
6512 SGN:SKP:MSG CMD=3,TYPE=16
6543 SGN:SGN:NREQ=0
6553 TSF:MSG:SEND,15-15-0-0,s=255,c=3,t=17,pt=6,l=25,sg=0,ft=0,st=OK:<NONCE>
6563 SGN:NCE:XMT,TO=15
8486 SGN:SGN:NREQ=0
8488 TSF:MSG:SEND,15-15-0-0,s=255,c=3,t=26,pt=1,l=1,sg=0,ft=0,st=OK:2
8515 TSF:MSG:READ,0-0-15,s=255,c=3,t=16,pt=0,l=0,sg=1:
8521 SGN:SKP:MSG CMD=3,TYPE=16
8554 SGN:SGN:NREQ=0
8564 TSF:MSG:SEND,15-15-0-0,s=255,c=3,t=17,pt=6,l=25,sg=0,ft=0,st=OK:<NONCE>
8572 SGN:NCE:XMT,TO=15
10498 SGN:SGN:NREQ=0
10502 TSF:MSG:SEND,15-15-0-0,s=255,c=3,t=26,pt=1,l=1,sg=0,ft=0,st=OK:2
10528 TSF:MSG:READ,0-0-15,s=255,c=3,t=16,pt=0,l=0,sg=1:
10534 SGN:SKP:MSG CMD=3,TYPE=16
10565 SGN:SGN:NREQ=0
10577 TSF:MSG:SEND,15-15-0-0,s=255,c=3,t=17,pt=6,l=25,sg=0,ft=0,st=OK:<NONCE>
10586 SGN:NCE:XMT,TO=15
11448 TSF:MSG:READ,0-0-15,s=255,c=3,t=16,pt=0,l=0,sg=1:
11454 SGN:SKP:MSG CMD=3,TYPE=16
11487 SGN:SGN:NREQ=0
11501 TSF:MSG:SEND,15-15-0-0,s=255,c=3,t=17,pt=6,l=25,sg=0,ft=0,st=OK:<NONCE>
11509 SGN:NCE:XMT,TO=15
12509 MCO:BGN:STP
Pressure Sensor BMP280 1.1

[alexsh1]

All other nodes are working fine with singing so the problem was incorrect reference to atsha204's pin on the GW. I'll debug the node above tomorrow

[Anticimex]

Alright. That is at least some progress. Just from the latest log I don't see anything going terribly wrong at the node side. But it perhaps hangs at that point? Could be a stack issue.

[alexsh1]

@anticimex It is working now. It was one of those late night issues. In the morning it started working like a charm! (I bet it won't be able to replicate it). Thank you for your help.

Also a good lesson for me. A working sketch for an AVR may or may not work for ARM. Extra attention required for defining pins etc.

On a different note FYI, I was struggling to clear EEPROM on my Sensebender GW.
See this https://forum.mysensors.org/topic/8814/cleareprom-does-not-work-for-sensebender-gw/9

[Anticimex]

@alexsh1 nice to hear :)