espressif / esp-idf

Espressif IoT Development Framework. Official development framework for Espressif SoCs.
Apache License 2.0
13.82k stars 7.32k forks source link

esp_http_client mbedtls_ssl_handshake returned -0x3000 (IDFGH-13582) #14470

Closed dizcza closed 1 month ago

dizcza commented 2 months ago

Answers checklist.

IDF version.

v5.1.4-700-ge026fd1f81

Espressif SoC revision.

ESP32

Operating System used.

Linux

How did you build your project?

Command line with idf.py

If you are using Windows, please specify command line type.

None

Development Kit.

TTGO T8

Power Supply used.

USB

What is the expected behavior?

esp_http_client_perform results in ESP_OK with no mbedtls errors

What is the actual behavior?

E (12:30:14.572) esp-tls-mbedtls: mbedtls_ssl_handshake returned -0x3000
E (12:30:14.580) HTTP_CLIENT: Connection failed

Steps to reproduce.

app = Flask(__name__)
auth = HTTPBasicAuth()

@app.route("/tasks")
@auth.login_required
def tasks():
    tasks_text = """
    250 all download '2024-02-15 06:10' '2024-02-15 06:15'
    298 all download '2024-08-29 11:10' '2024-08-29 11:44'
    """
    return Response(tasks_text, status=200, mimetype="text/plain")
gunicorn --certfile /home/vps/cert/ca_cert.pem --keyfile /home/vps/cert/ca_key.pem --worker-class gevent -b 0.0.0.0:8070 app_web:app
void ota_http_client_config_init(esp_http_client_config_t *config) {
    memset(config, 0, sizeof(esp_http_client_config_t));
    config->username = ENV_OTA_SERVER_USER;
    config->password = ENV_OTA_SERVER_PASS;
    config->auth_type = HTTP_AUTH_TYPE_BASIC;
//    config->keep_alive_enable = true;
    config->timeout_ms = 10000;
    config->skip_cert_common_name_check = true;
    config->crt_bundle_attach = esp_crt_bundle_attach;
}

esp_err_t app_http_client_get_tasks(esp_http_client_handle_t client) {
    esp_task_wdt_reset();
    esp_http_client_set_url(client, "/tasks");
    esp_http_client_set_method(client, HTTP_METHOD_GET);
    esp_http_client_set_header(client, "Content-Type", "text/plain");

    while (1) {
        esp_task_wdt_reset();
        esp_err_t err = esp_http_client_perform(client);
        if (err != ESP_ERR_HTTP_EAGAIN) {
            break;
        }
        vTaskDelay(pdMS_TO_TICKS(10));
    }

    if (esp_http_client_get_status_code(client) == 200) {
        ESP_LOGI(TAG, "\n%s", app_http_client_buff);
    } else {
        ESP_LOGW(TAG, "%s status = %d, content_length = %lld",
                 __func__,
                 esp_http_client_get_status_code(client),
                 esp_http_client_get_content_length(client));
    }
    return ESP_OK;
}

void app_http_client_loop() {
    esp_http_client_config_t config;
    ota_http_client_config_init(&config);
    config.host = HTTPS_SERVER_HOST;
    config.port = HTTPS_SERVER_PORT;
    config.path = "/";
    config.event_handler = _http_event_handler;
    config.user_data = app_http_client_buff;
    config.transport_type = HTTP_TRANSPORT_OVER_SSL;
    config.is_async = true;

    esp_http_client_handle_t client = esp_http_client_init(&config);

    app_http_client_get_tasks(client);

    esp_http_client_cleanup(client);
}

Debug Logs.

esptool.py --chip esp32 -p /dev/ttyUSB0 -b 921600 --before=default_reset --after=hard_reset write_flash --flash_mode dio --flash_freq 40m --flash_size 4MB 0x1000 bootloader/bootloader.bin 0x10000 esp32-sdpsensor.bin 0x8000 partition_table/partition-table.bin 0xd000 ota_data_initial.bin
esptool.py v4.7.0
Serial port /dev/ttyUSB0
Connecting....
Chip is ESP32-D0WDQ6-V3 (revision v3.0)
Features: WiFi, BT, Dual Core, 240MHz, VRef calibration in efuse, Coding Scheme None
Crystal is 40MHz
MAC: 08:3a:f2:46:95:50
Uploading stub...
Running stub...
Stub running...
Changing baud rate to 921600
Changed.

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:5852
ho 0 tail 12 room 4
load:0x40078000,len:15240
ho 0 tail 12 room 4
load:0x40080400,len:4
load:0x40080404,len:3616
entry 0x400805f4
I (560) cpu_start: Multicore app
I (560) quad_psram: This chip is ESP32-D0WD
I (560) esp_psram: Found 8MB PSRAM device
I (562) esp_psram: Speed: 40MHz
I (566) esp_psram: PSRAM initialized, cache is in low/high (2-core) mode.
W (573) esp_psram: Virtual address not enough for PSRAM, map as much as we can. 4MB is mapped
I (583) cpu_start: Pro cpu up.
I (586) cpu_start: Starting app cpu, entry point is 0x40081554
I (0) cpu_start: App cpu up.
I (1471) esp_psram: SPI SRAM memory test OK
I (1479) cpu_start: Pro cpu start user code
I (1480) cpu_start: cpu freq: 160000000 Hz
I (1480) cpu_start: Application information:
I (1483) cpu_start: Project name:     esp32-sdpsensor
I (1489) cpu_start: App version:      c2cee4b-dirty
I (1494) cpu_start: Compile time:     Aug 30 2024 12:29:02
I (1500) cpu_start: ELF file SHA256:  d715ab4bdd9394fc...
I (1506) cpu_start: ESP-IDF:          v5.1.4-700-ge026fd1f81
I (1513) cpu_start: Min chip rev:     v3.0
I (1517) cpu_start: Max chip rev:     v3.99 
I (1522) cpu_start: Chip rev:         v3.0
I (1527) heap_init: Initializing. RAM available for dynamic allocation:
I (1535) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (1541) heap_init: At 3FFC5950 len 0001A6B0 (105 KiB): DRAM
I (1547) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (1553) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (1560) heap_init: At 4009859C len 00007A64 (30 KiB): IRAM
I (1567) esp_psram: Adding pool of 4096K of PSRAM memory to heap allocator
I (1575) spi_flash: detected chip: generic
I (1579) spi_flash: flash io: dio
I (1612) localize: save_settings OK
I (1615) sleep: Configure to isolate all GPIO pins in sleep state
I (1615) sleep: Enable automatic switching of GPIO sleep configuration
I (1631) esp_core_dump_flash: Init core dump to flash
I (1631) esp_core_dump_flash: Found partition 'coredump' @ 3f0000 65536 bytes
I (1664) esp_core_dump_flash: Core dump data checksum is correct
I (1665) esp_core_dump_flash: Found core dump 18816 bytes in flash @ 0x3f0000
I (1668) app_start: Starting scheduler on CPU0
I (0) app_start: Starting scheduler on CPU1
I (00:00:00.194) main_task: Started on CPU0
I (1698) esp_psram: Reserving pool of 32K of internal memory for DMA/internal allocations
I (00:00:00.212) main_task: Calling app_main()
I (00:00:00.218) logsync: logsync initialized
I (00:00:00.314) bsp: CHIP_ESP32 (1), features 0x0032, revision 300, cores 2
I (00:00:00.315) bsp: Board MAC 0x509546F23A08
I (00:00:00.316) i2c-easy: Initializing I2C0 SDA=32 SCL=33 clk=400000
I (00:00:00.323) gpio: GPIO[32]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 1| Intr:0 
I (00:00:00.333) gpio: GPIO[33]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 1| Intr:0 
I (00:00:00.354) board: [0] board_sdpsensor_ping_dlvr 0x28 ESP_FAIL
I (00:00:00.364) board: [1] board_sdpsensor_ping_dlvr 0x28 ESP_OK
I (00:00:00.365) board: Found DLVR pressure sensor at 0x28
I (00:00:00.369) board: Loaded board model BOARD_V0_8 (7)
I (00:00:00.373) board: ***** Board TTGO v0.8 *****
I (00:00:00.412) board: Saved board model 7
I (00:00:00.413) Wire: Wire(port=1, sda=21, scl=22) begin OK
I (00:00:00.472) ssd1306: OLED initialized
I (00:00:00.499) oled: oled_log_start OK
I (00:00:00.524) RV3032: Initializing RV3032
I (00:00:00.535) rtcm: Found RTC RV3032 at 0x51
I (00:00:00.545) RV3032: rv3032_configureBSM 0x20
I (00:00:00.555) RV3032: rv3032_configureTrickleCharge TCR 0x04 TCM 0x02
I (00:00:00.556) rtcm: RV3032 temperature: 39.88
I (00:00:00.559) rtcm: RV3032 age 0
I (00:00:00.562) rtcm: RV3032 UTC now 2024-08-30 09:30:07
I (12:30:07.000) bsp: (1725021007) 2024-08-30 12:30:07
I (12:30:07.004) bsp: UTC offset: 10800 seconds (3 hours)
I (12:30:07.036) RV3032: rv3032_configureClockOut RV3032_1HZ OK
I (12:30:07.037) rtcm: RTC SQW set 1HZ
I (12:30:07.037) GPS-UART: Initializing GPS UART
I (12:30:07.042) GPS-UART: UART baud rate 38400
I (12:30:07.047) uart: queue free spaces: 100
I (12:30:07.145) GPS-UART: GPS UART started
I (12:30:07.180) GPS: GPS loaded desired accuracy 500 cm, SIV MIN 5
I (12:30:07.183) GPS: Enabled writing GPS coordinates to SD card
W (12:30:08.037) vfs: esp_vfs_register_fd_range is successful for range <54; 64) and VFS ID 2
I (3108) wifi:wifi driver task: 3ffdfd88, prio:23, stack:6656, core=0
I (3118) wifi:wifi firmware version: 7656a3f
I (3118) wifi:wifi certification version: v7.0
I (3128) wifi:config NVS flash: enabled
I (3128) wifi:config nano formating: disabled
I (3128) wifi:Init data frame dynamic rx buffer num: 32
I (3128) wifi:Init static rx mgmt buffer num: 5
I (3138) wifi:Init management short buffer num: 32
I (3138) wifi:Init static tx buffer num: 16
I (3148) wifi:Init tx cache buffer num: 32
I (3148) wifi:Init static rx buffer size: 1600
I (3158) wifi:Init static rx buffer num: 10
I (3158) wifi:Init dynamic rx buffer num: 32
I (12:30:08.104) wifi_init: rx ba win: 6
I (12:30:08.107) wifi_init: tcpip mbox: 32
I (12:30:08.112) wifi_init: udp mbox: 6
I (12:30:08.116) wifi_init: tcp mbox: 6
I (12:30:08.121) wifi_init: tcp tx win: 5744
I (12:30:08.126) wifi_init: tcp rx win: 5744
I (12:30:08.131) wifi_init: tcp mss: 1440
I (12:30:08.135) wifi_init: WiFi IRAM OP enabled
I (12:30:08.140) wifi_init: WiFi RX IRAM OP enabled
I (12:30:08.146) wifi_sta: Connecting to 'Dizcza' AUTH 3
I (12:30:08.155) phy_init: phy_version 4830,54550f7,Jun 20 2024,14:22:08
I (3298) wifi:mode : sta (08:3a:f2:46:95:50)
I (3298) wifi:enable tsf
I (3308) wifi:new:<1,1>, old:<1,0>, ap:<255,255>, sta:<1,1>, prof:1
I (3318) wifi:state: init -> auth (b0)
I (3318) wifi:state: auth -> assoc (0)
I (3328) wifi:state: assoc -> run (10)
I (3348) wifi:connected with Dizcza, aid = 17, channel 1, 40U, bssid = 60:aa:ef:13:aa:68
I (3348) wifi:security: WPA2-PSK, phy: bgn, rssi: -31
I (3348) wifi:pm start, type: 1

I (3348) wifi:dp: 1, bi: 102400, li: 3, scale listen interval from 307200 us to 307200 us
I (3358) wifi:AP's beacon interval = 102400 us, DTIM period = 1
I (12:30:09.297) esp_netif_handlers: sta ip: 192.168.3.113, mask: 255.255.255.0, gw: 192.168.3.1
I (12:30:09.299) wifi_sta: WiFi connection established
I (12:30:09.303) sdcard: Mounting SD MMC...
I (12:30:09.357) sdcard: SD card mounted at /sd
Name: SD32G
Type: SDHC/SDXC
Speed: 40.00 MHz (limit: 40.00 MHz)
Size: 29874MB
CSD: ver=2, sector_size=512, capacity=61182976 read_bl_len=9
SSR: bus_width=1
Free: 29727MB
I (12:30:09.370) sdcard: /sd/RECORDS_SDP exists
I (12:30:09.489) sdcard: mkdir /sd/RECORDS_SDP/073 OK
I (12:30:09.507) sdcard: logging to '/sd/RECORDS_SDP/073/LOG.LOG'
I (12:30:09.541) bsp: App version:   c2cee4b-dirty
I (12:30:09.548) bsp: Compile time:  Aug 30 2024 12:29:02
I (12:30:09.551) bsp: ESP-IDF:       v5.1.4-700-ge026fd1f81
I (12:30:09.554) ota: Running partition: ota_0, offset 0x00010000, size 0x001f0000
I (12:30:09.574) ota: ota_state ESP_OTA_IMG_VALID
I (12:30:09.589) coredump: Summary:
I (12:30:09.594) coredump: exc_task: main???????????
I (12:30:09.597) coredump: exc_pc: 1075318741
I (12:30:09.601) coredump: App SHA:
I (12:30:09.604) coredump: 65 66 39 36 31 34 31 38 38 39 33 61 34 39 64 35 
I (12:30:09.614) coredump: exc_bt_info->bt:
I (12:30:09.617) coredump: d5 0f 18 40 71 10 18 40 a1 01 0e 40 9b fa 0d 40 
I (12:30:09.625) coredump: exc_bt_info->depth: 17
I (12:30:09.630) coredump: exc_bt_info->corrupted: 0
I (12:30:09.636) coredump: exc_info->exc_cause: 0
I (12:30:09.640) coredump: exc_info->exc_vaddr: 0
I (12:30:09.645) coredump: ex_info->exc_a:
I (12:30:09.650) coredump: 74 10 18 80 60 ab fc 3f 4e 00 00 00 4e 00 00 00 
I (12:30:09.658) coredump: ex_info->epcx:
I (12:30:09.662) coredump: f7 1e 0e 40 00 00 
I (12:30:09.670) coredump: core dump addr: 4128768
I (12:30:09.674) coredump: core dump size: 18816
I (12:30:09.683) sdcard: Opened /sd/RECORDS_SDP/073/COREDUMP.BIN
I (12:30:09.708) webserver: Starting server on port: 80
I (12:30:09.718) webserver: webserver_start OK
I (12:30:09.726) logsync: logsync_early_stop
I (12:30:09.729) logsync: logsync_early_delete OK
I (12:30:09.734) syncman: RTC type 2
I (12:30:09.740) gpio: GPIO[34]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (12:30:09.746) gpio: GPIO[4]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 1| Intr:0 
I (12:30:09.756) syncman: MCPWM started (pin RTC 34 PPS 4)
I (12:30:09.762) syncman: esp_clk_apb_freq 80000000
I (12:30:09.766) sdprecord: Initializing sdprecord
I (12:30:09.772) i2c-easy: Initializing I2C0 SDA=32 SCL=33 clk=400000
I (12:30:09.780) gpio: GPIO[32]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 1| Intr:0 
I (12:30:09.793) gpio: GPIO[33]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 1| Intr:0 
I (12:30:10.806) sdpsensor: DLVR P 2.126 Pa, T 38.72 C
I (12:30:11.482) gpio: GPIO[34]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:1 
I (12:30:11.487) rtcm: rtcm_sync_attach_irq OK
I (12:30:11.490) rtcm: rtcm_sync_init time start 1725010212
I (12:30:11.502) sdcard: Opened /sd/RECORDS_SDP/073/RTC_SDP_SYNC.CSV
I (12:30:11.522) recordbuf: RECORDBUF_MAX_LAG 7
I (12:30:11.564) recordbuf: RECORDBUF THR ONSET 4.00 TRIG 6.00 OFFSET 2.00
I (12:30:11.573) recordbuf: RECORDBUF THR NN PROBA 0.50
I (12:30:11.579) recordbuf: RECORDBUF THR XCORR 0.80
I (12:30:11.586) sdprecord: Heap avail 4033 Kb, records queue size 100000
I (12:30:11.590) sdprecord: sdprecord_read_sensor_task started
I (12:30:11.597) sdcard: Opened /sd/RECORDS_SDP/073/DLVR-000.BIN
I (12:30:11.601) gpio: GPIO[39]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 0| Pulldown: 1| Intr:1 
I (12:30:11.604) sdprecord: sdprecord_init OK
I (12:30:11.612) sdprecord: sdprecord_init_drdy_interrupt OK
W (12:30:11.621) app_http: loaded task global id: 298
I (12:30:11.633) GPS-UART: minmea_gettime failed x1
I (12:30:12.553) sdprecord: [q 579] [r 1293 635 54296 4800] [dp 9 -0.18 0.20 rms 0.07 pp 0.38] [h 3439]
I (12:30:12.655) mbedtls: ssl_tls.c:4606 => handshake

I (12:30:12.660) mbedtls: ssl_msg.c:2353 => flush output

I (12:30:12.663) mbedtls: ssl_msg.c:2362 <= flush output

I (12:30:12.667) mbedtls: ssl_tls.c:4525 client state: MBEDTLS_SSL_HELLO_REQUEST

I (12:30:12.677) mbedtls: ssl_msg.c:2353 => flush output

I (12:30:12.681) mbedtls: ssl_msg.c:2362 <= flush output

I (12:30:12.686) mbedtls: ssl_tls.c:4525 client state: MBEDTLS_SSL_CLIENT_HELLO

I (12:30:12.696) mbedtls: ssl_client.c:919 => write client hello

I (12:30:12.712) mbedtls: ssl_msg.c:2783 => write handshake message

I (12:30:12.717) mbedtls: ssl_msg.c:2943 => write record

I (12:30:12.722) mbedtls: ssl_msg.c:3080 <= write record

I (12:30:12.726) mbedtls: ssl_msg.c:2904 <= write handshake message

I (12:30:12.731) mbedtls: ssl_client.c:1012 <= write client hello

I (12:30:12.738) mbedtls: ssl_msg.c:2353 => flush output

I (12:30:12.748) mbedtls: ssl_msg.c:2367 message length: 224, out_left: 224

I (12:30:12.757) mbedtls: ssl_msg.c:2374 ssl->f_send() returned 224 (-0xffffff20)

I (12:30:12.762) mbedtls: ssl_msg.c:2401 <= flush output

I (12:30:12.766) mbedtls: ssl_tls.c:4525 client state: MBEDTLS_SSL_SERVER_HELLO

I (12:30:12.775) mbedtls: ssl_tls12_client.c:1193 => parse server hello

I (12:30:12.782) mbedtls: ssl_msg.c:4189 => read record

I (12:30:12.789) mbedtls: ssl_msg.c:2155 => fetch input

I (12:30:12.794) mbedtls: ssl_msg.c:2295 in_left: 0, nb_want: 5

I (12:30:12.802) mbedtls: ssl_msg.c:2315 in_left: 0, nb_want: 5

I (12:30:12.812) mbedtls: ssl_tls.c:4617 <= handshake

I (12:30:12.825) mbedtls: ssl_tls.c:4606 => handshake

I (12:30:12.829) mbedtls: ssl_msg.c:2353 => flush output

I (12:30:12.833) mbedtls: ssl_msg.c:2362 <= flush output

I (12:30:12.837) mbedtls: ssl_tls.c:4525 client state: MBEDTLS_SSL_SERVER_HELLO

I (12:30:12.844) mbedtls: ssl_tls12_client.c:1193 => parse server hello

I (12:30:12.852) mbedtls: ssl_msg.c:4189 => read record

I (12:30:12.858) mbedtls: ssl_msg.c:2155 => fetch input

I (12:30:12.864) mbedtls: ssl_msg.c:2295 in_left: 0, nb_want: 5

I (12:30:12.874) mbedtls: ssl_msg.c:2315 in_left: 0, nb_want: 5

I (12:30:12.878) mbedtls: ssl_msg.c:2318 ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)

I (12:30:12.887) mbedtls: ssl_msg.c:2340 <= fetch input

I (12:30:12.892) mbedtls: ssl_msg.c:2155 => fetch input

I (12:30:12.900) mbedtls: ssl_msg.c:2295 in_left: 5, nb_want: 70

I (12:30:12.907) mbedtls: ssl_msg.c:2315 in_left: 5, nb_want: 70

I (12:30:12.915) mbedtls: ssl_msg.c:2318 ssl->f_recv(_timeout)() returned 65 (-0xffffffbf)

I (12:30:12.921) mbedtls: ssl_msg.c:2340 <= fetch input

I (12:30:12.929) mbedtls: ssl_msg.c:4261 <= read record

I (12:30:12.937) mbedtls: ssl_tls12_client.c:1445 server hello, total extension length: 21

I (12:30:12.943) mbedtls: ssl_tls12_client.c:1659 <= parse server hello

I (12:30:12.950) mbedtls: ssl_msg.c:2353 => flush output

I (12:30:12.955) mbedtls: ssl_msg.c:2362 <= flush output

I (12:30:12.962) mbedtls: ssl_tls.c:4525 client state: MBEDTLS_SSL_SERVER_CERTIFICATE

I (12:30:12.972) mbedtls: ssl_tls.c:8186 => parse certificate

I (12:30:12.977) mbedtls: ssl_msg.c:4189 => read record

I (12:30:12.983) mbedtls: ssl_msg.c:2155 => fetch input

I (12:30:12.989) mbedtls: ssl_msg.c:2295 in_left: 0, nb_want: 5

I (12:30:12.997) mbedtls: ssl_msg.c:2315 in_left: 0, nb_want: 5

I (12:30:13.006) mbedtls: ssl_msg.c:2318 ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)

I (12:30:13.012) mbedtls: ssl_msg.c:2340 <= fetch input

I (12:30:13.020) mbedtls: ssl_msg.c:2155 => fetch input

I (12:30:13.024) mbedtls: ssl_msg.c:2295 in_left: 5, nb_want: 960

I (12:30:13.031) mbedtls: ssl_msg.c:2315 in_left: 5, nb_want: 960

I (12:30:13.038) mbedtls: ssl_msg.c:2318 ssl->f_recv(_timeout)() returned 955 (-0xfffffc45)

I (12:30:13.047) mbedtls: ssl_msg.c:2340 <= fetch input

I (12:30:13.061) mbedtls: ssl_msg.c:4261 <= read record

E (12:30:13.073) esp-x509-crt-bundle: PK verify failed with error FFFFBD70
E (12:30:13.090) esp-x509-crt-bundle: Failed to verify certificate
W (12:30:13.095) mbedtls: ssl_tls.c:8006 x509_verify_cert() returned -12288 (-0x3000)

I (12:30:13.099) mbedtls: ssl_msg.c:5168 => send alert message

I (12:30:13.105) mbedtls: ssl_msg.c:2943 => write record

I (12:30:13.112) mbedtls: ssl_msg.c:2353 => flush output

I (12:30:13.120) mbedtls: ssl_msg.c:2367 message length: 7, out_left: 7

I (12:30:13.130) mbedtls: ssl_msg.c:2374 ssl->f_send() returned 7 (-0xfffffff9)

I (12:30:13.135) mbedtls: ssl_msg.c:2401 <= flush output

I (12:30:13.139) mbedtls: ssl_msg.c:3080 <= write record

I (12:30:13.147) mbedtls: ssl_msg.c:5180 <= send alert message

I (12:30:13.151) mbedtls: ssl_tls.c:4617 <= handshake

E (12:30:13.157) esp-tls-mbedtls: mbedtls_ssl_handshake returned -0x3000
E (12:30:13.165) HTTP_CLIENT: Connection failed
W (12:30:13.170) app_http: app_http_client_get_tasks status = 0, content_length = 0
I (12:30:13.291) sdprecord: [q 579] [r 1538 547 151374 4800] [dp -1 -0.18 0.20 rms 0.07 pp 0.38] [h 3407]
I (12:30:13.390) mbedtls: ssl_tls.c:4606 => handshake

I (12:30:13.395) mbedtls: ssl_msg.c:2353 => flush output

I (12:30:13.402) mbedtls: ssl_msg.c:2362 <= flush output

I (12:30:13.405) mbedtls: ssl_tls.c:4525 client state: MBEDTLS_SSL_HELLO_REQUEST

I (12:30:13.410) mbedtls: ssl_msg.c:2353 => flush output

I (12:30:13.415) mbedtls: ssl_msg.c:2362 <= flush output

I (12:30:13.422) mbedtls: ssl_tls.c:4525 client state: MBEDTLS_SSL_CLIENT_HELLO

I (12:30:13.431) mbedtls: ssl_client.c:919 => write client hello

I (12:30:13.449) mbedtls: ssl_msg.c:2783 => write handshake message

I (12:30:13.453) mbedtls: ssl_msg.c:2943 => write record

I (12:30:13.459) mbedtls: ssl_msg.c:3080 <= write record

I (12:30:13.467) mbedtls: ssl_msg.c:2904 <= write handshake message

I (12:30:13.470) mbedtls: ssl_client.c:1012 <= write client hello

I (12:30:13.475) mbedtls: ssl_msg.c:2353 => flush output

I (12:30:13.481) mbedtls: ssl_msg.c:2367 message length: 224, out_left: 224

I (12:30:13.494) mbedtls: ssl_msg.c:2374 ssl->f_send() returned 224 (-0xffffff20)

I (12:30:13.499) mbedtls: ssl_msg.c:2401 <= flush output

I (12:30:13.504) mbedtls: ssl_tls.c:4525 client state: MBEDTLS_SSL_SERVER_HELLO

I (12:30:13.511) mbedtls: ssl_tls12_client.c:1193 => parse server hello

I (12:30:13.519) mbedtls: ssl_msg.c:4189 => read record

I (12:30:13.527) mbedtls: ssl_msg.c:2155 => fetch input

I (12:30:13.531) mbedtls: ssl_msg.c:2295 in_left: 0, nb_want: 5

I (12:30:13.537) mbedtls: ssl_msg.c:2315 in_left: 0, nb_want: 5

I (12:30:13.546) mbedtls: ssl_tls.c:4617 <= handshake

I (12:30:13.555) mbedtls: ssl_tls.c:4606 => handshake

I (12:30:13.559) mbedtls: ssl_msg.c:2353 => flush output

I (12:30:13.563) mbedtls: ssl_msg.c:2362 <= flush output

I (12:30:13.568) mbedtls: ssl_tls.c:4525 client state: MBEDTLS_SSL_SERVER_HELLO

I (12:30:13.576) mbedtls: ssl_tls12_client.c:1193 => parse server hello

I (12:30:13.584) mbedtls: ssl_msg.c:4189 => read record

I (12:30:13.592) mbedtls: ssl_msg.c:2155 => fetch input

I (12:30:13.601) mbedtls: ssl_msg.c:2295 in_left: 0, nb_want: 5

I (12:30:13.606) mbedtls: ssl_msg.c:2315 in_left: 0, nb_want: 5

I (12:30:13.610) mbedtls: ssl_msg.c:2318 ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)

I (12:30:13.618) mbedtls: ssl_msg.c:2340 <= fetch input

I (12:30:13.626) mbedtls: ssl_msg.c:2155 => fetch input

I (12:30:13.633) mbedtls: ssl_msg.c:2295 in_left: 5, nb_want: 70

I (12:30:13.638) mbedtls: ssl_msg.c:2315 in_left: 5, nb_want: 70

I (12:30:13.646) mbedtls: ssl_msg.c:2318 ssl->f_recv(_timeout)() returned 65 (-0xffffffbf)

I (12:30:13.657) mbedtls: ssl_msg.c:2340 <= fetch input

I (12:30:13.662) mbedtls: ssl_msg.c:4261 <= read record

I (12:30:13.667) mbedtls: ssl_tls12_client.c:1445 server hello, total extension length: 21

I (12:30:13.675) mbedtls: ssl_tls12_client.c:1659 <= parse server hello

I (12:30:13.682) mbedtls: ssl_msg.c:2353 => flush output

I (12:30:13.689) mbedtls: ssl_msg.c:2362 <= flush output

I (12:30:13.694) mbedtls: ssl_tls.c:4525 client state: MBEDTLS_SSL_SERVER_CERTIFICATE

I (12:30:13.702) mbedtls: ssl_tls.c:8186 => parse certificate

I (12:30:13.709) mbedtls: ssl_msg.c:4189 => read record

I (12:30:13.718) mbedtls: ssl_msg.c:2155 => fetch input

I (12:30:13.721) mbedtls: ssl_msg.c:2295 in_left: 0, nb_want: 5

I (12:30:13.730) mbedtls: ssl_msg.c:2315 in_left: 0, nb_want: 5

I (12:30:13.738) mbedtls: ssl_msg.c:2318 ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)

I (12:30:13.743) mbedtls: ssl_msg.c:2340 <= fetch input

I (12:30:13.750) mbedtls: ssl_msg.c:2155 => fetch input

I (12:30:13.756) mbedtls: ssl_msg.c:2295 in_left: 5, nb_want: 960

I (12:30:13.763) mbedtls: ssl_msg.c:2315 in_left: 5, nb_want: 960

I (12:30:13.770) mbedtls: ssl_msg.c:2318 ssl->f_recv(_timeout)() returned 955 (-0xfffffc45)

I (12:30:13.783) mbedtls: ssl_msg.c:2340 <= fetch input

I (12:30:13.795) mbedtls: ssl_msg.c:4261 <= read record

E (12:30:13.806) esp-x509-crt-bundle: PK verify failed with error FFFFBD70
E (12:30:13.811) esp-x509-crt-bundle: Failed to verify certificate
W (12:30:13.815) mbedtls: ssl_tls.c:8006 x509_verify_cert() returned -12288 (-0x3000)

I (12:30:13.823) mbedtls: ssl_msg.c:5168 => send alert message

I (12:30:13.835) mbedtls: ssl_msg.c:2943 => write record

I (12:30:13.840) mbedtls: ssl_msg.c:2353 => flush output

I (12:30:13.843) mbedtls: ssl_msg.c:2367 message length: 7, out_left: 7

I (12:30:13.853) mbedtls: ssl_msg.c:2374 ssl->f_send() returned 7 (-0xfffffff9)

I (12:30:13.861) mbedtls: ssl_msg.c:2401 <= flush output

I (12:30:13.864) mbedtls: ssl_msg.c:3080 <= write record

I (12:30:13.869) mbedtls: ssl_msg.c:5180 <= send alert message

I (12:30:13.877) mbedtls: ssl_tls.c:4617 <= handshake

E (12:30:13.881) esp-tls-mbedtls: mbedtls_ssl_handshake returned -0x3000
E (12:30:13.889) HTTP_CLIENT: Connection failed
W (12:30:13.894) app_http: app_http_client_get_tasks status = 0, content_length = 0
I (12:30:13.968) sdprecord: [q 579] [r 1460 429 151374 4800] [dp 7 -0.18 0.20 rms 0.07 pp 0.38] [h 3407]
I (12:30:14.072) mbedtls: ssl_tls.c:4606 => handshake

I (12:30:14.080) mbedtls: ssl_msg.c:2353 => flush output

I (12:30:14.084) mbedtls: ssl_msg.c:2362 <= flush output

I (12:30:14.088) mbedtls: ssl_tls.c:4525 client state: MBEDTLS_SSL_HELLO_REQUEST

I (12:30:14.094) mbedtls: ssl_msg.c:2353 => flush output

I (12:30:14.100) mbedtls: ssl_msg.c:2362 <= flush output

I (12:30:14.106) mbedtls: ssl_tls.c:4525 client state: MBEDTLS_SSL_CLIENT_HELLO

I (12:30:14.114) mbedtls: ssl_client.c:919 => write client hello

I (12:30:14.131) mbedtls: ssl_msg.c:2783 => write handshake message

I (12:30:14.137) mbedtls: ssl_msg.c:2943 => write record

I (12:30:14.147) mbedtls: ssl_msg.c:3080 <= write record

I (12:30:14.152) mbedtls: ssl_msg.c:2904 <= write handshake message

I (12:30:14.155) mbedtls: ssl_client.c:1012 <= write client hello

I (12:30:14.160) mbedtls: ssl_msg.c:2353 => flush output

I (12:30:14.167) mbedtls: ssl_msg.c:2367 message length: 224, out_left: 224

I (12:30:14.180) mbedtls: ssl_msg.c:2374 ssl->f_send() returned 224 (-0xffffff20)

I (12:30:14.185) mbedtls: ssl_msg.c:2401 <= flush output

I (12:30:14.189) mbedtls: ssl_tls.c:4525 client state: MBEDTLS_SSL_SERVER_HELLO

I (12:30:14.197) mbedtls: ssl_tls12_client.c:1193 => parse server hello

I (12:30:14.207) mbedtls: ssl_msg.c:4189 => read record

I (12:30:14.211) mbedtls: ssl_msg.c:2155 => fetch input

I (12:30:14.217) mbedtls: ssl_msg.c:2295 in_left: 0, nb_want: 5

I (12:30:14.223) mbedtls: ssl_msg.c:2315 in_left: 0, nb_want: 5

I (12:30:14.231) mbedtls: ssl_tls.c:4617 <= handshake

I (12:30:14.246) mbedtls: ssl_tls.c:4606 => handshake

I (12:30:14.250) mbedtls: ssl_msg.c:2353 => flush output

I (12:30:14.254) mbedtls: ssl_msg.c:2362 <= flush output

I (12:30:14.257) mbedtls: ssl_tls.c:4525 client state: MBEDTLS_SSL_SERVER_HELLO

I (12:30:14.269) mbedtls: ssl_tls12_client.c:1193 => parse server hello

I (12:30:14.272) mbedtls: ssl_msg.c:4189 => read record

I (12:30:14.278) mbedtls: ssl_msg.c:2155 => fetch input

I (12:30:14.286) mbedtls: ssl_msg.c:2295 in_left: 0, nb_want: 5

I (12:30:14.292) mbedtls: ssl_msg.c:2315 in_left: 0, nb_want: 5

I (12:30:14.298) mbedtls: ssl_msg.c:2318 ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)

I (12:30:14.307) mbedtls: ssl_msg.c:2340 <= fetch input

I (12:30:14.314) mbedtls: ssl_msg.c:2155 => fetch input

I (12:30:14.319) mbedtls: ssl_msg.c:2295 in_left: 5, nb_want: 70

I (12:30:14.326) mbedtls: ssl_msg.c:2315 in_left: 5, nb_want: 70

I (12:30:14.335) mbedtls: ssl_msg.c:2318 ssl->f_recv(_timeout)() returned 65 (-0xffffffbf)

I (12:30:14.343) mbedtls: ssl_msg.c:2340 <= fetch input

I (12:30:14.355) mbedtls: ssl_msg.c:4261 <= read record

I (12:30:14.360) mbedtls: ssl_tls12_client.c:1445 server hello, total extension length: 21

I (12:30:14.366) mbedtls: ssl_tls12_client.c:1659 <= parse server hello

I (12:30:14.372) mbedtls: ssl_msg.c:2353 => flush output

I (12:30:14.378) mbedtls: ssl_msg.c:2362 <= flush output

I (12:30:14.385) mbedtls: ssl_tls.c:4525 client state: MBEDTLS_SSL_SERVER_CERTIFICATE

I (12:30:14.393) mbedtls: ssl_tls.c:8186 => parse certificate

I (12:30:14.403) mbedtls: ssl_msg.c:4189 => read record

I (12:30:14.408) mbedtls: ssl_msg.c:2155 => fetch input

I (12:30:14.411) mbedtls: ssl_msg.c:2295 in_left: 0, nb_want: 5

I (12:30:14.419) mbedtls: ssl_msg.c:2315 in_left: 0, nb_want: 5

I (12:30:14.425) mbedtls: ssl_msg.c:2318 ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)

I (12:30:14.434) mbedtls: ssl_msg.c:2340 <= fetch input

I (12:30:14.440) mbedtls: ssl_msg.c:2155 => fetch input

I (12:30:14.449) mbedtls: ssl_msg.c:2295 in_left: 5, nb_want: 960

I (12:30:14.456) mbedtls: ssl_msg.c:2315 in_left: 5, nb_want: 960

I (12:30:14.463) mbedtls: ssl_msg.c:2318 ssl->f_recv(_timeout)() returned 955 (-0xfffffc45)

I (12:30:14.469) mbedtls: ssl_msg.c:2340 <= fetch input

I (12:30:14.484) mbedtls: ssl_msg.c:4261 <= read record

E (12:30:14.495) esp-x509-crt-bundle: PK verify failed with error FFFFBD70
E (12:30:14.500) esp-x509-crt-bundle: Failed to verify certificate
W (12:30:14.505) mbedtls: ssl_tls.c:8006 x509_verify_cert() returned -12288 (-0x3000)

I (12:30:14.512) mbedtls: ssl_msg.c:5168 => send alert message

I (12:30:14.518) mbedtls: ssl_msg.c:2943 => write record

I (12:30:14.524) mbedtls: ssl_msg.c:2353 => flush output

I (12:30:14.530) mbedtls: ssl_msg.c:2367 message length: 7, out_left: 7

I (12:30:14.546) mbedtls: ssl_msg.c:2374 ssl->f_send() returned 7 (-0xfffffff9)

I (12:30:14.554) mbedtls: ssl_msg.c:2401 <= flush output

I (12:30:14.557) mbedtls: ssl_msg.c:3080 <= write record

I (12:30:14.561) mbedtls: ssl_msg.c:5180 <= send alert message

I (12:30:14.567) mbedtls: ssl_tls.c:4617 <= handshake

E (12:30:14.572) esp-tls-mbedtls: mbedtls_ssl_handshake returned -0x3000
E (12:30:14.580) HTTP_CLIENT: Connection failed
W (12:30:14.585) app_http: app_http_client_get_tasks status = 0, content_length = 0
I (12:30:14.672) sdprecord: [q 579] [r 1328 330 151374 4851] [dp 12 -0.18 0.22 rms 0.07 pp 0.40] [h 3407]
I (12:30:14.774) mbedtls: ssl_tls.c:4606 => handshake

I (12:30:14.780) mbedtls: ssl_msg.c:2353 => flush output

I (12:30:14.783) mbedtls: ssl_msg.c:2362 <= flush output

I (12:30:14.787) mbedtls: ssl_tls.c:4525 client state: MBEDTLS_SSL_HELLO_REQUEST

I (12:30:14.794) mbedtls: ssl_msg.c:2353 => flush output

I (12:30:14.800) mbedtls: ssl_msg.c:2362 <= flush output

I (12:30:14.807) mbedtls: ssl_tls.c:4525 client state: MBEDTLS_SSL_CLIENT_HELLO

I (12:30:14.817) mbedtls: ssl_client.c:919 => write client hello

I (12:30:14.828) mbedtls: ssl_msg.c:2783 => write handshake message

I (12:30:14.834) mbedtls: ssl_msg.c:2943 => write record

I (12:30:14.840) mbedtls: ssl_msg.c:3080 <= write record

I (12:30:14.844) mbedtls: ssl_msg.c:2904 <= write handshake message

I (12:30:14.852) mbedtls: ssl_client.c:1012 <= write client hello

I (12:30:14.859) mbedtls: ssl_msg.c:2353 => flush output

I (12:30:14.863) mbedtls: ssl_msg.c:2367 message length: 224, out_left: 224

I (12:30:14.875) mbedtls: ssl_msg.c:2374 ssl->f_send() returned 224 (-0xffffff20)

I (12:30:14.881) mbedtls: ssl_msg.c:2401 <= flush output

I (12:30:14.888) mbedtls: ssl_tls.c:4525 client state: MBEDTLS_SSL_SERVER_HELLO

I (12:30:14.893) mbedtls: ssl_tls12_client.c:1193 => parse server hello

I (12:30:14.901) mbedtls: ssl_msg.c:4189 => read record

I (12:30:14.906) mbedtls: ssl_msg.c:2155 => fetch input

I (12:30:14.913) mbedtls: ssl_msg.c:2295 in_left: 0, nb_want: 5

I (12:30:14.920) mbedtls: ssl_msg.c:2315 in_left: 0, nb_want: 5

I (12:30:14.927) mbedtls: ssl_tls.c:4617 <= handshake

I (12:30:14.935) mbedtls: ssl_tls.c:4606 => handshake

I (12:30:14.940) mbedtls: ssl_msg.c:2353 => flush output

I (12:30:14.947) mbedtls: ssl_msg.c:2362 <= flush output

I (12:30:14.951) mbedtls: ssl_tls.c:4525 client state: MBEDTLS_SSL_SERVER_HELLO

I (12:30:14.958) mbedtls: ssl_tls12_client.c:1193 => parse server hello

I (12:30:14.966) mbedtls: ssl_msg.c:4189 => read record

I (12:30:14.971) mbedtls: ssl_msg.c:2155 => fetch input

I (12:30:14.978) mbedtls: ssl_msg.c:2295 in_left: 0, nb_want: 5

I (12:30:14.986) mbedtls: ssl_msg.c:2315 in_left: 0, nb_want: 5

I (12:30:14.993) mbedtls: ssl_msg.c:2318 ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)

I (12:30:15.000) mbedtls: ssl_msg.c:2340 <= fetch input

I (12:30:15.009) mbedtls: ssl_msg.c:2155 => fetch input

I (12:30:15.012) mbedtls: ssl_msg.c:2295 in_left: 5, nb_want: 70

I (12:30:15.019) mbedtls: ssl_msg.c:2315 in_left: 5, nb_want: 70

I (12:30:15.026) mbedtls: ssl_msg.c:2318 ssl->f_recv(_timeout)() returned 65 (-0xffffffbf)

I (12:30:15.036) mbedtls: ssl_msg.c:2340 <= fetch input

I (12:30:15.042) mbedtls: ssl_msg.c:4261 <= read record

I (12:30:15.048) mbedtls: ssl_tls12_client.c:1445 server hello, total extension length: 21

I (12:30:15.058) mbedtls: ssl_tls12_client.c:1659 <= parse server hello

I (12:30:15.065) mbedtls: ssl_msg.c:2353 => flush output

I (12:30:15.069) mbedtls: ssl_msg.c:2362 <= flush output

I (12:30:15.084) mbedtls: ssl_tls.c:4525 client state: MBEDTLS_SSL_SERVER_CERTIFICATE

I (12:30:15.089) mbedtls: ssl_tls.c:8186 => parse certificate

I (12:30:15.092) mbedtls: ssl_msg.c:4189 => read record

I (12:30:15.103) mbedtls: ssl_msg.c:2155 => fetch input

I (12:30:15.107) mbedtls: ssl_msg.c:2295 in_left: 0, nb_want: 5

I (12:30:15.112) mbedtls: ssl_msg.c:2315 in_left: 0, nb_want: 5

I (12:30:15.119) mbedtls: ssl_msg.c:2318 ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)

I (12:30:15.128) mbedtls: ssl_msg.c:2340 <= fetch input

I (12:30:15.134) mbedtls: ssl_msg.c:2155 => fetch input

I (12:30:15.142) mbedtls: ssl_msg.c:2295 in_left: 5, nb_want: 960

I (12:30:15.147) mbedtls: ssl_msg.c:2315 in_left: 5, nb_want: 960

I (12:30:15.154) mbedtls: ssl_msg.c:2318 ssl->f_recv(_timeout)() returned 955 (-0xfffffc45)

I (12:30:15.163) mbedtls: ssl_msg.c:2340 <= fetch input

I (12:30:15.179) mbedtls: ssl_msg.c:4261 <= read record

E (12:30:15.190) esp-x509-crt-bundle: PK verify failed with error FFFFFFF0
E (12:30:15.192) diskio_sdmmc: sdmmc_write_blocks failed (257)
E (12:30:15.285) diskio_sdmmc: sdmmc_write_blocks failed (257)
E (12:30:15.386) diskio_sdmmc: sdmmc_read_blocks failed (257)
E (12:30:15.485) esp-x509-crt-bundle: Failed to verify certificate
Guru Meditation Error: Core  0 panic'ed (LoadProhibited). Exception was unhandled.

Core  0 register dump:
PC      : 0x40187b88  PS      : 0x00060730  A0      : 0x80187c24  A1      : 0x3ffce860  
A2      : 0x0000004e  A3      : 0x0000004e  A4      : 0x00000001  A5      : 0x0000004e  
A6      : 0x00000000  A7      : 0x3ffcf0a0  A8      : 0x80187b88  A9      : 0x3ffce840  
A10     : 0x00000000  A11     : 0x3ffce874  A12     : 0x00060920  A13     : 0x00000043  
A14     : 0x3ffce76c  A15     : 0x3ffce890  SAR     : 0x00000018  EXCCAUSE: 0x0000001c  
EXCVADDR: 0x00000064  LBEG    : 0x4000c349  LEND    : 0x4000c36b  LCOUNT  : 0x00000000  

Backtrace: 0x40187b85:0x3ffce860 0x40187c21:0x3ffce8a0 0x400e0181:0x3ffce8c0 0x400dfa7b:0x3ffce960 0x401b28fd:0x3ffce990 0x400908c5:0x3ffce9c0 0x40116385:0x3ffcea10 0x401491d7:0x3ffcea40 0x4014921a:0x3ffceb50 0x40131c23:0x3ffceb80 0x4013348e:0x3ffcebd0 0x401308d2:0x3ffcec70 0x4013093b:0x3ffcec90 0x400e3ec1:0x3ffcecb0 0x400e3b19:0x3ffcecd0 0x400e3cb1:0x3ffced10 0x40129e0b:0x3ffced30 0x40129e61:0x3ffced50 0x401a5da3:0x3ffced70 0x400e4d2c:0x3ffced90 0x400e59b9:0x3ffcedc0 0x400da382:0x3ffcee00 0x400da430:0x3ffcee30 0x400d6c7f:0x3ffceee0 0x401aff65:0x3ffcef80 0x4008cf86:0x3ffcefb0

ELF file SHA256: d715ab4bdd9394fc

I (10641) esp_core_dump_flash: Save core dump to flash...
I (10647) esp_core_dump_common: Backing up stack @ 0x3ffce6a0 and use core dump stack @ 0x3ffba850
I (10657) esp_core_dump_flash: Erase flash 20480 bytes @ 0x3f0000
I (10839) esp_core_dump_flash: Write end offset 0x4980, check sum length 32
I (10840) esp_core_dump_common: Core dump used 1232 bytes on stack. 364 bytes left free.
I (10845) esp_core_dump_common: Restoring stack @ 0x3ffce6a0
I (10851) esp_core_dump_flash: Core dump has been saved to flash.
CPU halted.
Done

0x40187b88: _fwrite_r at /builds/idf/crosstool-NG/.build/xtensa-esp32-elf/src/newlib/newlib/libc/stdio/fwrite.c:135 (discriminator 14)

0x4000c349: memcpy in ROM
0x4000c36b: memcpy in ROM

0x40187b85: _fwrite_r at /builds/idf/crosstool-NG/.build/xtensa-esp32-elf/src/newlib/newlib/libc/stdio/fwrite.c:135 (discriminator 14)
0x40187c21: fwrite at /builds/idf/crosstool-NG/.build/xtensa-esp32-elf/src/newlib/newlib/libc/stdio/fwrite.c:177
0x400e0181: sdcard_log_write at /home/dizcza/Projects/Embedded/eclipse-workspace/esp32-sdpsensor/components_esp32/sdcard/sdcard_log.c:35
0x400dfa7b: logsync_write at /home/dizcza/Projects/Embedded/eclipse-workspace/esp32-sdpsensor/components_esp32/logsync/logsync.c:83
0x401b28fd: esp_log_writev at /home/dizcza/tools/esp-idf/components/log/log.c:197
0x400908c5: esp_log_write at /home/dizcza/tools/esp-idf/components/log/log.c:207
0x40116385: esp_crt_verify_callback at /home/dizcza/tools/esp-idf/components/mbedtls/esp_crt_bundle/esp_crt_bundle.c:141
0x401491d7: x509_crt_merge_flags_with_cb at /home/dizcza/tools/esp-idf/components/mbedtls/mbedtls/library/x509_crt.c:3025
 (inlined by) x509_crt_verify_restartable_ca_cb at /home/dizcza/tools/esp-idf/components/mbedtls/mbedtls/library/x509_crt.c:3110
0x4014921a: mbedtls_x509_crt_verify_restartable at /home/dizcza/tools/esp-idf/components/mbedtls/mbedtls/library/x509_crt.c:3209
0x40131c23: ssl_parse_certificate_verify at /home/dizcza/tools/esp-idf/components/mbedtls/mbedtls/library/ssl_tls.c:7996
 (inlined by) mbedtls_ssl_parse_certificate at /home/dizcza/tools/esp-idf/components/mbedtls/mbedtls/library/ssl_tls.c:8255
0x4013348e: mbedtls_ssl_handshake_client_step at /home/dizcza/tools/esp-idf/components/mbedtls/mbedtls/library/ssl_tls12_client.c:3523
0x401308d2: mbedtls_ssl_handshake_step at /home/dizcza/tools/esp-idf/components/mbedtls/mbedtls/library/ssl_tls.c:4546
 (inlined by) mbedtls_ssl_handshake_step at /home/dizcza/tools/esp-idf/components/mbedtls/mbedtls/library/ssl_tls.c:4498
0x4013093b: mbedtls_ssl_handshake at /home/dizcza/tools/esp-idf/components/mbedtls/mbedtls/library/ssl_tls.c:4610
 (inlined by) mbedtls_ssl_handshake at /home/dizcza/tools/esp-idf/components/mbedtls/mbedtls/library/ssl_tls.c:4587
0x400e3ec1: esp_mbedtls_handshake at /home/dizcza/tools/esp-idf/components/esp-tls/esp_tls_mbedtls.c:218
0x400e3b19: esp_tls_handshake at /home/dizcza/tools/esp-idf/components/esp-tls/esp_tls.c:116 (discriminator 15)
 (inlined by) esp_tls_low_level_conn at /home/dizcza/tools/esp-idf/components/esp-tls/esp_tls.c:495 (discriminator 15)
0x400e3cb1: esp_tls_conn_new_async at /home/dizcza/tools/esp-idf/components/esp-tls/esp_tls.c:549
0x40129e0b: esp_tls_connect_async at /home/dizcza/tools/esp-idf/components/tcp_transport/transport_ssl.c:74
0x40129e61: ssl_connect_async at /home/dizcza/tools/esp-idf/components/tcp_transport/transport_ssl.c:90
0x401a5da3: esp_transport_connect_async at /home/dizcza/tools/esp-idf/components/tcp_transport/transport.c:132
0x400e4d2c: esp_http_client_connect at /home/dizcza/tools/esp-idf/components/esp_http_client/esp_http_client.c:1419
0x400e59b9: esp_http_client_perform at /home/dizcza/tools/esp-idf/components/esp_http_client/esp_http_client.c:1253
0x400da382: app_http_client_get_tasks at /home/dizcza/Projects/Embedded/eclipse-workspace/esp32-sdpsensor/main/app_http.c:504
0x400da430: app_http_client_loop at /home/dizcza/Projects/Embedded/eclipse-workspace/esp32-sdpsensor/main/app_http.c:582
0x400d6c7f: app_main at /home/dizcza/Projects/Embedded/eclipse-workspace/esp32-sdpsensor/main/main.c:151 (discriminator 17)
0x401aff65: main_task at /home/dizcza/tools/esp-idf/components/freertos/app_startup.c:208 (discriminator 13)
0x4008cf86: vPortTaskWrapper at /home/dizcza/tools/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

More Information.

When I put the code of app_http_client_loop to the esp_http_client example code (in the https_with_url() function), I don't get these errors or at least I wasn't able to reproduce them for several minutes. Neither do I get them when I don't use SSL stack (it works over HTTP but not HTTPS).

Other times I get this repeating error:

E (12:54:59.943) esp-tls-mbedtls: mbedtls_ssl_setup returned -0x7F00
E (12:54:59.950) esp-tls: create_ssl_handle failed
E (12:54:59.956) HTTP_CLIENT: Connection failed
W (12:54:59.961) app_http: app_http_client_get_tasks status = 0, content_length = 0
W (12:55:00.037) mbedtls: ssl_tls.c:1420 alloc(16717 bytes) failed

I get these errors even if I strip 80% of the functionality of my app. I don't understand where and why the issue happens. mbedtls: ssl_tls.c:1420 alloc(16717 bytes) failed points to some memory issues but the first logs I sent don't have alloc issues at all!


Here is the modified example and the logs:

static void https_with_url(void)
{
    esp_http_client_config_t config = {
        .host = "85.217.171.57",
        .path = "/tasks",
        .port = 8070,
        .event_handler = _http_event_handler,
        .crt_bundle_attach = esp_crt_bundle_attach,
        .skip_cert_common_name_check = true,
        .transport_type = HTTP_TRANSPORT_OVER_SSL,
        .user_data = app_http_client_buff,
    };

    config.username = ENV_OTA_SERVER_USER;
    config.password = ENV_OTA_SERVER_PASS;
    config.auth_type = HTTP_AUTH_TYPE_BASIC;

    esp_http_client_handle_t client = esp_http_client_init(&config);

    esp_http_client_set_url(client, "/tasks");
    esp_http_client_set_method(client, HTTP_METHOD_GET);
    esp_http_client_set_header(client, "Content-Type", "text/plain");

    esp_err_t err = esp_http_client_perform(client);

    if (err == ESP_OK) {
        ESP_LOGI(TAG, "HTTPS Status = %d, content_length = %"PRIu64,
                esp_http_client_get_status_code(client),
                esp_http_client_get_content_length(client));
        ESP_LOGI(TAG, "\n%s", app_http_client_buff);
    } else {
        ESP_LOGE(TAG, "Error perform http request %s", esp_err_to_name(err));
    }
    esp_http_client_cleanup(client);
}

static void http_test_task(void *pvParameters)
{
    while (1) {
        https_with_url();
        vTaskDelay(pdMS_TO_TICKS(1000));
    }
}

In both cases, I'm using the same sdkconfig.defaults (see https://github.com/espressif/esp-idf/issues/14467#issuecomment-2320515015) and the same HTTPS endpoint.

This code works fine with no errors:

I (00:00:04.098) esp_netif_handlers: example_netif_sta ip: 192.168.3.113, mask: 255.255.255.0, gw: 192.168.3.1
I (00:00:04.100) example_connect: Got IPv4 event: Interface "example_netif_sta" address: 192.168.3.113
I (00:00:04.109) example_common: Connected to example_netif_sta
I (00:00:04.116) example_common: - IPv4 address: 192.168.3.113,
I (00:00:04.124) HTTP_CLIENT: Connected to AP, begin http example
I (00:00:04.129) main_task: Returned from app_main()
I (00:00:04.389) esp-x509-crt-bundle: Certificate validated
I (00:00:06.176) HTTP_CLIENT: HTTPS Status = 200, content_length = 109
I (00:00:06.177) HTTP_CLIENT: 
250 all download '2024-02-15 06:10' '2024-02-15 06:15'
298 all download '2024-08-29 11:10' '2024-08-29 11:44'
I (00:00:06.196) HTTP_CLIENT: HTTP_EVENT_DISCONNECTED
I (00:00:07.484) esp-x509-crt-bundle: Certificate validated
I (00:00:09.126) HTTP_CLIENT: HTTPS Status = 200, content_length = 109
I (00:00:09.127) HTTP_CLIENT: 
250 all download '2024-02-15 06:10' '2024-02-15 06:15'
298 all download '2024-08-29 11:10' '2024-08-29 11:44'
I (00:00:09.137) HTTP_CLIENT: HTTP_EVENT_DISCONNECTED
I (00:00:10.442) esp-x509-crt-bundle: Certificate validated
I (00:00:12.006) HTTP_CLIENT: HTTPS Status = 200, content_length = 109
dizcza commented 2 months ago

Fixed by increasing the keep-alive timeout on the server side.

In particular, I added --keep-alive 10 to my gunicorn command.

Not sure if I need to enable the keep-alive in the ESP HTTP client config -- added it to be safe.

dizcza commented 2 months ago

Increasing keep alive helps but hasn't fully resolved the problem. Sometimes I still get

E (15:56:57.241) esp-x509-crt-bundle: PK verify failed with error FFFFBD70
E (15:56:57.245) esp-x509-crt-bundle: Failed to verify certificate
E (15:56:57.255) esp-tls-mbedtls: mbedtls_ssl_handshake returned -0x3000
E (15:56:57.272) HTTP_CLIENT: Connection failed
W (15:56:57.275) app_http: app_http_client_get_tasks status = 0, content_length = 0

or

E (19:27:53.717) esp-x509-crt-bundle: PK verify failed with error FFFFBD70
E (19:27:53.722) esp-x509-crt-bundle: Failed to verify certificate
E (19:27:53.729) esp-tls-mbedtls: mbedtls_ssl_handshake returned -0x3000
E (19:27:53.732) esp-tls: Failed to open new connection
E (19:27:53.737) transport_base: Failed to open a new connection
E (19:27:53.754) HTTP_CLIENT: Connection failed, sock < 0
W (19:27:53.757) app_http: app_http_client_get_tasks line 500: ESP_ERR_HTTP_CONNECT
nileshkale123 commented 2 months ago

Hello @dizcza ,

Sorry for the delay in reply.

Could you please try providing a certificate through "cacert_buf" method for this endpoint (in place of certificate bundle)? Please refer to code at this.

More information on various approaches of server verification are here

dizcza commented 1 month ago

@nileshkale123 I'm not using the https_request API. I'm using esp_http_client API for both GET and POST requests.

I guess this corresponds to setting cert_pem:

void ota_http_client_config_init(esp_http_client_config_t *config) {
    extern const char ca_cert_pem_start[] asm("_binary_ca_cert_pem_start");
    extern const char ca_cert_pem_end[] asm("_binary_ca_cert_pem_end");

    memset(config, 0, sizeof(esp_http_client_config_t));
    config->username = ENV_OTA_SERVER_USER;
    config->password = ENV_OTA_SERVER_PASS;
    config->auth_type = HTTP_AUTH_TYPE_BASIC;
    config->timeout_ms = OTA_LOADER_TIMEOUT_MS;
    config->skip_cert_common_name_check = true;
    config->cert_pem = ca_cert_pem_start;
    config->cert_len = ca_cert_pem_end - ca_cert_pem_start;
    config->transport_type = HTTP_TRANSPORT_OVER_SSL;
}

As you might have guessed, I'm using the same client config for both HTTPS OTA updates and HTTPS GET/POST client requests.

And I still get the same errors

W (14:33:10.300) app_http: Last esp error code: ESP_ERR_MBEDTLS_SSL_SETUP_FAILED
W (14:33:10.303) app_http: Last mbedtls failure: 0x7f00
E (14:33:20.250) esp-tls-mbedtls: mbedtls_ssl_setup returned -0x7F00
E (14:33:20.255) esp-tls: create_ssl_handle failed
E (14:33:20.259) esp-tls: Failed to open new connection
E (14:33:20.262) transport_base: Failed to open a new connection
E (14:33:20.272) HTTP_CLIENT: Connection failed, sock < 0

And on the server side

Traceback (most recent call last):
  File "/home/vps/miniconda3/lib/python3.7/site-packages/gunicorn/workers/base_async.py", line 65, in handle
    util.reraise(*sys.exc_info())
  File "/home/vps/miniconda3/lib/python3.7/site-packages/gunicorn/util.py", line 626, in reraise
    raise value
  File "/home/vps/miniconda3/lib/python3.7/site-packages/gunicorn/workers/base_async.py", line 48, in handle
    req = next(parser)
  File "/home/vps/miniconda3/lib/python3.7/site-packages/gunicorn/http/parser.py", line 42, in __next__
    self.mesg = self.mesg_class(self.cfg, self.unreader, self.source_addr, self.req_count)
  File "/home/vps/miniconda3/lib/python3.7/site-packages/gunicorn/http/message.py", line 180, in __init__
    super().__init__(cfg, unreader, peer_addr)
  File "/home/vps/miniconda3/lib/python3.7/site-packages/gunicorn/http/message.py", line 54, in __init__
    unused = self.parse(self.unreader)
  File "/home/vps/miniconda3/lib/python3.7/site-packages/gunicorn/http/message.py", line 192, in parse
    self.get_data(unreader, buf, stop=True)
  File "/home/vps/miniconda3/lib/python3.7/site-packages/gunicorn/http/message.py", line 183, in get_data
    data = unreader.read()
  File "/home/vps/miniconda3/lib/python3.7/site-packages/gunicorn/http/unreader.py", line 37, in read
    d = self.chunk()
  File "/home/vps/miniconda3/lib/python3.7/site-packages/gunicorn/http/unreader.py", line 64, in chunk
    return self.sock.recv(self.mxchunk)
  File "/home/vps/miniconda3/lib/python3.7/site-packages/gevent/_ssl3.py", line 555, in recv
    return self.read(buflen)
  File "/home/vps/miniconda3/lib/python3.7/site-packages/gevent/_ssl3.py", line 386, in read
    return self._sslobj.read(nbytes or 1024)
OSError: [Errno 0] Error
nileshkale123 commented 1 month ago

Hello @dizcza

The error code 0x7F00 relates to a heap memory issue, indicating that there might not be enough memory available during the SSL setup phase. Could you please check the free heap memory before initiating the connection, especially just before the esp_http_client configuration is set up?

If the available memory is low, you might consider optimizing memory usage or increasing the heap size, if possible.

Additionally, could you please share a small executable example using an IDF project so that we can reproduce the issue and provide further assistance?

dizcza commented 1 month ago

Hmm. It seems I cannot reliably reproduce the issue: it happened only once or twice daily during the last two days.

Could it be due to changing esp_crt_bundle_attach to cert_pem... hard to tell.

I need to add another ESP32 device to talk to the same server and see what happens.

I'll reopen the issue if I get more description.

dizcza commented 3 weeks ago

Ok, after I

the problem disappeared.

Either of the steps alone didn't solve the problem. Only when I did all things, the issue was gone. Make sure you're not running low on the internal heap memory:

heap_caps_get_minimum_free_size(MALLOC_CAP_8BIT | MALLOC_CAP_DMA | MALLOC_CAP_INTERNAL).

Keep track of this value for hours.