@anticimex I would say you are right, signing does not seem to have anything to do with the FOTA problems I'm having. I've kept on try the last few hours and all I can say by now is that the firmware upload over the air works ... sometimes. Also rebooting the gateway seems to increase the probability for success. This is getting a little frustrating right now. Anyway, thanks again for your help with signing!

As for the documentation, I'm not very good at that myself. One thing I would suggest is breaking it up into smaller chunks. For example, separate the theoretical background from the technical documentation. Create smaller how-tos for single use cases, e.g. cover soft and ATSHA204 based signing separately. It could also help to state the library version explicitly that each part of the documentation is referring to.

That's probably not much help, but hopefully at least a little constructive.

@anticimex I have configured both devices using the personalization sketch now, and message signing is working perfectly with version 2.1.1! Unfortunately though, this seems to break FOTA again for me. Do you know if this could that actually be related to using message signing?

These are the first lines I see on the gateway after I reset the node that I would expect to get a new firmware over the air:

0;255;3;0;9;TSF:MSG:READ,4-4-255,s=255,c=3,t=7,pt=1,l=1,sg=0:0
0;255;3;0;9;TSF:MSG:BC
0;255;3;0;9;TSF:MSG:FPAR REQ,ID=4
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;Skipping security for command 3 type 8
0;255;3;0;9;TSF:MSG:SEND,0-0-4-4,s=255,c=3,t=8,pt=1,l=1,sg=1,ft=0,st=OK:0
0;255;3;0;9;TSF:MSG:READ,4-4-255,s=255,c=3,t=7,pt=1,l=1,sg=0:0
0;255;3;0;9;TSF:MSG:BC
0;255;3;0;9;TSF:MSG:FPAR REQ,ID=4
0;255;3;0;9;TSF:CKU:OK,FCTRL
0;255;3;0;9;TSF:MSG:GWL OK
0;255;3;0;9;Skipping security for command 3 type 8
0;255;3;0;9;TSF:MSG:SEND,0-0-4-4,s=255,c=3,t=8,pt=1,l=1,sg=1,ft=0,st=OK:0
0;255;3;0;9;TSF:MSG:READ,4-4-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=4
0;255;3;0;9;TSF:CKU:OK,FCTRL
0;255;3;0;9;TSF:MSG:GWL OK
0;255;3;0;9;Skipping security for command 3 type 8

And I'd like to say that I appreciate the awesome work you are doing here very much! I really try to read and understand the documentation, but in some places it is not that easy to follow.

@anticimex I will. Right now I'm not sure though, what is actually causing the problem. It might be the library, the bootloader, the controller (MyController), or my general lack of expertise on the topic...

@anticimex Thank you very much for your quick response! I didn't realize that the simple password option was not supported in version 2.1.1. Since FOTA doesn't seem to work for me in version 2.2.0 I'll try personalizing my nodes instead, tonight.

Oh, I forgot to add that I already tried erasing the EEPROM on both devices but that didn't help either.

Hi,
For a few days now I've been trying to get my test-setup to work. I am using a NodeMCU Wifi MQTT gateway connected to my Mosquitto server and a single Arduino pro mini node, both with NRF24 radios. The node is supposed to be updated over the air later on, so I installed the latest MYSBootloader.

I had almost everything up an running 2 days ago including message signing. The only problem remaining was, that while FOTA updates were working, serial firmware uploads through the Arduino IDE were failing. I was able to solve this by compiling the bootloader for a reduced upload speed and at the same time upgraded gateway and node from library version 2.1.1 to 2.2. As it turned out, with version 2.2 over-the-air updates were no longer working. So I downgraded both nodes to version 2.1.1 which fixed FOTA for me.

Unfortunately, message signing seems to be broken now. This is the debug output from the node:

5656 MCO:SLP:WUP=-1
+++ request 
5660 Will not sign message for destination 0 as it does not require it
5668 TSF:MSG:SEND,4-4-0-0,s=1,c=2,t=36,pt=0,l=0,sg=0,ft=0,st=OK:
5677 MCO:SLP:MS=3000,SMS=1,I1=255,M1=255,I2=255,M2=255
5683 Will not sign message for destination 0 as it does not require it
5691 TSF:MSG:SEND,4-4-0-0,s=255,c=3,t=22,pt=5,l=4,sg=0,ft=0,st=OK:1520
5937 TSF:MSG:READ,0-0-4,s=1,c=3,t=16,pt=0,l=0,sg=1:
5943 Skipping security for command 3 type 16
SHA256: 118E8C33213D6E353FDF26D2B28D84A5D745CFE2F099D3B2B4AAAAAAAAAAAAAA
5976 Will not sign message for destination 0 as it does not require it
5992 TSF:MSG:SEND,4-4-0-0,s=255,c=3,t=17,pt=6,l=25,sg=0,ft=0,st=OK:118E8C33213D6E353FDF26D2B28D84A5D745CFE2F099D3B2B4
6004 Transmitted nonce
6141 TSF:MSG:READ,0-0-4,s=1,c=1,t=36,pt=0,l=1,sg=1:1
Signature in message: 019753BF095A75BF7ED5A2A7CAE4ECDEBC916EFDF06B044A
Message to process: 00040E01240131
Current nonce: 118E8C33213D6E353FDF26D2B28D84A5D745CFE2F099D3B2B4AAAAAAAAAAAAAA
HMAC: 215BD88BE0543189561A6FCE26ADFAB61E8CF6C6EB2E16BBD514BD506C55082D
Signature bad: 015BD88BE0543189561A6FCE26ADFAB61E8CF6C6EB2E16BB
6324 Signature verification failed!
6334 !TSF:MSG:SIGN VERIFY FAIL
6400 MCO:SLP:TPD

This is the corresponding output on the gateway:

0;255;3;0;9;TSF:MSG:READ,4-4-0,s=1,c=2,t=36,pt=0,l=0,sg=0:
0;255;3;0;9;Sending message on topic: gateway1-out/4/1/2/0/36
0;255;3;0;9;TSF:MSG:READ,4-4-0,s=255,c=3,t=22,pt=5,l=4,sg=0:1520
0;255;3;0;9;Sending message on topic: gateway1-out/4/255/3/0/22
0;255;3;0;9;Message arrived on topic: gateway1-in/4/1/1/0/36
0;255;3;0;9;Skipping security for command 3 type 16
0;255;3;0;9;TSF:MSG:SEND,0-0-4-4,s=1,c=3,t=16,pt=0,l=0,sg=1,ft=0,st=OK:
0;255;3;0;9;Nonce requested from 4. Waiting...
0;255;3;0;9;TSF:MSG:READ,4-4-0,s=255,c=3,t=17,pt=6,l=25,sg=0:118E8C33213D6E353FDF26D2B28D84A5D745CFE2F099D3B2B4
0;255;3;0;9;Nonce received from 4.
0;255;3;0;9;Proceeding with signing...
0;255;3;0;9;Message to process: 00040E01240131
0;255;3;0;9;Current nonce: 118E8C33213D6E353FDF26D2B28D84A5D745CFE2F099D3B2B4AAAAAAAAAAAAAA
0;255;3;0;9;HMAC: 959753BF095A75BF7ED5A2A7CAE4ECDEBC916EFDF06B044ACD49D19B741939C4
0;255;3;0;9;Signature in message: 019753BF095A75BF7ED5A2A7CAE4ECDEBC916EFDF06B044A
0;255;3;0;9;Message signed
0;255;3;0;9;Message to send has been signed
0;255;3;0;9;TSF:MSG:SEND,0-0-4-4,s=1,c=1,t=36,pt=0,l=1,sg=1,ft=0,st=OK:1

Config on the node:

#define MY_SMART_SLEEP_WAIT_DURATION_MS (700ul)
#define MY_DEBUG_VERBOSE_SIGNING //!< Enable signing related debug prints to serial monitor
#define MY_SIGNING_SOFT //!< Software signing
#define MY_SIGNING_SOFT_RANDOMSEED_PIN 7 //!< Unconnected analog pin for random seed
#define MY_SIGNING_REQUEST_SIGNATURES
#define MY_SIGNING_SIMPLE_PASSWD "mysecretpw"

Config on the gateway:

#define MY_DEBUG_VERBOSE_SIGNING //!< Enable signing related debug prints to serial monitor
#define MY_SIGNING_SOFT //!< Software signing
#define MY_SIGNING_SOFT_RANDOMSEED_PIN 7 //!< Unconnected analog pin for random seed
#define MY_SIGNING_SIMPLE_PASSWD "mysecretpw"

Any hint or help would be greatly appreciated!

Best regards,
Christian

Ok, now I'm seeing items in my Inbox, after I changed my org.eclipse.smarthome.mqtt.cfg from

ineluki.qos=2
ineluki.retain=true

to

#ineluki.qos=2
ineluki.retain=false

Unfortunately, I'm still making no progress here. In the meantime I deleted the MQTT Gateway in the Paper UI and restarted the device to see what would happen. Now I'm seeing an error in openhab.log:

2018-01-16 19:45:23.419 [INFO ] [.transport.mqtt.MqttBrokerConnection] - Starting MQTT broker connection 'ineluki' to 'tcp://192.168.5.2:1883' with clientid openhab2 and file store '/openhab/userdata/tmp/ineluki'
2018-01-16 19:45:29.680 [INFO ] [.transport.mqtt.MqttBrokerConnection] - MQTT connection to 'ineluki' was lost: MqttException
2018-01-16 19:45:29.681 [ERROR] [rotocol.mqtt.MySensorsMqttConnection] - MQTT connection offline - {}
org.eclipse.paho.client.mqttv3.MqttException: MqttException
        at org.eclipse.paho.client.mqttv3.internal.CommsCallback.run(CommsCallback.java:176) [211:org.eclipse.paho.client.mqttv3:1.0.2]
        at java.lang.Thread.run(Thread.java:748) [?:?]
Caused by: java.lang.NullPointerException
        at org.openhab.binding.mysensors.internal.protocol.mqtt.MySensorsMqttConnection$MySensorsMqttSubscriber.processMessage(MySensorsMqttConnection.java:142) ~[?:?]
        at org.eclipse.smarthome.io.transport.mqtt.MqttBrokerConnection$ClientCallbacks.messageArrived(MqttBrokerConnection.java:121) ~[?:?]
        at org.eclipse.paho.client.mqttv3.internal.CommsCallback.handleMessage(CommsCallback.java:354) ~[?:?]
        at org.eclipse.paho.client.mqttv3.internal.CommsCallback.run(CommsCallback.java:162) ~[?:?]
        ... 1 more
2018-01-16 19:45:29.709 [INFO ] [.reconnect.PeriodicReconnectStrategy] - Try to restore connection to 'ineluki' every 10000ms

Does this give any clue on what's going wrong?

@TimO
Ok, I've restarted the sensor multiple times now and I assume that it presents itself properly as it is discovered by other controllers (mycontroller.org, that is). But in OpenHAB's PaperUI it doesn't show up at all. There is a trace of it in the openhab.log though:

2018-01-10 09:29:39.268 [WARN ] [al.sensors.child.MySensorsChildSTemp] - Overwrite variable: V_VAR1
2018-01-10 09:29:39.269 [WARN ] [al.sensors.child.MySensorsChildSTemp] - Overwrite variable: V_VAR2
2018-01-10 09:29:39.277 [WARN ] [al.sensors.child.MySensorsChildSTemp] - Overwrite variable: V_VAR3
2018-01-10 09:29:39.289 [WARN ] [al.sensors.child.MySensorsChildSTemp] - Overwrite variable: V_VAR4
2018-01-10 09:29:39.289 [WARN ] [al.sensors.child.MySensorsChildSTemp] - Overwrite variable: V_VAR5
2018-01-10 20:38:26.959 [WARN ] [nal.sensors.child.MySensorsChildSHum] - Overwrite variable: V_VAR1
2018-01-10 20:38:26.980 [WARN ] [nal.sensors.child.MySensorsChildSHum] - Overwrite variable: V_VAR2
2018-01-10 20:38:26.980 [WARN ] [nal.sensors.child.MySensorsChildSHum] - Overwrite variable: V_VAR3
2018-01-10 20:38:26.980 [WARN ] [nal.sensors.child.MySensorsChildSHum] - Overwrite variable: V_VAR4
2018-01-10 20:38:26.981 [WARN ] [nal.sensors.child.MySensorsChildSHum] - Overwrite variable: V_VAR5
2018-01-10 20:38:27.084 [WARN ] [sors.child.MySensorsChildSMultimeter] - Overwrite variable: V_VAR1
2018-01-10 20:38:27.086 [WARN ] [sors.child.MySensorsChildSMultimeter] - Overwrite variable: V_VAR2
2018-01-10 20:38:27.086 [WARN ] [sors.child.MySensorsChildSMultimeter] - Overwrite variable: V_VAR3
2018-01-10 20:38:27.088 [WARN ] [sors.child.MySensorsChildSMultimeter] - Overwrite variable: V_VAR4
2018-01-10 20:38:27.089 [WARN ] [sors.child.MySensorsChildSMultimeter] - Overwrite variable: V_VAR5
2018-01-10 20:39:10.530 [WARN ] [rs.internal.gateway.MySensorsGateway] - Presented child is alredy present in gateway
2018-01-10 20:39:11.529 [WARN ] [rs.internal.gateway.MySensorsGateway] - Presented child is alredy present in gateway
2018-01-10 20:39:11.660 [WARN ] [rs.internal.gateway.MySensorsGateway] - Presented child is alredy present in gateway
2018-01-10 20:40:58.584 [WARN ] [rs.internal.gateway.MySensorsGateway] - Presented child is alredy present in gateway
2018-01-10 20:40:59.461 [WARN ] [rs.internal.gateway.MySensorsGateway] - Presented child is alredy present in gateway
2018-01-10 20:40:59.592 [WARN ] [rs.internal.gateway.MySensorsGateway] - Presented child is alredy present in gateway

While this is happening on MQTT:

gateway1-out/3/255/0/0/17 2.1.1
gateway1-out/3/255/3/0/6 0
gateway1-out/3/255/3/0/11 Combined Climate Sensor
gateway1-out/3/255/3/0/12 1.0.16
gateway1-out/3/0/0/0/7 (null)
gateway1-out/3/7/0/0/30 (null)
gateway1-out/3/10/2/0/15 (null)
gateway1-out/3/1/1/0/0 21.9
gateway1-out/3/0/1/0/1 42
gateway1-out/3/7/1/0/38 3.98
gateway1-out/3/255/3/0/0 56

Have you got another hint for me, maybe? It would be greatly appreciated.

@timo said in openHAB 2.2 binding MQTT support:

My guess: the file org.eclipse.smarthome.mqtt.cfg is missing

Excellent guess, that was my problem! My gateway is "online" now. It would have taken me forever to figure that out on my own, so thank you very much! (And yes, reading your first post now I realize that you said so.)

Should OpenHAB be able to discover the sensors behind the gateway? Or do I need to configure them manually?