sparkfun / SparkFun_u-blox_SARA-R5_Arduino_Library

An Arduino library for the u-blox SARA-R5 LTE-M / NB-IoT modules with secure cloud
Other
14 stars 11 forks source link

Sparkfun AssetTracker: MQTT problem when connecting through LTE modem #50

Closed Davefries1966 closed 3 months ago

Davefries1966 commented 3 months ago

Hi all, As per previous related issues, I purchased a Sparkfun AssetTracker development kit with MicroMod ESP32 add-on, LTE/GNSS antennas and so on.

I developed an application which connects to a MOSQUITTO broker on port 8883 (in TLS/SSL mode) and sends some topics to it. All works flawlessly when connecting to the MOSQUITTO test broker (test.mosquitto.org:8883) with both wifi and LTE connection.

Then I installed my MOSQUITTO broker on a remote server controlled by me (with public static IP 2.XXX.XXX.XXX) and certificates generated by me through OpenSSL. The MQTT connection runs ok when using wifi connection (library PubSubClient) while the problem occurs when using LTE.

I can say that same certificates work when using MQTT client as MQTTX or MQTT EXPLORER connecting to the same broker 2.XXX.XXX.XXX:8883.

I could verify that the source code written to set the modem and launch the MQTT connection works fine (result is always ok for each instruction). This is the code (which I had found as sample code around there):

setMQTTCommandCallback(mqttCallback);
...
setSecurityManager(SARA_R5_SEC_MANAGER_OPCODE_IMPORT, SARA_R5_SEC_MANAGER_ROOTCA, SEC_ROOT_CA, rootCa);
setSecurityManager(SARA_R5_SEC_MANAGER_OPCODE_IMPORT, SARA_R5_SEC_MANAGER_CLIENT_CERT, SEC_CLIENT_CERT, cert);
setSecurityManager(SARA_R5_SEC_MANAGER_OPCODE_IMPORT, SARA_R5_SEC_MANAGER_CLIENT_KEY, SEC_CLIENT_KEY, key);
resetSecurityProfile(LTE_SEC_PROFILE_MQTT);
configSecurityProfile(LTE_SEC_PROFILE_MQTT, SARA_R5_SEC_PROFILE_PARAM_CERT_VAL_LEVEL, SARA_R5_SEC_PROFILE_CERTVAL_OPCODE_YESNOURL);
configSecurityProfile(LTE_SEC_PROFILE_MQTT, SARA_R5_SEC_PROFILE_PARAM_TLS_VER, SARA_R5_SEC_PROFILE_TLS_OPCODE_VER1_2);
configSecurityProfile(LTE_SEC_PROFILE_MQTT, SARA_R5_SEC_PROFILE_PARAM_CYPHER_SUITE, SARA_R5_SEC_PROFILE_SUITE_OPCODE_PROPOSEDDEFAULT);
configSecurityProfileString(LTE_SEC_PROFILE_MQTT, SARA_R5_SEC_PROFILE_PARAM_ROOT_CA, SEC_ROOT_CA);
configSecurityProfileString(LTE_SEC_PROFILE_MQTT, SARA_R5_SEC_PROFILE_PARAM_CLIENT_CERT, SEC_CLIENT_CERT);
configSecurityProfileString(LTE_SEC_PROFILE_MQTT, SARA_R5_SEC_PROFILE_PARAM_CLIENT_KEY, SEC_CLIENT_KEY);
configSecurityProfileString(LTE_SEC_PROFILE_MQTT, SARA_R5_SEC_PROFILE_PARAM_SNI, broker);
setMQTTclientId(id);
setMQTTserver(broker, MQTT_BROKER_PORT);
setMQTTsecure(true, LTE_SEC_PROFILE_MQTT);
setMQTTcredentials(userName, passWord);
connectMQTT();

...

All above instructions return SARA_R5_error_t=0 (success). But when calling getMQTTprotocolError() inside mqttCallback(), I got an error on command SARA_R5_MQTT_COMMAND_LOGIN (command=1) with error codes 13 and 8. According to SARA R5 AT commands documentation, the error code = 8 says "Cannot set secure socket".

This is the source code:

...
void mqttCallback(int command, int result) {
    if (result == 0) {
      int code1, code2;
      SARA_R5_error_t err = getMQTTprotocolError(&code1, &code2);
      if (SARA_R5_SUCCESS == err) {
        log_e("command %d protocol error code1 %d code2 %d", command, code1, code2);
      } else {
        log_e("command %d protocol error failed with error", command, err);
      }
    } 
...

This is the output:

15:44:16.186 ---> mqttCallback(): command 1 protocol error code1 13 code2 8

I tried also to comment the following line:

configSecurityProfileString(LTE_SEC_PROFILE_MQTT, SARA_R5_SEC_PROFILE_PARAM_SNI, broker);

and to disable client certificate evaluation:

configSecurityProfile(LTE_SEC_PROFILE_MQTT, SARA_R5_SEC_PROFILE_PARAM_CERT_VAL_LEVEL, SARA_R5_SEC_PROFILE_CERTVAL_OPCODE_NO);

without success.

Any help would be very appreciated!

David

PaulZC commented 3 months ago

Hi David,

All I can suggest is checking that you are passing the certs and key correctly formatted as String.

I did run into an issue where I had to use this exact formatting to define the certs and key in PROGMEM. IIRC, if I included a line break before the -----BEGIN, it failed...

Code1 13 is the MQTT error class. Code2 8 is an "internal error"... Not much help...

Are there any more clues in the debug messages (enableDebugging)?

I hope this helps, Paul

Davefries1966 commented 3 months ago

Thanks Paul for your prompt reply.

Actually Code2 = 8 is "Cannot set secure socket" according to A.8.4.1 of AT commands manual. It seems related to some issue regarding certification chain. All I can say is that the same cert and key String variables are used by PubSubClient without any issue.

Is there any option on SARA R5 API to disable "SSL Secure" in the same way I can do on MQTTX or MQTT EXPLORER ?

Anyway I tried your suggested format, and enabled debugging, got the same error (log tail):

19:39:20.059 -> OK
19:39:20.059 -> sendCommandWithResponse: Command: +USECPRF=0,3,"rootCA"
19:39:20.059 -> AT+USECPRF=0,3,"rootCA"
19:39:20.092 -> sendCommandWithResponse: Response: 
19:39:20.092 -> OK
19:39:20.092 -> 
19:39:20.092 -> 
19:39:20.092 -> OK
19:39:20.092 -> sendCommandWithResponse: Command: +USECPRF=0,5,"cliCert"
19:39:20.128 -> AT+USECPRF=0,5,"cliCert"
19:39:20.175 -> sendCommandWithResponse: Response: 
19:39:20.175 -> OK
19:39:20.175 -> 
19:39:20.175 -> 
19:39:20.175 -> OK
19:39:20.175 -> sendCommandWithResponse: Command: +USECPRF=0,6,"cliKey"
19:39:20.175 -> AT+USECPRF=0,6,"cliKey"
19:39:20.209 -> sendCommandWithResponse: Response: 
19:39:20.209 -> OK
19:39:20.209 -> 
19:39:20.209 -> 
19:39:20.209 -> OK
19:39:20.209 -> sendCommandWithResponse: Command: +USECPRF=0,10,"2.XXX.XXX.XXX"
19:39:20.209 -> AT+USECPRF=0,10,"2.XXX.XXX.XXX"
19:39:20.277 -> sendCommandWithResponse: Response: 
19:39:20.277 -> OK
19:39:20.277 -> 
...
19:39:20.277 -> sendCommandWithResponse: Command: +UMQTT=0,"cat-1881f4"
19:39:20.277 -> AT+UMQTT=0,"cat-1881f4"
19:39:20.311 -> sendCommandWithResponse: Response: 
19:39:20.311 -> OK
19:39:20.311 -> 
19:39:20.311 -> 
19:39:20.311 -> OK
19:39:20.311 -> sendCommandWithResponse: Command: +UMQTT=2,"2.XXX.XXX.XXX",8883
19:39:20.311 -> AT+UMQTT=2,"2.XXX.XXX.XXX",8883
19:39:20.394 -> sendCommandWithResponse: Response: 
19:39:20.394 -> OK
19:39:20.394 -> 
19:39:20.394 -> 
19:39:20.394 -> OK
19:39:20.394 -> sendCommandWithResponse: Command: +UMQTT=11,1,0
19:39:20.394 -> AT+UMQTT=11,1,0
19:39:20.429 -> sendCommandWithResponse: Response: 
...
19:39:20.429 -> OK
19:39:20.429 -> sendCommandWithResponse: Command: +UMQTT=4,"username","password"
19:39:20.429 -> AT+UMQTT=4,"username","password: 
19:39:20.510 -> OK
19:39:20.510 -> 
19:39:20.510 -> 
19:39:20.510 -> OK
19:39:20.510 -> sendCommandWithResponse: Command: +UMQTTC=1
19:39:20.510 -> AT+UMQTTC=1
19:39:20.545 -> sendCommandWithResponse: Response: 
19:39:20.545 -> OK
19:39:20.545 -> 
19:39:20.545 -> 
19:39:20.545 -> OK
19:39:20.627 -> bufferedPoll: event(s) found! ===>
19:39:20.627 -> bufferedPoll: start of event: +CSCON: 1
19:39:20.627 -> bufferedPoll: end of event
19:39:20.627 -> bufferedPoll: <=== end of event(s)!
19:39:24.809 -> bufferedPoll: event(s) found! ===>
19:39:24.809 -> bufferedPoll: start of event: +ULWM2MSTAT: 2,721,58271
19:39:24.809 -> bufferedPoll: end of event
19:39:24.809 -> bufferedPoll: <=== end of event(s)!
19:39:36.527 -> bufferedPoll: event(s) found! ===>
19:39:36.527 -> bufferedPoll: start of event: +UUMQTTC: 1,0
19:39:36.527 -> processReadEvent: MQTT command result
19:39:36.527 -> sendCommandWithResponse: Command: +UMQTTER
19:39:36.579 -> AT+UMQTTER
19:39:36.594 -> sendCommandWithResponse: Response: 
19:39:36.594 -> +UMQTTER: 13,8

David

Davefries1966 commented 3 months ago

Comparing the debugging obtained from both test connections, that is, test.mosquitto.org:8883 and my_broker:8883, I got in the first case (test.mosquitto.org):

20:35:54.014 -> bufferedPoll: start of event: +UUMQTTC: 1,1
20:35:54.014 -> processReadEvent: MQTT command result
20:35:54.014 -> [_][LTE.h:298] mqttCallback(): login
20:35:54.014 -> [_][LTE.h:631] setState(): state change 6(mqtt)

In the latter case (my MQTT broker):

20:32:51.347 -> bufferedPoll: start of event: +UUMQTTC: 1,0
20:32:51.381 -> processReadEvent: MQTT command result
20:32:51.381 -> sendCommandWithResponse: Command: +UMQTTER
20:32:51.417 -> sendCommandWithResponse: Response: 
20:32:51.417 -> +CSCON: 1
20:32:51.417 -> 
20:32:51.417 -> +UMQTTER: 13,8

It seems that the only difference is +UUMQTTC: 1,0 instead of +UUMQTTC: 1,1

PaulZC commented 3 months ago

Hi David,

+UUMQTTC: 1,0 is MQTT login fail.

Agreed, Code2 == 8 is Cannot set secure socket. (I was looking at an old version of the AT Manual previously.)

Maybe you need to change the configSecurityProfile(LTE_SEC_PROFILE_MQTT, SARA_R5_SEC_PROFILE_PARAM_TLS_VER, SARA_R5_SEC_PROFILE_TLS_OPCODE_VER1_2); ?

https://github.com/sparkfun/SparkFun_u-blox_SARA-R5_Arduino_Library/blob/cc961b2870059eb7a9f91cfc99af18187d614ae2/src/SparkFun_u-blox_SARA-R5_Arduino_Library.h#L575-L588

https://github.com/sparkfun/SparkFun_u-blox_SARA-R5_Arduino_Library/blob/cc961b2870059eb7a9f91cfc99af18187d614ae2/src/SparkFun_u-blox_SARA-R5_Arduino_Library.h#L598-L605

I hope this helps, Paul

Davefries1966 commented 3 months ago

IT DOES WORK NOW! :-)

I re-made all the certificates and changed the setting of param SARA_R5_SEC_PROFILE_PARAM_TLS_VER to SARA_R5_SEC_PROFILE_TLS_OPCODE_ANYVER.

Thanks Paul again for your precious support! :-)

PaulZC commented 3 months ago

No problem David - I'm glad it's working...

Closing...

Best wishes, Paul