u-blox / ubxlib

Portable C libraries which provide APIs to build applications with u-blox products and services. Delivered as add-on to existing microcontroller and RTOS SDKs.
Apache License 2.0
287 stars 82 forks source link

USECMNG invalid certificate/key format #242

Closed mos216 closed 1 month ago

mos216 commented 1 month ago

Hello,

Currently, I'm trying to test the example main_tls which uses certifications files for tls communications. But so far I always get an error message that the certification is invalid can not be written to the modem.

0000/01/01 00:00:17.653: AT+UDNSRN=0,"ubxlib.com" 0000/01/01 00:00:18.346: 0000/01/01 00:00:18.349: +UDNSRN:"18.133.144.142" 0000/01/01 00:00:18.353: 0000/01/01 00:00:18.356: OK U_CELL_SOCK: found it at "18.133.144.142". Address is: IPV4 18.133.144.142 0000/01/01 00:00:18.386: AT+USECMNG=4,1,"ubxlib_test_client_cert" 0000/01/01 00:00:18.445: 0000/01/01 00:00:18.448: +CME ERROR: parameters are invalid 0000/01/01 00:00:18.475: AT+USECMNG=0,1,"ubxlib_test_client_cert",840 0000/01/01 00:00:18.535: 0000/01/01 00:00:18.537: > 0000/01/01 00:00:18.663: -----BEGIN CERTIFICATE-----MIICSjCCAdACFD+js1Fht6STx4lF3zGisrnThT4iMAoGCCqGSM49BAMDMIGFMQswCQYDVQQGEwJVUzELMAkGA1UECAwCV0ExEDAOBgNVBAcMB1RoYWx3aWwxDzANBgNVBAoMBnUtYmxveDELMAkGA1UECwwCY2ExFzAVBgNVBAMMDnd3dy51LWJsb3guY29tMSAwHgYJKoZIhvcNAQkBFhF1YnhsaWJAdS1ibG94LmNvbTAgFw0yMzA3MDkwODI3NDBaGA8yMTIzMDYxNTA4Mjc0MFowgYkxCzAJBgNVBAYTAlVTMQswCQYDVQQIDAJXQTEQMA4GA1UEBwwHVGhhbHdpbDEPMA0GA1UECgwGdS1ibG94MQ8wDQYDVQQLDAZjbGllbnQxFzAVBgNVBAMMDnd3dy51LWJsb3guY29tMSAwHgYJKoZIhvcNAQkBFhF1YnhsaWJAdS1ibG94LmNvbTB2MBAGByqGSM49AgEGBSuBBAAiA2IABApmNYLlR8CrS9MAocQX+bUU4+1EkmT61bchs6pf9RVvvbgbLkw2gk/So8vPifo6imJcjWteiIByxYKKFSIyghz/o0hjmpDz1XoYPtGENrz/dyISP35ZFk9sRJZ4pSX1uDAKBggqhkjOPQQDAwNoADBlAjEA3scFsQb9Aj+lzC34h+AS6RGHLHr81Txm713MHnXjrpe0jEk8bTULtydY8Jyf9c+DAjBMEdAEODaOp5Vn02ZOkKtbm91R6rFS1IZTFJ2MQCALG50CGHviROz1O6YfRcRFTks=-----END CERTIFICATE-----0000/01/01 00:00:18.749: 0000/01/01 00:00:18.751: +CME ERROR: USECMNG invalid certificate/key format AT+USECMNG=4,2,"ubxlib_test_client_key" 0000/01/01 00:00:18.836: 0000/01/01 00:00:18.839: +CME ERROR: parameters are invalid 0000/01/01 00:00:18.866: AT+USECMNG=0,2,"ubxlib_test_client_key",282 0000/01/01 00:00:18.926: 0000/01/01 00:00:18.928: > 0000/01/01 00:00:19.005: -----BEGIN EC PRIVATE KEY-----MIGkAgEBBDBxQnFRM8oo6gCjmfNNgTdfUQreohEDs1NFIOq84DO3120rKI4Ypf7hxog10lSfhhOgBwYFK4EEACKhZANiAAQKZjWC5UfAq0vTAKHEF/m1FOPtRJJk+tW3IbOqX/UVb724Gy5MNoJP0qPLz4n6OopiXI1rXoiAcsWCihUiMoIc/6NIY5qQ89V6GD7RhDa8/3ciEj9+WRZPbESWeKUl9bg=-----END EC PRIVATE KEY-----0000/01/01 00:00:19.042: 0000/01/01 00:00:19.045: +CME ERROR: USECMNG invalid certificate/key format AT+USECMNG=4,0,"ubxlib_test_ca_cert" 0000/01/01 00:00:19.129: 0000/01/01 00:00:19.132: +CME ERROR: parameters are invalid U_SECURITY_TLS_TEST: storing CA certificate... 0000/01/01 00:00:19.163: AT+USECMNG=0,0,"ubxlib_test_ca_cert",956 0000/01/01 00:00:19.222: 0000/01/01 00:00:19.224: > 0000/01/01 00:00:19.361: -----BEGIN CERTIFICATE-----MIICoTCCAiagAwIBAgIUXW8iJeCsbA3ygmXIT3wqxqtZla4wCgYIKoZIzj0EAwIwgYUxCzAJBgNVBAYTAlVTMQswCQYDVQQIDAJXQTEQMA4GA1UEBwwHVGhhbHdpbDEPMA0GA1UECgwGdS1ibG94MQswCQYDVQQLDAJjYTEXMBUGA1UEAwwOd3d3LnUtYmxveC5jb20xIDAeBgkqhkiG9wAkGA1UEBhMCVVMxCzAJBgNVBAgMAldBMRAwDgYDVQQHDAdUaGFsd2lsMQ8wDQYDVQQKDAZ1LWJsb3gxCzAJBgNVBAsMAmNhMRcwFYmxveC5jb20wdjAQBgcqhkjOPQIBBgUrgQQAIgNiAAS5br7n7+wiMwp5h3BojVn+cH4oZN7ngyfadR961TJZsu/g2arYE8SJTVI+qzQC4KiBb+rTXQIYk9sxEo+mTyJ4BWaVxoWOXjvALNRtyrbls6q36ttXoYsU5UAgNWJiH/ejUzBRMB0GA1UdDgQWBBRKetSAT3SQ45r2l64eXK1vf8sTzDAfBgNVHSMEGDAWgBRKetSAT3SQ45r2l64eXK1vf8sTzDAPBgNVHRMBAf8EBTADAQH/MAoGCCqGSM49BAMCA2kAMGYCMQD7WrRzaAxBikIHPuoDZo7tAdA5Zsbg9axBPS+wm3mdKLGwWjdep2IWLmn/uuFEVlwCMQDXxDnOuuc6p1nzmtrn9JHVE0/+HdeDj6KdnDWWtZJQsagHDAEmld8oEDlgiDO9Bnw=-----END CERTIFICATE-----0000/01/01 00:00:19.456: 0000/01/01 00:00:19.459: +CME ERROR: USECMNG invalid certificate/key format

RobMeades commented 1 month ago

That's rather odd: this example is run here as a standard part of regression testing, see AT output below. From your previous post the FW version of your LENA-R8 is 02.00,A01.40, which is the same as the one we test with but it is possible that we originally stored our test certificate when running an earlier version of the LENA-R8 FW and something changed in a later version of the FW which meant that it no longer supports the format we think it supports.

Let me try deleting the certificates from storage and running the test again.

2024-05-23 19:04:04,051 U_APP: Running exampleSocketsTls...
2024-05-23 19:04:04,052 progress update - item exampleSocketsTls() started on 19:04:04.052291.
2024-05-23 19:04:04,092 U_CELL: initialising with enable power pin not connected, PWR_ON pin 26 (0x1a) (and is toggled from 0 to 1) and VInt pin 37 (0x25) (and is 0 when module is on).
2024-05-23 19:04:04,144 U_CELL_PWR: pin 15 (0x0f), connected to module DTR pin, is being used to control power saving, where 0 means "DTR on" (and hence power saving not allowed).
2024-05-23 19:04:04,214 AT
2024-05-23 19:04:04,291 OK
2024-05-23 19:04:04,302 U_CELL_PWR: powering on, module is already on.
2024-05-23 19:04:04,313 ATE0
2024-05-23 19:04:04,363 OK
2024-05-23 19:04:04,375 AT+CMEE=2
2024-05-23 19:04:04,444 OK
2024-05-23 19:04:04,455 AT+UDCONF=1,0
2024-05-23 19:04:04,524 OK
2024-05-23 19:04:04,535 ATI9
2024-05-23 19:04:04,603 02.00,A01.40
2024-05-23 19:04:04,634 OK
2024-05-23 19:04:04,646 AT&C1
2024-05-23 19:04:04,684 OK
2024-05-23 19:04:04,695 AT&D0
2024-05-23 19:04:04,764 OK
2024-05-23 19:04:04,775 AT&K3
2024-05-23 19:04:05,004 OK
2024-05-23 19:04:05,016 AT+UPSV=4,1300
2024-05-23 19:04:05,083 OK
2024-05-23 19:04:05,095 AT+UGPRF?
2024-05-23 19:04:05,164 +UGPRF:2,1234,"myserver"
2024-05-23 19:04:05,194 OK
2024-05-23 19:04:05,206 AT+CFUN=4
2024-05-23 19:04:05,247 OK
2024-05-23 19:04:05,258 Opened device with return code 0.
2024-05-23 19:04:05,270 Bringing up the network...
2024-05-23 19:04:05,281 U_CELL_NET: preparing to register/connect...
2024-05-23 19:04:05,292 AT+CREG=2
2024-05-23 19:04:05,323 OK
2024-05-23 19:04:05,335 AT+CGREG=2
2024-05-23 19:04:05,403 OK
2024-05-23 19:04:05,414 AT+CEREG=4
2024-05-23 19:04:05,483 OK
2024-05-23 19:04:05,495 AT+CIMI
2024-05-23 19:04:05,573 234500003651411
2024-05-23 19:04:05,604 OK
2024-05-23 19:04:05,615 AT+CIMI
2024-05-23 19:04:05,653 234500003651411
2024-05-23 19:04:05,684 OK
2024-05-23 19:04:05,695 U_CELL_NET: APN from database is "jtm2m".
2024-05-23 19:04:05,707 AT+CGDCONT=1,"IP","jtm2m"
2024-05-23 19:04:05,736 OK
2024-05-23 19:04:05,748 AT+UAUTHREQ=1,0,"",""
2024-05-23 19:04:05,813 OK
2024-05-23 19:04:05,828 AT+CGDCONT=2,"IP","jtm2m"
2024-05-23 19:04:05,898 OK
2024-05-23 19:04:05,910 U_CELL_NET: setting automatic network selection mode...
2024-05-23 19:04:05,921 AT+COPS?
2024-05-23 19:04:05,973 +COPS: 0
2024-05-23 19:04:06,004 OK
2024-05-23 19:04:06,955 AT+CFUN=1
2024-05-23 19:04:07,023 OK
2024-05-23 19:04:07,035 AT+CREG?
2024-05-23 19:04:07,103 +CREG: 0,"0000","0000",0
2024-05-23 19:04:07,134 OK
2024-05-23 19:04:07,146 -1: NReg
2024-05-23 19:04:07,385 AT+CGREG?
2024-05-23 19:04:07,454 +CGREG: 2,0,"0000","0000"
2024-05-23 19:04:07,484 OK
2024-05-23 19:04:07,496 -1: NReg
2024-05-23 19:04:07,735 AT+CEREG?
2024-05-23 19:04:07,805 +CEREG: 4,0,"0000","00000000", 0,0,9,"00000000","00000000"
2024-05-23 19:04:07,835 OK
2024-05-23 19:04:07,847 -1: NReg
2024-05-23 19:04:08,085 AT+CREG?
2024-05-23 19:04:08,154 +CREG: 0,"0000","0000",0
2024-05-23 19:04:08,184 OK
2024-05-23 19:04:08,195 -1: NReg
2024-05-23 19:04:08,435 AT+CGREG?
2024-05-23 19:04:08,504 +CGREG: 2,0,"0000","0000"
2024-05-23 19:04:08,534 OK
2024-05-23 19:04:08,546 -1: NReg
2024-05-23 19:04:08,785 AT+CEREG?
2024-05-23 19:04:08,856 +CEREG: 4,0,"0000","00000000", 0,0,9,"00000000","00000000"
2024-05-23 19:04:08,887 OK
2024-05-23 19:04:08,898 -1: NReg
2024-05-23 19:04:09,135 AT+CREG?
2024-05-23 19:04:09,204 +CREG: 0,"0000","0000",0
2024-05-23 19:04:09,234 OK
2024-05-23 19:04:09,245 -1: NReg
2024-05-23 19:04:09,485 AT+CGREG?
2024-05-23 19:04:09,554 +CGREG: 2,0,"0000","0000"
2024-05-23 19:04:09,584 OK
2024-05-23 19:04:09,596 -1: NReg
2024-05-23 19:04:09,835 AT+CEREG?
2024-05-23 19:04:09,905 +CEREG: 4,0,"0000","00000000", 0,0,9,"00000000","00000000"
2024-05-23 19:04:09,935 OK
2024-05-23 19:04:09,947 -1: NReg
2024-05-23 19:04:10,185 AT+CREG?
2024-05-23 19:04:10,254 +CREG: 0,"0000","0000",0
2024-05-23 19:04:10,284 OK
2024-05-23 19:04:10,295 -1: NReg
2024-05-23 19:04:10,535 AT+CGREG?
2024-05-23 19:04:10,604 +CREG: 5,"037e","0938",0
2024-05-23 19:04:10,635 +CGREG: 2,0,"0000","0000"
2024-05-23 19:04:10,665 OK
2024-05-23 19:04:10,677 0: RegR
2024-05-23 19:04:10,688 -1: NReg
2024-05-23 19:04:10,885 AT+CEREG?
2024-05-23 19:04:10,955 +CEREG: 4,4,"0000","00000000", 0,0,9,"00000000","00000000"
2024-05-23 19:04:10,986 OK
2024-05-23 19:04:10,997 -1: OoC
2024-05-23 19:04:11,235 AT+CREG?
2024-05-23 19:04:11,303 +CREG: 5,"037e","0938",0
2024-05-23 19:04:11,334 OK
2024-05-23 19:04:11,345 0: RegR
2024-05-23 19:04:11,585 AT+CGREG?
2024-05-23 19:04:11,654 +CGREG: 2,0,"0000","0000"
2024-05-23 19:04:11,684 OK
2024-05-23 19:04:11,695 -1: NReg
2024-05-23 19:04:11,935 AT+CEREG?
2024-05-23 19:04:12,005 +CEREG: 4,4,"0000","00000000", 0,0,9,"00000000","00000000"
2024-05-23 19:04:12,036 OK
2024-05-23 19:04:12,047 -1: OoC
2024-05-23 19:04:12,285 AT+CREG?
2024-05-23 19:04:12,354 +CREG: 5,"037e","0938",0
2024-05-23 19:04:12,384 OK
2024-05-23 19:04:12,395 0: RegR
2024-05-23 19:04:12,579 +CGREG: 5,"037E","0938"
2024-05-23 19:04:12,610 +CREG: 5,"037E","0938"
2024-05-23 19:04:12,621 3: RegR
2024-05-23 19:04:12,633 0: RegR
2024-05-23 19:04:12,695 AT+COPS=3,0
2024-05-23 19:04:12,763 OK
2024-05-23 19:04:12,775 AT+COPS?
2024-05-23 19:04:12,924 +COPS: 0,0,"vodafone UK",0
2024-05-23 19:04:12,954 OK
2024-05-23 19:04:12,966 AT+CGATT?
2024-05-23 19:04:13,003 +CGATT:1
2024-05-23 19:04:13,034 OK
2024-05-23 19:04:13,045 AT+CGACT?
2024-05-23 19:04:13,083 OK
2024-05-23 19:04:16,035 AT+CGACT=1,1
2024-05-23 19:04:16,943 OK
2024-05-23 19:04:16,954 AT+CGACT?
2024-05-23 19:04:17,023 +CGACT: 1,1
2024-05-23 19:04:17,053 OK
2024-05-23 19:04:17,064 AT+CGACT?
2024-05-23 19:04:17,103 +CGACT: 1,1
2024-05-23 19:04:17,133 OK
2024-05-23 19:04:20,056 AT+CGACT=1,2
2024-05-23 19:04:21,203 OK
2024-05-23 19:04:21,215 AT+CGACT?
2024-05-23 19:04:21,283 +CGACT: 1,1
2024-05-23 19:04:21,295 +CGACT: 2,1
2024-05-23 19:04:21,324 OK
2024-05-23 19:04:21,336 AT+CEER
2024-05-23 19:04:21,383 +CEER:No Error Call
2024-05-23 19:04:21,414 OK
2024-05-23 19:04:24,311 U_CELL_NET: connected after 18 second(s).
2024-05-23 19:04:24,335 AT+CGACT?
2024-05-23 19:04:24,403 +CGACT: 1,1
2024-05-23 19:04:24,415 +CGACT: 2,1
2024-05-23 19:04:24,444 OK
2024-05-23 19:04:24,455 AT+CGPADDR=1
2024-05-23 19:04:24,486 +CGPADDR: 1,"10.85.125.87"
2024-05-23 19:04:24,516 OK
2024-05-23 19:04:24,527 U_CELL_NET: IP address "10.85.125.87".
2024-05-23 19:04:24,539 AT+CGCONTRDP=1
2024-05-23 19:04:24,569 +CGCONTRDP: 1,5,,"0.0.0.0.0.0.0.0"
2024-05-23 19:04:24,599 OK
2024-05-23 19:04:24,610 U_CELL_NET: unable to read DNS addresses.
2024-05-23 19:04:24,622 AT+CMUX=0,0,,128
2024-05-23 19:04:24,663 OK
2024-05-23 19:04:25,744 ATE0
2024-05-23 19:04:25,774 OK
2024-05-23 19:04:25,935 AT+CMEE=2
2024-05-23 19:04:25,965 OK
2024-05-23 19:04:26,104 AT+UPSV?
2024-05-23 19:04:26,135 +UPSV: 4,1300
2024-05-23 19:04:26,166 OK
2024-05-23 19:04:26,315 AT+UPSV=0
2024-05-23 19:04:26,345 OK
2024-05-23 19:04:27,380 U_CELL_PPP: sent ATD*99***2#[0d]
2024-05-23 19:04:27,392 U_CELL_PPP: received [0d][0a]CONNECT[0d][0a]
2024-05-23 19:04:27,783 [0;32mI (2004562) esp-netif_lwip-ppp: Connected
2024-05-23 19:04:27,795 U_PORT_PPP: received event 0.
2024-05-23 19:04:27,832 [0;32mI (2004612) esp-netif_lwip-ppp: Connected
2024-05-23 19:04:27,843 U_PORT_PPP: received event 0.
2024-05-23 19:04:27,879 Looking up server address...
2024-05-23 19:04:27,890 U_CELL_SOCK: looking up IP address of "ubxlib.com".
2024-05-23 19:04:27,975 AT+CGDCONT?
2024-05-23 19:04:28,006 +CGDCONT: 1,"IP","jtm2m","10.85.125.87",0,0
2024-05-23 19:04:28,017 +CGDCONT: 2,"IP","jtm2m","10.113.240.254",0,0
2024-05-23 19:04:28,048 OK
2024-05-23 19:04:28,407 AT+UDNSRN=0,"ubxlib.com"
2024-05-23 19:04:29,614 +UDNSRN:"18.133.144.142"
2024-05-23 19:04:29,645 OK
2024-05-23 19:04:29,656 U_CELL_SOCK: found it at "18.133.144.142".
2024-05-23 19:04:29,668 Address is: IPV4 18.133.144.142
2024-05-23 19:04:30,131 AT+USECMNG=4,1,"ubxlib_test_client_cert"
2024-05-23 19:04:30,164 +USECMNG: 4,1,"ubxlib_test_client_cert","335F892F5984588093CCF136A365E457"
2024-05-23 19:04:30,194 OK
2024-05-23 19:04:30,700 AT+USECMNG=4,2,"ubxlib_test_client_key"
2024-05-23 19:04:30,732 +USECMNG: 4,2,"ubxlib_test_client_key","8FE6DDDB64B8F82EA252B2BB5E3808E8"
2024-05-23 19:04:30,762 OK
2024-05-23 19:04:31,230 AT+USECMNG=4,0,"ubxlib_test_ca_cert"
2024-05-23 19:04:31,263 +USECMNG: 4,0,"ubxlib_test_ca_cert","A883A02DE0AD346426B3FB8A1B933D84"
2024-05-23 19:04:31,293 OK
2024-05-23 19:04:31,305 Creating socket...
2024-05-23 19:04:31,435 AT+USOCR=6
2024-05-23 19:04:31,465 +USOCR:0
2024-05-23 19:04:31,496 OK
2024-05-23 19:04:31,508 U_SOCK: socket created, descriptor 2, network handle 0x3ffc618c, socket handle 5.
2024-05-23 19:04:31,665 AT+USECPRF=0
2024-05-23 19:04:31,696 OK
2024-05-23 19:04:32,159 AT+USECPRF=0,3,"ubxlib_test_ca_cert"
2024-05-23 19:04:32,190 OK
2024-05-23 19:04:32,651 AT+USECPRF=0,5,"ubxlib_test_client_cert"
2024-05-23 19:04:32,681 OK
2024-05-23 19:04:33,140 AT+USECPRF=0,6,"ubxlib_test_client_key"
2024-05-23 19:04:33,171 OK
2024-05-23 19:04:33,525 AT+USECPRF=0,0,1
2024-05-23 19:04:33,556 OK
2024-05-23 19:04:33,985 AT+USOSEC=0,1,0
2024-05-23 19:04:34,016 OK
2024-05-23 19:04:34,253 U_SOCK: connecting socket to "18.133.144.142:5065"...
2024-05-23 19:04:34,698 AT+USOCO=0,"18.133.144.142",5065
2024-05-23 19:04:38,064 OK
2024-05-23 19:04:38,077 U_SOCK: socket with descriptor 2, network handle 0x3ffc618c, socket handle 5, is  connected to address "18.133.144.142:5065".
2024-05-23 19:04:38,089 Sending data...
2024-05-23 19:04:38,335 AT+USOWR=0,45
2024-05-23 19:04:38,469 @ The quick brown fox jumps over the lazy dog.[00]
2024-05-23 19:04:38,480 +USOWR: 0,45
2024-05-23 19:04:38,510 OK
2024-05-23 19:04:38,521 Sent 45 byte(s) to echo server.
2024-05-23 19:04:38,765 AT+USORD=0,0
2024-05-23 19:04:38,797 +USORD:0,0
2024-05-23 19:04:38,828 OK
2024-05-23 19:04:39,146 AT+USORD=0,0
2024-05-23 19:04:39,177 +UUSORD:0,45
2024-05-23 19:04:39,207 +USORD:0,45
2024-05-23 19:04:39,238 OK
2024-05-23 19:04:39,465 AT+USORD=0,64
2024-05-23 19:04:39,497 +USORD:0,45,"The quick brown fox jumps over the lazy dog.[00]"
2024-05-23 19:04:39,528 OK
2024-05-23 19:04:39,560 Received echo back (45 byte(s)): The quick brown fox jumps over the lazy dog.
2024-05-23 19:04:39,571 Closing socket...
2024-05-23 19:04:39,775 AT+USOCL=0,1
2024-05-23 19:04:39,806 OK
2024-05-23 19:04:39,818 U_SOCK: socket with descriptor 2, network handle 0x3ffc618c, socket handle 5, has been closed.
2024-05-23 19:04:39,849 +UUSOCL: 0
2024-05-23 19:04:39,948 Taking down network...
2024-05-23 19:04:39,999 U_PORT_PPP: waiting to be released.
2024-05-23 19:04:40,971 [0;32mI (2017742) esp-netif_lwip-ppp: User interrupt
2024-05-23 19:04:40,982 U_PORT_PPP: received event 5.
2024-05-23 19:04:40,994 U_PORT_PPP: released.
2024-05-23 19:04:41,075 AT+COPS?
2024-05-23 19:04:41,224 +COPS: 0,0,"vodafone UK",0
2024-05-23 19:04:41,254 OK
2024-05-23 19:04:41,265 AT+CFUN=4
2024-05-23 19:04:42,387 OK
2024-05-23 19:04:42,418 +CGREG: 0,"037E","0938"
2024-05-23 19:04:42,449 +CREG: 0,"0000","0000"
2024-05-23 19:04:42,480 +CREG: 0,"0000","0000",0
2024-05-23 19:04:42,491 -1: NReg
2024-05-23 19:04:42,502 -1: NReg
2024-05-23 19:04:42,513 -1: NReg
2024-05-23 19:04:42,524 AT+CREG?
2024-05-23 19:04:42,553 +CREG: 0,"0000","0000",0
2024-05-23 19:04:42,584 OK
2024-05-23 19:04:42,595 -1: NReg
2024-05-23 19:04:42,836 AT+CGREG?
2024-05-23 19:04:42,904 +CGREG: 2,0,"0000","0000"
2024-05-23 19:04:42,934 OK
2024-05-23 19:04:42,945 -1: NReg
2024-05-23 19:04:43,185 AT+CEREG?
2024-05-23 19:04:43,254 +CEREG: 4,0,"0000","00000000", 0,0,9,"00000000","00000000"
2024-05-23 19:04:43,285 OK
2024-05-23 19:04:43,296 -1: NReg
2024-05-23 19:04:43,535 AT+CGATT?
2024-05-23 19:04:43,603 +CGATT:0
2024-05-23 19:04:43,635 OK
2024-05-23 19:04:43,646 -1: NReg
2024-05-23 19:04:43,658 U_CELL_NET: disconnected.
2024-05-23 19:04:43,669 AT+CEER
2024-05-23 19:04:43,697 +CEER:No Error Call
2024-05-23 19:04:43,728 OK
2024-05-23 19:04:46,887 Done.
2024-05-23 19:04:46,900 /home/ubxlib/workspace/ubxlib/example/sockets/main_tls.c:300:exampleSocketsTls:PASS
RobMeades commented 1 month ago

Confirmed that if I delete the working key and then try to store exactly the same key again I get +CME ERROR: USECMNG invalid certificate/key format back. Let me find out what changed...

mos216 commented 1 month ago

Hi Rob, Thanks , looking forward for the solution :)

RobMeades commented 1 month ago

Figured it out: LENA-R8 was modified to require line endings in the PEM format file, first time I've ever seen this in one of our cellular modules. I will update the certificate arrays used by the examples to include line endings and let you know when that is pushed here.

RobMeades commented 1 month ago

Hopefully fixed in 759020036fdcff164934c697e2780f7c102b20cd.

mos216 commented 1 month ago

Hi Rob , many thanks again for ur support it is working indeed with new line char. but unfortunately still can't connect this device to AWS IOT broker

screenshot from the code

` uMqttClientConnection_t connection = U_MQTT_CLIENT_CONNECTION_DEFAULT; uSecurityTlsSettings_t tlsSettings = U_SECURITY_TLS_SETTINGS_DEFAULT; tlsSettings.certificateCheck = U_SECURITY_TLS_CERTIFICATE_CHECK_ROOT_CA; char topic[U_SECURITY_SERIAL_NUMBER_MAX_LENGTH_BYTES]; const char message[] = "The quick brown fox jumps over the lazy dog"; char buffer[64]; size_t bufferSize; volatile bool messagesAvailable = false; int32_t startTimeMs; int32_t returnCode;

// Initialise the APIs we will need
uPortInit();
uDeviceInit();
uPortLogOn();

// Open the device
returnCode = uDeviceOpen(&gDeviceCfg, &devHandle);
uPortLog("Opened device with return code %d.\n", returnCode);

if (returnCode == 0) {
    // Bring up the network interface
    uPortLog("Bringing up the network...\n");
    if (uNetworkInterfaceUp(devHandle, gNetType,
                            &gNetworkCfg) == 0) {
        checkCredentials(devHandle, &tlsSettings);
        pContext = pUMqttClientOpen(devHandle, &tlsSettings);
        if (pContext != NULL) {
            connection.pBrokerNameStr = AWS_BROKER;
            connection.localPort = 8883;
            connection.pClientIdStr = "lenar8";

            uPortLog("Connecting to MQTT broker \"%s\"...\n", AWS_BROKER);
            if (uMqttClientConnect(pContext, &connection) == 0) {
                uMqttClientSetMessageCallback(pContext,
                                              messageIndicationCallback,
                                              (void *) &messagesAvailable);
                uSecurityGetSerialNumber(devHandle, topic);

` here is the logs , maybe you have some idea

U_PORT_BOARD_CFG: using CELLULAR device "cfg-device-cellular" from the device tree, module-type 8 on UART 2, uart-baud-rate 115200 with pin-enable-power -1 (0xffffffff), pin-pwr-on 38 (0x26), pin-vint 39 (0x27), pin-dtr-power-saving -1 (0xffffffff). U_CELL: initialising with enable power pin not connected, PWR_ON pin 38 (0x26) (and is toggled from 1 to 0) and VInt pin 39 (0x27) (and is 1 when module is on). AT

OK U_CELL_PWR: powering on, module is already on. ATE0

OK AT+CMEE=2

OK AT+UDCONF=1,0

OK ATI9

02.00,A01.40

OK AT&C1

OK AT&D0

OK AT&K0

OK AT+UPSV=4,1300

OK AT+UGPRF?

+UGPRF:2,0,""

OK AT+CFUN=4

OK Opened device with return code 0. Bringing up the network... U_PORT_BOARD_CFG: using CELLULAR network configuration associated with device "cfg-device-cellular" from the device tree, timeout-seconds 1800, APN "iot.1nce.net", username "", password "", authentication-mode 0, MCC/MNC NULL, uart-ppp: NULL. U_CELL_NET: preparing to register/connect... AT+CREG=2

OK AT+CGREG=2

OK AT+CEREG=4

OK AT+CIMI

901405112793458

OK U_CELL_NET: user-specified APN is "iot.1nce.net". AT+CGDCONT=1,"IP","iot.1nce.net"

OK AT+UAUTHREQ=1,0,"",""

OK U_CELL_NET: setting automatic network selection mode... AT+COPS?

+COPS: 0

OK AT+CFUN=1

OK AT+CREG?

+CREG: 0,"0000","0000",0

OK -1: NReg AT+CGREG?

+CGREG: 2,0,"0000","0000"

OK -1: NReg AT+CEREG?

+CEREG: 4,0,"0000","00000000", 0,0,9,"00000000","00000000"

OK -1: NReg AT+CREG?

+CREG: 0,"0000","0000",0

OK -1: NReg AT+CGREG?

+CGREG: 2,0,"0000","0000"

OK -1: NReg AT+CEREG?

+CEREG: 4,0,"0000","00000000", 0,0,9,"00000000","00000000"

OK -1: NReg AT+CREG?

+CREG: 0,"0000","0000",0

OK -1: NReg AT+CGREG?

+CGREG: 2,0,"0000","0000"

OK -1: NReg AT+CEREG?

+CEREG: 4,0,"0000","00000000", 0,0,9,"00000000","00000000"

OK -1: NReg

+CREG: 5,"00d8","feba",0 0: RegR AT+CREG?

+CREG: 5,"00d8","feba",0

OK 0: RegR AT+CGREG?

+CGREG: 2,0,"0000","0000"

OK -1: NReg AT+CEREG?

+CEREG: 4,4,"0000","00000000", 0,0,9,"00000000","00000000"

OK -1: OoC AT+CREG?

+CREG: 5,"00d8","feba",0

OK 0: RegR

+CGREG: 5,"00D8","FEBA"

+CREG: 5,"00D8","FEBA" 3: RegR 0: RegR AT+CGREG?

+CGREG: 2,5,"00D8","FEBA"

OK 3: RegR AT+COPS=3,0

OK AT+COPS?

+COPS: 0,0,"vodafone NL",0

OK AT+CGATT?

+CGATT:1

OK AT+CGACT?

OK AT+CGACT=1,1

OK AT+CGACT?

+CGACT: 1,1

OK AT+CEER

+CEER:No Error Call

OK U_CELL_NET: connected after 13 second(s). AT+CGACT?

+CGACT: 1,1

OK AT+CGPADDR=1

+CGPADDR: 1,"10.42.63.5"

OK U_CELL_NET: IP address "10.42.63.5". AT+CGCONTRDP=1

+CGCONTRDP: 1,5,,"0.0.0.0.0.0.0.0"

OK U_CELL_NET: unable to read DNS addresses. AT+USECMNG=4,1,"test_aws_cert"

+USECMNG: 4,1,"test_aws_cert","779F57D926322E562A0DBDDFD9D3652D"

OK AT+USECMNG=0,1,"test_aws_cert",1223

-----BEGIN CERTIFICATE----xxxxxxxxx-----END CERTIFICATE----- +USECMNG: 0,1,"test_aws_cert","779F57D926322E562A0DBDDFD9D3652D" OK AT+USECMNG=4,2,"test_aws_client_key"

+USECMNG: 4,2,"test_aws_client_key","943E2CB05F1C0B3010D509814237200B"

OK AT+USECMNG=0,2,"test_aws_client_key",1678

-----BEGIN RSA PRIVATE KEY-----xxxxxxxxxx=-----END RSA PRIVATE KEY----- +USECMNG: 0,2,"test_aws_client_key","943E2CB05F1C0B3010D509814237200B" OK AT+USECMNG=4,0,"test_aws_ca_key"

+USECMNG: 4,0,"test_aws_ca_key","43C6BFAEECFEAD2F18C6886830FCC8E6"

OK U_SECURITY_TLS_TEST: storing CA certificate... AT+USECMNG=0,0,"test_aws_ca_key",1187

-----BEGIN CERTIFICATE-----xxxxxxxxxx-----END CERTIFICATE----- +USECMNG: 0,0,"test_aws_ca_key","43C6BFAEECFEAD2F18C6886830FCC8E6" OK AT+USECPRF=0

OK AT+USECPRF=0,3,"test_aws_ca_key"

OK AT+USECPRF=0,5,"test_aws_cert"

OK AT+USECPRF=0,6,"test_aws_client_key"

OK AT+USECPRF=0,0,1

OK Connecting to MQTT broker "xxxxxxxxxxxxxxx-ats.iot.eu-central-1.amazonaws.com"... AT+UMQTT=2,"xxxxxxxxxxx-ats.iot.eu-central-1.amazonaws.com"

OK AT+UMQTT=0,"lenar8"

OK Unable to connect to MQTT broker "a1xujxuw3b7jj6-ats.iot.eu-central-1.amazonaws.com"! Taking down network... AT+COPS?

+COPS: 0,0,"vodafone NL",0

OK AT+CFUN=4

OK

+CGREG: 0,"00D8","FEBA"

+CREG: 0,"00D8","FEBA"

+CREG: 0,"0000","0000",0 -1: NReg -1: NReg -1: NReg AT+CREG?

+CREG: 0,"0000","0000",0

OK -1: NReg AT+CGREG?

+CGREG: 2,0,"0000","0000"

OK -1: NReg AT+CEREG?

+CEREG: 4,0,"0000","00000000", 0,0,9,"00000000","00000000"

OK -1: NReg AT+CGATT?

+CGATT:0

OK -1: NReg U_CELL_NET: disconnected. AT+CEER

+CEER:No Error Call

OK Done. ---- Closed serial port COM14 due to disconnection from the machine ----

RobMeades commented 1 month ago

Can you let me know the return code from the MQTT connection attempt? It looks like ubxlib is not actually trying to connect:

Connecting to MQTT broker "xxxxxxxxxxxxxxx-ats.iot.eu-central-1.amazonaws.com"...
AT+UMQTT=2,"xxxxxxxxxxx-ats.iot.eu-central-1.amazonaws.com"
OK
AT+UMQTT=0,"lenar8"
OK

The above shows the broker URL and then the MQTT client unique name being set up but there is no actual connection attempt, which makes me think something has gone wrong with the configuration. Here is a log from running the same code on LENA-R8 in our test system, so that you can see a working example:

2024-05-30 09:23:04,968 Connecting to MQTT broker "ubxlib.com"...
2024-05-30 09:23:05,315 AT+UMQTT=2,"ubxlib.com"
2024-05-30 09:23:05,346 OK
2024-05-30 09:23:05,452 AT+CGSN
2024-05-30 09:23:05,483 863618054041566
2024-05-30 09:23:05,513 OK
2024-05-30 09:23:05,866 AT+UMQTT=0,"863618054041566"
2024-05-30 09:23:05,896 OK
2024-05-30 09:23:05,907 U_CELL_MQTT: trying to connect...
2024-05-30 09:23:06,053 AT+UMQTTC=1
2024-05-30 09:23:06,085 OK
2024-05-30 09:23:06,096 U_CELL_MQTT: waiting for response for up to 120 second(s)...
2024-05-30 09:23:10,053 +UUMQTTC: 1,1
2024-05-30 09:23:10,068 U_CELL_MQTT: connected after 3 second(s).
2024-05-30 09:23:10,272 AT+CGSN
2024-05-30 09:23:10,303 863618054041566
2024-05-30 09:23:10,334 OK
2024-05-30 09:23:10,345 U_CELL_INFO: IMEI is 863618054041566.
2024-05-30 09:23:10,356 Subscribing to topic "863618054041566"...
2024-05-30 09:23:10,797 AT+UMQTTC=4,2,"863618054041566"
2024-05-30 09:23:10,827 OK
2024-05-30 09:23:11,166 +UUMQTTC: 4,1,2,"863618054041566"
2024-05-30 09:23:11,813 Publishing "The quick brown fox jumps over the lazy dog" to topic "863618054041566"...
2024-05-30 09:23:12,458 AT+UMQTTC=9,2,0,"863618054041566",43
2024-05-30 09:23:12,588 > The quick brown fox jumps over the lazy dog
2024-05-30 09:23:12,600 OK
2024-05-30 09:23:13,353 +UUMQTTC: 9,1
2024-05-30 09:23:13,681 AT
2024-05-30 09:23:13,712 OK
2024-05-30 09:23:14,294 +UUMQTTC: 6,1,0The broker says there are 1 message(s) unread.
2024-05-30 09:23:14,944 AT+UMQTTC=6,1
2024-05-30 09:23:14,976 +UMQTTC:6,2,58,15,"863618054041566",43,"The quick brown fox jumps over the lazy dog"
2024-05-30 09:23:15,007 OK
2024-05-30 09:23:15,019 New message in topic "863618054041566" is 43 character(s): "The quick brown fox jumps over the lazy dog".

There is no U_CELL_MQTT: trying to connect... line in the log you pasted-in above.

mos216 commented 1 month ago

Hi Rob,

you are right , this one is missing

the error code is Unable to connect to MQTT broker [-4] "xxxxxxxxxx-ats.iot.eu-central-x.amazonaws.com"!

after debug seems there is something wrong here

image

ok via At command I get this error when I try to set the port

image
RobMeades commented 1 month ago

Ah, good, LENA-R8 does not support setting the local MQTT port and you shouldn't need that feature anyway: remember that this is the local port, at your module, not the destination port, which I think is the number you have in that M-Center window (8883). Only SARA-R412M-02B supports setting the local port and I've no idea what the use case for it is, kinda wish we'd never put support for it into ubxlib as it always confuses people.

So it might be that all you need to do is remove the line:

connection.localPort = 8883;
RobMeades commented 1 month ago

FYI, if you want to set a different destination port, you just put it on the end of the broker URL.

mos216 commented 1 month ago

you were right , but still unfortunately getting error but this time has different error

U_CELL_MQTT: connected after 12 second(s). AT

OK AT+CGSN

353760970017713

OK U_CELL_INFO: IMEI is 353760970017713. Subscribing to topic "353760970017713"... AT+UMQTTC=4,2,"353760970017713"

OK

+UUMQTTC: 4,0

+UUMQTTC: 0,100 AT+UMQTTER

+UMQTTER: 13,4

OK AT+UMQTTER

+UMQTTER: 13,4

OK U_CELL_MQTT: error codes 13, 4. Publishing "The quick brown fox jumps over the lazy dog" to topic "353760970017713"... AT+UMQTTC=9,2,0,"353760970017713",43

+CME ERROR: parameters are invalid

RobMeades commented 1 month ago

Definitely getting closer.

Subscribing to topic "353760970017713"...
AT+UMQTTC=4,2,"353760970017713"
OK

+UUMQTTC: 4,0
+UUMQTTC: 0,100

AT+UMQTTER
+UMQTTER: 13,4
OK

Referring to the LENA-R8 AT manual, section 27.4.2, in the response to the subscribe request, +UUMQTTC: 4,0, 0 means "failed" and that is immediately followed by +UUMQTTC: 0,100, which is the MQTT broker logging you out. Now, according to section 27.4.1 of the LENA-R8 AT manual, code 100 means that you are being logged out because the keep-alive timer has expired, which I find difficult to believe. It certainly means the broker is logging you out though.

When an error like this occurs, ubxlib asks the module for its MQTT error code:

AT+UMQTTER
+UMQTTER: 13,4
OK

...and, from appendix A.7.4 of the LENA-R8 AT manual, error 4 is Internal error, which seems odd since you've clearly been logged out by the MQTT broker.

Not sure what to suggest next since, on the face of it, this looks like the broker rather than us: it might be worth you trying setting a keep-alive timer, which most MQTT brokers like you to have so that connections aren't left up after a client has disconnected without notice. You could maybe set connection.inactivityTimeoutSeconds = 120 and connection.keepAlive = true? Not saying this is going to fix it but it would be interesting to see if it makes a difference.

RobMeades commented 1 month ago

Another possibility: checking here:

https://docs.aws.amazon.com/iot/latest/developerguide/mqtt.html#mqtt-qos

...it might be that the AWS MQTT broker does not support QoS 2, it might be worth trying U_MQTT_QOS_AT_LEAST_ONCE (1) in your subscribe and publish calls. If this turns out to fix it for you I will update the example to use U_MQTT_QOS_AT_LEAST_ONCE in order that no-one else falls over this issue.

mos216 commented 1 month ago

it is indeed fixed after setting QoS to 1 instead of 2! nice catch :)

I noticed sometimes that it falls into a loop when publishing the message and doesn't exist this loop till resetting the device!

+UMQTTC:6,0,60,15,"353760970017713",45,"{ "message": "Hello from AWS IoT console"}"

OK New message in topic "353760970017713" is 45 character(s): "{ "message": "Hello from AWS IoT console" }". AT+UMQTTC=6,1

+UMQTTC:6,1,58,15,"353760970017713",43,"The quick brown fox jumps over the lazy dog"

OK New message in topic "353760970017713" is 43 character(s): "The quick brown fox jumps over the lazy dog". AT+UMQTTC=6,1

+CME ERROR: parameters are invalid AT+UMQTTER

+UMQTTER: 13,2

OK U_CELL_MQTT: error codes 13, 2. AT+UMQTTC=6,1

+CME ERROR: parameters are invalid AT+UMQTTER

+UMQTTER: 13,2

OK U_CELL_MQTT: error codes 13, 2. AT+UMQTTC=6,1

+CME ERROR: parameters are invalid AT+UMQTTER

+UMQTTER: 13,2

OK U_CELL_MQTT: error codes 13, 2. AT+UMQTTC=6,1

+CME ERROR: parameters are invalid AT+UMQTTER

+UMQTTER: 13,2

OK U_CELL_MQTT: error codes 13, 2. AT+UMQTTC=6,1

...........................................................

RobMeades commented 1 month ago

I noticed sometimes that it falls into a loop when publishing the message and doesn't exist this loop till resetting the device!

Odd: that log fragment shows a message being read, rather than a publish:

AT+UMQTTC=6,1
+UMQTTC:6,1,58,15,"353760970017713",43,"The quick brown fox jumps over the lazy dog"
OK
New message in topic "353760970017713" is 43 character(s): "The quick brown fox jumps over the lazy dog".

The loop in the example:

https://github.com/u-blox/ubxlib/blob/759020036fdcff164934c697e2780f7c102b20cd/example/mqtt_client/mqtt_main.c#L361-L375

...is quite primitive: there is no way to ask the module how many messages are unread so the ubxlib code keeps a local count and that is what the top of the while loop is checking. In your actual code you should probably store the return value of uMqttClientMessageRead() in a local variable and exit the while() loop if that variable goes negative.

mos216 commented 1 month ago

Thanks Rob. This case can be closed!

RobMeades commented 1 month ago

Good stuff; I will update the example to check the return value of uMqttClientMessageRead().

RobMeades commented 4 weeks ago

Example updated in commit 08d587e371a71474aa1f353767af36cf369f6732.