ESP32 Forum

ESP32 Official Forum
http://esp32.io/

TLS connection reset: I (33839) mbedtls: ssl_tls.c:5170 got an alert message, type: [1:0]

http://esp32.io/viewtopic.php?f=13&t=12279

Page 1 of 1

TLS connection reset: I (33839) mbedtls: ssl_tls.c:5170 got an alert message, type: [1:0]

Posted: Thu Sep 12, 2019 9:17 am
by yanosz
Hello folks,

after stabilizing the wifi (pings are running fine now), I've some problems with MQTT / TLS - MQTT without TLS is doing fine.
Version: esp-idf v.3.3
Client: esp-mqtt
Broker: Mosquitto (Debian Stretch & Debian Buster)

I enabled TLS debugging at first, the mqtt-client is able to send two messages (Look for MQTT_EVENT_PUBLISHED) using QoS 1. After a while the connection resets and the client reboots.

Code: Select all

I (24099) mqtt.c: MQTT_EVENT_PUBLISHED, msg_id=11094
I (28509) mbedtls: ssl_tls.c:8682 => write
I (28509) mbedtls: ssl_tls.c:3343 => write record
I (28509) mbedtls: ssl_tls.c:1445 => encrypt buf
I (28529) mbedtls: ssl_tls.c:1781 <= encrypt buf
I (28539) mbedtls: ssl_tls.c:2755 => flush output
I (28539) mbedtls: ssl_tls.c:2774 message length: 1051, out_left: 1051
I (28539) mbedtls: ssl_tls.c:2779 ssl->f_send() returned 1051 (-0xfffffbe5)
I (28549) mbedtls: ssl_tls.c:2807 <= flush output
I (28549) mbedtls: ssl_tls.c:3476 <= write record
I (28559) mbedtls: ssl_tls.c:8710 <= write
I (28559) mbedtls: ssl_tls.c:8682 => write
I (28569) mbedtls: ssl_tls.c:3343 => write record
I (28569) mbedtls: ssl_tls.c:1445 => encrypt buf
I (28579) mbedtls: ssl_tls.c:1781 <= encrypt buf
I (28589) mbedtls: ssl_tls.c:2755 => flush output
I (28589) mbedtls: ssl_tls.c:2774 message length: 218, out_left: 218
I (28599) mbedtls: ssl_tls.c:2779 ssl->f_send() returned 218 (-0xffffff26)
I (28599) mbedtls: ssl_tls.c:2807 <= flush output
I (28609) mbedtls: ssl_tls.c:3476 <= write record
I (28619) mbedtls: ssl_tls.c:8710 <= write
I (28699) mbedtls: ssl_tls.c:8270 => read
I (28699) mbedtls: ssl_tls.c:4311 => read record
I (28699) mbedtls: ssl_tls.c:2536 => fetch input
I (28699) mbedtls: ssl_tls.c:2697 in_left: 0, nb_want: 5
I (28709) mbedtls: ssl_tls.c:2721 in_left: 0, nb_want: 5
I (28719) mbedtls: ssl_tls.c:2722 ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)
I (28729) mbedtls: ssl_tls.c:2742 <= fetch input
I (28729) mbedtls: ssl_tls.c:2536 => fetch input
I (28739) mbedtls: ssl_tls.c:2697 in_left: 5, nb_want: 33
I (28739) mbedtls: ssl_tls.c:2721 in_left: 5, nb_want: 33
I (28749) mbedtls: ssl_tls.c:2722 ssl->f_recv(_timeout)() returned 28 (-0xffffffe4)
I (28759) mbedtls: ssl_tls.c:2742 <= fetch input
I (28759) mbedtls: ssl_tls.c:1794 => decrypt buf
I (28769) mbedtls: ssl_tls.c:2376 <= decrypt buf
I (28769) mbedtls: ssl_tls.c:4385 <= read record
I (28779) mbedtls: ssl_tls.c:8558 <= read
I (29119) mbedtls: ssl_tls.c:8682 => write
I (29119) mbedtls: ssl_tls.c:3343 => write record
I (29119) mbedtls: ssl_tls.c:1445 => encrypt buf
I (29129) mbedtls: ssl_tls.c:1781 <= encrypt buf
I (29129) mbedtls: ssl_tls.c:2755 => flush output
I (29139) mbedtls: ssl_tls.c:2774 message length: 192, out_left: 192
I (29149) mbedtls: ssl_tls.c:2779 ssl->f_send() returned 192 (-0xffffff40)
I (29149) mbedtls: ssl_tls.c:2807 <= flush output
I (29159) mbedtls: ssl_tls.c:3476 <= write record
I (29159) mbedtls: ssl_tls.c:8710 <= write
I (29179) mbedtls: ssl_tls.c:8270 => read
I (29179) mbedtls: ssl_tls.c:4311 => read recordI (29179) m
bedtls: ssl_tls.c:2536 => fetch input
I (29189) mbedtls: ssl_tls.c:2697 in_left: 0, nb_want: 5
I (29189) mbedtls: ssl_tls.c:2721 in_left: 0, nb_want: 5
I (29199) mbedtls: ssl_tls.c:2722 ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)
I (29209) mbedtls: ssl_tls.c:2742 <= fetch input
I (29209) mbedtls: ssl_tls.c:2536 => fetch input
I (29219) mbedtls: ssl_tls.c:2697 in_left: 5, nb_want: 33
I (29229) mbedtls: ssl_tls.c:2721 in_left: 5, nb_want: 33
I (29229) mbedtls: ssl_tls.c:2722 ssl->f_recv(_timeout)() returned 28 (-0xffffffe4)
I (29239) mbedtls: ssl_tls.c:2742 <= fetch input
I (29249) mbedtls: ssl_tls.c:1794 => decrypt buf
I (29249) mbedtls: ssl_tls.c:2376 <= decrypt buf
I (29259) mbedtls: ssl_tls.c:4385 <= read record
I (29259) mbedtls: ssl_tls.c:8558 <= read
I (29269) mqtt.c: MQTT_EVENT_PUBLISHED, msg_id=46133
I (33679) mbedtls: ssl_tls.c:8682 => write
I (33679) mbedtls: ssl_tls.c:3343 => write record
I (33679) mbedtls: ssl_tls.c:1445 => encrypt buf
I (33699) mbedtls: ssl_tls.c:1781 <= encrypt buf
I (33709) mbedtls: ssl_tls.c:2755 => flush output
I (33709) mbedtls: ssl_tls.c:2774 message length: 1051, out_left: 1051
I (33709) mbedtls: ssl_tls.c:2779 ssl->f_send() returned 1051 (-0xfffffbe5)
I (33719) mbedtls: ssl_tls.c:2807 <= flush output
I (33719) mbedtls: ssl_tls.c:3476 <= write record
I (33729) mbedtls: ssl_tls.c:8710 <= write
I (33729) mbedtls: ssl_tls.c:8682 => write
I (33739) mbedtls: ssl_tls.c:3343 => write record
I (33739) mbedtls: ssl_tls.c:1445 => encrypt buf
I (33749) mbedtls: ssl_tls.c:8270 => read
I (33749) mbedtls: ssl_tls.c:4311 => read record
I (33759) mbedtls: ssl_tls.c:2536 => fetch input
I (33759) mbedtls: ssl_tls.c:2697 in_left: 0, nb_want: 5
I (33769) mbedtls: ssl_tls.c:2721 in_left: 0, nb_want: 5
I (33779) mbedtls: ssl_tls.c:2722 ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)
I (33779) mbedtls: ssl_tls.c:1781 <= encrypt buf
I (33789) mbedtls: ssl_tls.c:2742 <= fetch input
I (33799) mbedtls: ssl_tls.c:2536 => fetch input
I (33799) mbedtls: ssl_tls.c:2697 in_left: 5, nb_want: 31
I (33799) mbedtls: ssl_tls.c:2755 => flush output
I (33809) mbedtls: ssl_tls.c:2721 in_left: 5, nb_want: 31
I (33819) mbedtls: ssl_tls.c:2722 ssl->f_recv(_timeout)() returned 26 (-0xffffffe6)
I (33829) mbedtls: ssl_tls.c:2742 <= fetch input
I (33829) mbedtls: ssl_tls.c:1794 => decrypt buf
I (33839) mbedtls: ssl_tls.c:2376 <= decrypt buf
I (33839) mbedtls: ssl_tls.c:5170 got an alert message, type: [1:0]
I (33849) mbedtls: ssl_tls.c:5185 is a close notify message
W (33859) mbedtls: ssl_tls.c:4369 mbedtls_ssl_handle_message_type() returned -30848 (-0x7880)
W (33869) mbedtls: ssl_tls.c:8335 mbedtls_ssl_read_record() returned -30848 (-0x7880)

E (33879) MQTT_CLIENT: Read error or end of stream
I (33889) mqtt.c: MQTT_EVENT_DISCONNECTED
I (33889) status.c: Got status 5
Guru Meditation Error: Core  0 panic'ed (InstrFetchProhibited). Exception was unhandled.
Core 0 register dump:
PC      : 0x00000001  PS      : 0x00060030  A0      : 0x8018bce9  A1      : 0x3ffbaf50  
A2      : 0x3ffdebc4  A3      : 0x00000001  A4      : 0x3f431840  A5      : 0x00000ac8  
A6      : 0x00000001  A7      : 0x0000000a  A8      : 0x8019a719  A9      : 0x3ffbaf10  
A10     : 0x3ffdec20  A11     : 0x00000001  A12     : 0x3f431840  A13     : 0x00000ac8  
A14     : 0x3ffbaf5c  A15     : 0x00000014  SAR     : 0x00000004  EXCCAUSE: 0x00000014  
EXCVADDR: 0x00000000  LBEG    : 0x400014fd  LEND    : 0x4000150d  LCOUNT  : 0xffffffff  

ELF file SHA256: 2b3f8b27b2f62db55e8b23e7a9e4e944b99a656cfb108830cdea101df36855bf

Backtrace: 0x00000001:0x3ffbaf50 0x4018bce6:0x3ffbb1a0 0x4018ccc3:0x3ffbb1d0 0x4018d3b8:0x3ffbb200 0x4018d426:0x3ffbb220 0x4016d785:0x3ffbb240 0x4011e2bc:0x3ffbb260 0x401a7fad:0x3ffbb290 0x40107cba:0x3ffbb2b0 0x40108fa7:0x3ffbb2d0 0x40107384:0x3ffbb310 0x401073a9:0x3ffbb330 0x401068ed:0x3ffbb390 0x40106b5b:0x3ffbb440 0x400d0c7e:0x3ffbb4f0 0x400927bd:0x3ffbb510
0x4018bce6: mbedtls_ssl_flush_output at /home/jan/esp/esp-idf/components/mbedtls/mbedtls/library/ssl_tls.c:9332
0x4018ccc3: mbedtls_ssl_write_record at /home/jan/esp/esp-idf/components/mbedtls/mbedtls/library/ssl_tls.c:9332
0x4018d3b8: ssl_write_real at /home/jan/esp/esp-idf/components/mbedtls/mbedtls/library/ssl_tls.c:9332
0x4018d426: mbedtls_ssl_write at /home/jan/esp/esp-idf/components/mbedtls/mbedtls/library/ssl_tls.c:9332
0x4016d785: tls_write at /home/jan/esp/esp-idf/components/esp-tls/esp_tls.c:524
Do you know, what's wong, here?

Thanks,
yanosz

Re: TLS connection reset: I (33839) mbedtls: ssl_tls.c:5170 got an alert message, type: [1:0]

Posted: Fri Sep 13, 2019 1:03 am
by ESP_Angus
Hi yanoz,

Each end of a TLS connection can send notifications (warnings or errors) to each other. In this case, the other end is sending the "I'm going to close the connection" notification to the ESP:

Code: Select all

I (33839) mbedtls: ssl_tls.c:5170 got an alert message, type: [1:0]
I (33849) mbedtls: ssl_tls.c:5185 is a close notify message
You can read about them in the TLS standard especially "7.2.1. Closure Alerts": https://tools.ietf.org/html/rfc5246#page-28

This one is "warning" [1] "close_notify [0]. There's no errror reported, it's just telling you "I'm closing now" as a more polite way than just closing the socket.

To try to find out why it closed, you'll need to look at the Mosquitto logs on the server side.

Of course, this shouldn't cause a crash:

Code: Select all

E (33879) MQTT_CLIENT: Read error or end of stream
I (33889) mqtt.c: MQTT_EVENT_DISCONNECTED
I (33889) status.c: Got status 5
Guru Meditation Error: Core  0 panic'ed (InstrFetchProhibited). Exception was unhandled.
Core 0 register dump:
Are the mqtt.c & status.c lines coming from your project's code?

Is it possible your code is calling back into the ESP-MQTT API with some no-longer-valid parameters?
All times are UTC
Page 1 of 1
Powered by phpBB® Forum Software © phpBB Limited
https://www.phpbb.com/