joelguittet / mender-esp32-example

Mender MCU example running on ESP32 using ESP-IDF platform
MIT License
14 stars 6 forks source link

esp-x509-crt-bundle: Failed to verify certificate #11

Closed Piocky closed 1 month ago

Piocky commented 1 month ago

Hi,

I wanted to test your example before implementing it to my project, as it would be lovely for us to be able to use Mender on ESP32 (already using it with Raspberry Pi on production). But I'm getting an error after flashing your code without touching anything else than the Mender Host in SDKconfig:

I (5537) main: Running project 'mender-esp32-example' version '0.1'
I (5547) main: Mender client initialized
I (5557) mender: ./components/mender-mcu-client/mender-mcu-client/platform/storage/esp-idf/nvs/src/mender-storage.c (169): OTA ID or artifact name not available
I (5557) mender: ./components/mender-mcu-client/mender-mcu-client/platform/storage/esp-idf/nvs/src/mender-storage.c (242): Device configuration not available
I (5577) main: Mender configure initialized
I (5587) main: Mender inventory initialized
I (5587) main: Mender troubleshoot initialized
I (5597) main: Device configuration retrieved
I (7027) wifi:<ba-add>idx:1 (ifx:0, 34:60:f9:8b:a8:67), tid:0, ssn:0, winSize:64
E (7097) esp-x509-crt-bundle: Failed to verify certificate
E (7097) esp-tls-mbedtls: mbedtls_ssl_handshake returned -0x3000
E (7097) esp-tls: Failed to open new connection
E (7107) transport_base: Failed to open a new connection
E (7117) HTTP_CLIENT: Connection failed, sock < 0
E (7117) mender: ./components/mender-mcu-client/mender-mcu-client/platform/net/esp-idf/src/mender-http.c (122): Unable to open HTTP client connection: ESP_ERR_HTTP_CONNECT
E (7137) mender: ./components/mender-mcu-client/mender-mcu-client/core/src/mender-api.c (187): Unable to perform HTTP request
I (7147) main: Mender client authentication failed (1/3)

I also tried changing the mender_client_config.recommissioning from false to true, but still get the same issue:

I (5537) main: Running project 'mender-esp32-example' version '0.1'
I (5547) mender: ./components/mender-mcu-client/mender-mcu-client/platform/tls/generic/mbedtls/src/mender-tls.c (114): Delete authentication keys...
I (5557) main: Mender client initialized
I (5567) mender: ./components/mender-mcu-client/mender-mcu-client/platform/storage/esp-idf/nvs/src/mender-storage.c (90): Authentication keys are not available
I (5577) mender: ./components/mender-mcu-client/mender-mcu-client/platform/tls/generic/mbedtls/src/mender-tls.c (126): Generating authentication keys...
I (5617) mender: ./components/mender-mcu-client/mender-mcu-client/platform/storage/esp-idf/nvs/src/mender-storage.c (242): Device configuration not available
I (5617) main: Mender configure initialized
I (5627) main: Mender inventory initialized
I (5627) main: Mender troubleshoot initialized
I (5637) main: Device configuration retrieved
I (12357) mender: ./components/mender-mcu-client/mender-mcu-client/platform/storage/esp-idf/nvs/src/mender-storage.c (169): OTA ID or artifact name not available
I (13817) wifi:<ba-add>idx:1 (ifx:0, 34:60:f9:8b:a8:67), tid:0, ssn:0, winSize:64
E (13867) esp-x509-crt-bundle: Failed to verify certificate
E (13867) esp-tls-mbedtls: mbedtls_ssl_handshake returned -0x3000
E (13867) esp-tls: Failed to open new connection
E (13877) transport_base: Failed to open a new connection
E (13877) HTTP_CLIENT: Connection failed, sock < 0
E (13887) mender: ./components/mender-mcu-client/mender-mcu-client/platform/net/esp-idf/src/mender-http.c (122): Unable to open HTTP client connection: ESP_ERR_HTTP_CONNECT
E (13897) mender: ./components/mender-mcu-client/mender-mcu-client/core/src/mender-api.c (187): Unable to perform HTTP request
I (13907) main: Mender client authentication failed (1/3)

Any idea of what I'm missing here?

joelguittet commented 1 month ago

Hello @Piocky

Thanks for reporting this, looks it's not normal. I have used the mender-esp32-example beginning of April but I will test it again to check.

In the meantime can you give me the following details:

Thanks Joel

Piocky commented 1 month ago

Yes of course:

Piocky commented 1 month ago

I just tested with the hosted Mender and it works, so I guess the problem comes from the server certificate, but I don't know where to add it.

joelguittet commented 1 month ago

Good, thanks for the details! My advice will be to start with the hosted.mender.io server so you can learn and check it's working (I see you just write you have tested in parallel I was writing). Actually your issue is because the server certificate is not recognized by the device, so the TLS verification fails and connection is closed. The ESP32 has a bundle of certificates (https://docs.espressif.com/projects/esp-idf/en/stable/esp32/api-reference/protocols/esp_crt_bundle.html) so that common and well known servers are authenticated properly. Your own server is not. You will have to add the certificate of your server to the ESP32 configuration. See the link I just mentioned and particularly CONFIG_MBEDTLS_CUSTOM_CERTIFICATE_BUNDLE and CONFIG_MBEDTLS_CUSTOM_CERTIFICATE_BUNDLE_PATH options. I tested with my own mender instance too several months ago, was working but the server certificate I'm using is provided by Let's Encrypt, which is normal to be properly recognized. I don't know if you own configuration will require a modification of mender-mcu-client repo. Let me know if yes and I will be happy to receive a Pull Request to extend possibilities of the mender client covering more use case (I let this issue opened for a while for this purpose). If this is helping you you can have a look at the Zephyr examples I also made. There is no bundle and I just add the wanted certificate. of Course APIs of Zephyr and ESP-IDF are different but it's just about the global idea: https://github.com/joelguittet/mender-stm32l4a6-zephyr-example.

For reference, I just made a quick test with the current source code, latest commit of master branch, working as expected, here is the log you should have if working:

entry 0x4008064c
I (29) boot: ESP-IDF v5.0.2 2nd stage bootloader
I (29) boot: compile time 16:48:54
I (29) boot: chip revision: v1.0  
I (32) boot.esp32: SPI Speed      : 40MHz
I (36) boot.esp32: SPI Mode       : DIO  
I (41) boot.esp32: SPI Flash Size : 4MB  
I (46) boot: Enabling RNG early entropy source...
I (51) boot: Partition Table:
I (55) boot: ## Label            Usage          Type ST Offset   Length
I (62) boot:  0 nvs              WiFi data        01 02 00009000 00008000
I (69) boot:  1 otadata          OTA data         01 00 00011000 00002000
I (77) boot:  2 phy_init         RF data          01 01 00013000 00001000
I (84) boot:  3 ota_0            OTA app          00 10 00020000 001f0000
I (92) boot:  4 ota_1            OTA app          00 11 00210000 001f0000
I (99) boot: End of partition table
I (103) esp_image: segment 0: paddr=00020020 vaddr=3f400020 size=3b310h (242448) map
I (199) esp_image: segment 1: paddr=0005b338 vaddr=3ffb0000 size=033cch ( 13260) load
I (205) esp_image: segment 2: paddr=0005e70c vaddr=40080000 size=0190ch (  6412) load
I (208) esp_image: segment 3: paddr=00060020 vaddr=400d0020 size=a3d0ch (670988) map
I (456) esp_image: segment 4: paddr=00103d34 vaddr=4008190c size=13a50h ( 80464) load
I (500) boot: Loaded app from partition at offset 0x20000
I (500) boot: Disabling RNG early entropy source...
I (512) cpu_start: Pro cpu up.
I (512) cpu_start: Starting app cpu, entry point is 0x40081330
0x40081330: call_start_cpu1 at C:/Users/Storm/Documents/Electronique/Espressif/esp-idf/components/esp_system/port/cpu_start.c:141

I (0) cpu_start: App cpu up.
I (528) cpu_start: Pro cpu start user code
I (528) cpu_start: cpu freq: 160000000 Hz
I (528) cpu_start: Application information:
I (533) cpu_start: Project name:     mender-esp32-example
I (539) cpu_start: App version:      0.1
I (544) cpu_start: Compile time:     May 23 2024 16:47:59
I (550) cpu_start: ELF file SHA256:  339a38b111dccbcb...
I (556) cpu_start: ESP-IDF:          v5.0.2
I (561) cpu_start: Min chip rev:     v0.0
I (565) cpu_start: Max chip rev:     v3.99 
I (570) cpu_start: Chip rev:         v1.0
I (575) heap_init: Initializing. RAM available for dynamic allocation:
I (582) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (588) heap_init: At 3FFB79A8 len 00028658 (161 KiB): DRAM
I (594) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (601) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (607) heap_init: At 4009535C len 0000ACA4 (43 KiB): IRAM
I (615) spi_flash: detected chip: generic
I (618) spi_flash: flash io: dio
I (623) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (675) example_connect: Start example_connect.
I (695) wifi:wifi driver task: 3ffc0590, prio:23, stack:6656, core=0
I (695) system_api: Base MAC address is not set
I (695) system_api: read default base MAC address from EFUSE
I (705) wifi:wifi firmware version: 57982fe
I (705) wifi:wifi certification version: v7.0
I (705) wifi:config NVS flash: enabled
I (705) wifi:config nano formating: disabled
I (715) wifi:Init data frame dynamic rx buffer num: 32
I (715) wifi:Init management frame dynamic rx buffer num: 32
I (725) wifi:Init management short buffer num: 32
I (725) wifi:Init dynamic tx buffer num: 32
I (735) wifi:Init static rx buffer size: 1600
I (735) wifi:Init static rx buffer num: 10
I (735) wifi:Init dynamic rx buffer num: 32
I (745) wifi_init: rx ba win: 6
I (745) wifi_init: tcpip mbox: 32
I (755) wifi_init: udp mbox: 6
I (755) wifi_init: tcp mbox: 6
I (755) wifi_init: tcp tx win: 5744
I (765) wifi_init: tcp rx win: 5744
I (765) wifi_init: tcp mss: 1440
I (775) wifi_init: WiFi IRAM OP enabled
I (775) wifi_init: WiFi RX IRAM OP enabled
I (785) phy_init: phy_version 4670,719f9f6,Feb 18 2021,17:07:07
I (885) wifi:mode : sta (7c:9e:bd:ed:bc:1c)
I (885) wifi:enable tsf
I (895) example_connect: Connecting to PLATANES6-IOT-2GHZ...
I (895) example_connect: Waiting for IP(s)
I (3305) wifi:new:<4,1>, old:<1,0>, ap:<255,255>, sta:<4,1>, prof:1
I (3985) wifi:state: init -> auth (b0)
I (4125) wifi:state: auth -> assoc (0)
I (4125) wifi:state: assoc -> run (10)
I (4135) wifi:connected with PLATANES6-IOT-2GHZ, aid = 1, channel 4, 40U, bssid = ca:fb:00:03:97:ce
I (4135) wifi:security: WPA2-PSK, phy: bgn, rssi: -66
I (4135) wifi:pm start, type: 1

I (4325) wifi:AP's beacon interval = 102400 us, DTIM period = 2
I (4465) wifi:<ba-add>idx:0 (ifx:0, ca:fb:00:03:97:ce), tid:0, ssn:1, winSize:64
I (5645) esp_netif_handlers: example_netif_sta ip: 192.168.2.140, mask: 255.255.255.0, gw: 192.168.2.1
I (5645) example_connect: Got IPv4 event: Interface "example_netif_sta" address: 192.168.2.140
I (5675) example_connect: Got IPv6 event: Interface "example_netif_sta" address: fe80:0000:0000:0000:7e9e:bdff:feed:bc1c, type: 
ESP_IP6_ADDR_IS_LINK_LOCAL
I (5675) example_common: Connected to example_netif_sta
I (5685) example_common: - IPv4 address: 192.168.2.140,
I (5685) example_common: - IPv6 address: fe80:0000:0000:0000:7e9e:bdff:feed:bc1c, type: ESP_IP6_ADDR_IS_LINK_LOCAL
I (5695) main: MAC address of the device '7c:9e:bd:ed:bc:1c'
I (5705) main: Running project 'mender-esp32-example' version '0.1'
I (5725) mender: ./components/mender-mcu-client/mender-mcu-client/platform/storage/esp-idf/nvs/src/mender-storage.c (169): OTA ID or artifact name not available
I (5855) main: Mender client initialized
I (5855) mender: ./components/mender-mcu-client/mender-mcu-client/platform/storage/esp-idf/nvs/src/mender-storage.c (242): Device configuration not available
I (5865) main: Mender configure initialized
I (5865) main: Mender inventory initialized
I (5875) main: Device configuration retrieved
I (7775) esp-x509-crt-bundle: Certificate validated
I (9145) HTTP_CLIENT: Body received in fetch header state, 0x3ffcb540, 156
I (9155) main: Mender client authenticated
I (9155) mender: ./components/mender-mcu-client/mender-mcu-client/core/src/mender-client.c (440): Checking for deployment...
I (9645) esp-x509-crt-bundle: Certificate validated
I (10575) mender: ./components/mender-mcu-client/mender-mcu-client/core/src/mender-client.c (448): No deployment available
I (11195) esp-x509-crt-bundle: Certificate validated
I (13125) esp-x509-crt-bundle: Certificate validated
Piocky commented 1 month ago

Thanks for your quick answer @joelguittet. I did see the link you mentioned about esp_cert_bundle, and tried to add my server certificate in cert/server.crt then add this to the path, it still doesn't work. Also tried to skip the server certificate verification in ESP-TLS, still the same result. I know that we had some issue with this certificate as it doesn't allow us to move above Mender Server 3.1, and unfortunately we need to create a new server with new certificate (which means updating all the devices that are already on the field). It's in the pipe, but not done yet.

joelguittet commented 1 month ago

My pleasure :-) Let me know if I can help and don't hesitate to keep me updated of your progress/feedbacks in general about my mender client.

Piocky commented 1 month ago

I changed the extension from .crt to .pem, and now the certificate works...

I (5165) esp_netif_handlers: example_netif_sta ip: 192.168.0.118, mask: 255.255.255.0, gw: 192.168.0.1
I (5165) example_connect: Got IPv4 event: Interface "example_netif_sta" address: 192.168.0.118
I (5515) example_connect: Got IPv6 event: Interface "example_netif_sta" address: fe80:0000:0000:0000:deda:0cff:fe69:7834, type: ESP_IP6_ADDR_IS_LINK_LOCAL
I (5515) example_common: Connected to example_netif_sta
I (5525) example_common: - IPv4 address: 192.168.0.118,
I (5525) example_common: - IPv6 address: fe80:0000:0000:0000:deda:0cff:fe69:7834, type: ESP_IP6_ADDR_IS_LINK_LOCAL
I (5535) main: MAC address of the device 'dc:da:0c:69:78:34'
I (5545) main: Running project 'mender-esp32-example' version '0.1'
I (5565) mender: ./components/mender-mcu-client/mender-mcu-client/platform/storage/esp-idf/nvs/src/mender-storage.c (169): OTA ID or artifact name not available
I (6195) main: Mender client initialized
I (6195) mender: ./components/mender-mcu-client/mender-mcu-client/platform/storage/esp-idf/nvs/src/mender-storage.c (242): Device configuration not available
I (6285) main: Mender configure initialized
I (6285) main: Mender inventory initialized
I (6285) main: Mender troubleshoot initialized
I (6295) main: Device configuration retrieved
I (7025) wifi:<ba-add>idx:1 (ifx:0, 34:60:f9:8b:a8:67), tid:0, ssn:0, winSize:64
I (7275) esp-x509-crt-bundle: Certificate validated
E (7835) mender: ./components/mender-mcu-client/mender-mcu-client/core/src/mender-api.c (860): [405] Method Not Allowed: unknown error
I (7835) main: Mender client authentication failed (1/3)

Now I think I need to investigate on the server side to see what happens. I'll let you know if I succeed moving forward.

Thanks a lot for your work and your help :)

Piocky commented 1 month ago

Just a typo in the host path.. I had a '/' at the end, which lead to "POST //api/devices/v1/authentication/auth_requests HTTP/1.1" 405, lucky that I found it that quickly! Everything works well now, and I can see my ESP32 among my other devices:

I (5535) main: MAC address of the device 'dc:da:0c:69:78:34'
I (5545) main: Running project 'mender-esp32-example' version '0.1'
I (5565) mender: ./components/mender-mcu-client/mender-mcu-client/platform/storage/esp-idf/nvs/src/mender-storage.c (169): OTA ID or artifact name not available
I (6195) main: Mender client initialized
I (6195) mender: ./components/mender-mcu-client/mender-mcu-client/platform/storage/esp-idf/nvs/src/mender-storage.c (242): Device configuration not available
I (6285) main: Mender configure initialized
I (6285) main: Mender inventory initialized
I (6295) main: Mender troubleshoot initialized
I (6295) main: Device configuration retrieved
I (7025) wifi:<ba-add>idx:1 (ifx:0, 34:60:f9:8b:a8:67), tid:0, ssn:0, winSize:64
I (7275) esp-x509-crt-bundle: Certificate validated
I (7835) main: Mender client authenticated
I (7835) mender: ./components/mender-mcu-client/mender-mcu-client/core/src/mender-client.c (440): Checking for deployment...
I (8085) esp-x509-crt-bundle: Certificate validated
I (8625) mender: ./components/mender-mcu-client/mender-mcu-client/core/src/mender-client.c (448): No deployment available
I (8855) esp-x509-crt-bundle: Certificate validated
I (9985) esp-x509-crt-bundle: Certificate validated
I (10765) esp-x509-crt-bundle: Certificate validated
I (11295) mender: ./components/mender-mcu-client/mender-mcu-client/core/src/mender-api.c (807): Troubleshoot client connected
I (19705) mender: ./components/mender-mcu-client/mender-mcu-client/add-ons/src/mender-troubleshoot.c (663): Starting a new shell session
I (19705) main: Shell connected with width=135 and height=27
I (47945) main: Shell disconnected
I (59195) mender: ./components/mender-mcu-client/mender-mcu-client/add-ons/src/mender-troubleshoot.c (663): Starting a new shell session
I (59205) main: Shell connected with width=135 and height=27
image

So now the next step will be to have fun deploying some new image I guess :)

joelguittet commented 1 month ago

Well done !! Yeah have fun. New feature to come soon in the next release of the client ;-)

Piocky commented 1 month ago

I guess this was just too easy after all :)

I (5190) esp_netif_handlers: example_netif_sta ip: 192.168.0.118, mask: 255.255.255.0, gw: 192.168.0.1
I (5190) example_connect: Got IPv4 event: Interface "example_netif_sta" address: 192.168.0.118
I (5550) example_connect: Got IPv6 event: Interface "example_netif_sta" address: fe80:0000:0000:0000:deda:0cff:fe69:7834, type: ESP_IP6_ADDR_IS_LINK_LOCAL
I (5550) example_common: Connected to example_netif_sta
I (5560) example_common: - IPv4 address: 192.168.0.118,
I (5560) example_common: - IPv6 address: fe80:0000:0000:0000:deda:0cff:fe69:7834, type: ESP_IP6_ADDR_IS_LINK_LOCAL
I (5570) main: MAC address of the device 'dc:da:0c:69:78:34'
I (5580) main: Running project 'mender-esp32-example' version '0.2'
I (6250) main: Mender client initialized
I (6250) mender: ./components/mender-mcu-client/mender-mcu-client/platform/storage/esp-idf/nvs/src/mender-storage.c (242): Device configuration not available
I (6270) main: Mender configure initialized
I (6270) main: Mender inventory initialized
I (6280) main: Mender troubleshoot initialized
I (6280) main: Device configuration retrieved
I (7090) wifi:<ba-add>idx:1 (ifx:0, 34:60:f9:8b:a8:67), tid:0, ssn:0, winSize:64
I (7340) esp-x509-crt-bundle: Certificate validated
I (7920) main: Mender client authenticated
I (7970) mender: ./components/mender-mcu-client/mender-mcu-client/platform/ota/esp-idf/src/mender-ota.c (176): Application has been mark valid and rollback canceled
I (8210) esp-x509-crt-bundle: Certificate validated
I (8770) main: Deployment status is 'success'
I (8780) mender: ./components/mender-mcu-client/mender-mcu-client/core/src/mender-client.c (442): Checking for deployment...
I (9030) esp-x509-crt-bundle: Certificate validated
I (9590) mender: ./components/mender-mcu-client/mender-mcu-client/core/src/mender-client.c (450): No deployment available
I (9830) esp-x509-crt-bundle: Certificate validated
I (10620) esp-x509-crt-bundle: Certificate validated
I (11440) esp-x509-crt-bundle: Certificate validated
I (11980) mender: ./components/mender-mcu-client/mender-mcu-client/core/src/mender-api.c (808): Troubleshoot client connected

Thank you so much for this project! This will probably save me a lot of time investigating AWS OTA and just stick with our current workflow!

joelguittet commented 1 month ago

I m happy to see it is useful for you too!