Mbed-TLS / mbedtls

An open source, portable, easy to use, readable and flexible TLS library, and reference implementation of the PSA Cryptography API. Releases are on a varying cadence, typically around 3 - 6 months between releases.
https://www.trustedfirmware.org/projects/mbed-tls/
Other
5.22k stars 2.55k forks source link

mbedtls_ssl_handshake server sticks in failing with MBEDTLS_ERR_RSA_VERIFY_FAILED error after some point #7833

Open HamzaHajeir opened 1 year ago

HamzaHajeir commented 1 year ago

Summary

System information

Mbed TLS version (number or commit id): 2.28.3 Operating system and version: Built with Ubuntu Configuration (if not default, please attach mbedtls_config.h): Please find attached config.txt

Compiler and options (if you used a pre-built binary, please indicate how you obtained it): With default esp-idf compilation environment: version release/v4.4

Additional environment information: Built using a fork of espressif/esp32-arduino-lib-builder

Expected behavior

I host TLS webserver using LwIP ALTCP TLS - MBEDTLS port, I expect every client (browser) to be able to connect anytime.

In essence, It works correctly to some point, correct behaviour includes making successful handshakes and communication. The problem starts after some amount of time/process, in which causes to deny any new connections, even from browsers were already connected by the means of a reload button.
Already connected connections prior to this point continue to communicate successfully afterwards.

The error code returned by the mbedtls_ssl_handshake is fixed at -17280 (-0x4380) (MBEDTLS_ERR_RSA_VERIFY_FAILED).

I've noticed that some times the preceeding handshake's error code is -17168 (-0x4310), which I've tried to find the represented meaning, but failed to, nearest assumption is MBEDTLS_ERR_RSA_PRIVATE_FAILED | MBEDTLS_ERR_MPI_NEGATIVE_VALUE.

Is there any hint for what's going wrong? With thanks,

Actual behavior

Log shows:

IDF/components/mbedtls/mbedtls/library/ssl_srv.c:3542: mbedtls_pk_sign() returned -17280 (-0x4380)

Or in the other described case:

IDF/components/mbedtls/mbedtls/library/ssl_srv.c:3542: mbedtls_pk_sign() returned -17168 (-0x4310)

Steps to reproduce

It's hard to tell how to reproduce, as the time is uncertain, and upon that any further reset of the webserver (including SSL context) yield in yet again successful handshakes until it reappears.

However, here's the running ALTCP MBEDTLS Code, pointing to the handshake API call:

https://github.com/HamzaHajeir/esp-lwip/blob/2.1.2-esp-patch/src/apps/altcp_tls/altcp_tls_mbedtls.c#L278

Additional information

Meanwhile this issue, the MCU is able to reconnect to a MQTT server by TLS with successful (one-way auth) handshakes,

My investigation of a very long log shows that this problem leaks memory too.

Debug Logs.

Example of a complete verbose log:
(You can expect other data being interfered with UART port at printing, those which are printed from the other core).

00:31:38.711 > IDF/components/mbedtls/mbedtls/library/ssl_tls.c:5804: => handshake
00:31:38.713 > H4AT:1: H=58248 M=42996 B=42996 S=5292 NEW CONNECTION 0x3ffdeb8c --> IDF/components/mbedtls/mbedtls/library/ssl_srv.c:4511: server state: 0
00:31:38.714 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:2033: => flush output
00:31:38.715 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:2042: <= flush output
00:31:38.716 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:4511: server state: 1
00:31:38.717 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:2033: => flush output
00:31:38.718 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:2042: <= flush output
00:31:38.718 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1397: => parse client hello
00:31:38.719 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:1835: => fetch input
00:31:38.720 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:1977: in_left: 0, nb_want: 5
00:31:38.721 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:1997: in_left: 0, nb_want: 5
00:31:38.722 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:1998: ssl->f_recv(_timeout)() returned 5 (-0xfffffffb)
00:31:38.723 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:2020: <= fetch input
00:31:38.724 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1449: client hello v3, message type: 22
00:31:38.725 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1457: client hello v3, message len.: 512
00:31:38.726 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1460: client hello v3, protocol version: [3:1]
00:31:38.727 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:1835: => fetch input
00:31:38.727 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:1977: in_left: 5, nb_want: 517
00:31:38.728 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:1997: in_left: 5, nb_want: 517
00:31:38.729 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:1998: ssl->f_recv(_timeout)() returned 512 (-0xfffffe00)
00:31:38.730 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:2020: <= fetch input
00:31:38.731 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1551: client hello v3, handshake type: 1
00:31:38.731 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1559: client hello v3, handshake len.: 508
00:31:38.732 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1653: dumping 'client hello, version' (2 bytes)
00:31:38.733 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1653: 0000:  03 03                                            ..
00:31:38.734 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1682: dumping 'client hello, random bytes' (32 bytes)
00:31:38.735 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1682: 0000:  1c 39 2f 13 eb 46 bf 57 d8 cf 3d 30 cb de 2b 88  .9/..F.W..=0..+.
00:31:38.737 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1682: 0010:  c6 a2 c4 94 3e 99 d9 29 a6 d1 81 2e 34 f8 98 07  ....>..)....4...
00:31:38.738 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1699: dumping 'client hello, session id' (32 bytes)
00:31:38.739 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1699: 0000:  b9 2a d6 fc 5a 13 29 91 8d 7f 9f a6 c5 32 06 2b  .*..Z.)......2.+
00:31:38.741 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1699: 0010:  9e b0 63 d8 d4 c2 9f 2d 10 ee 72 5a 60 83 1c 6a  ..c....-..rZ`..j
00:31:38.742 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1774: dumping 'client hello, ciphersuitelist' (32 bytes)
00:31:38.743 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1774: 0000:  4a 4a 13 01 13 02 13 03 c0 2b c0 2f c0 2c c0 30  JJ.......+./.,.0
00:31:38.745 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1774: 0010:  cc a9 cc a8 c0 13 c0 14 00 9c 00 9d 00 2f 00 35  ............./.5
00:31:38.747 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1793: dumping 'client hello, compression' (1 bytes)
00:31:38.748 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1793: 0000:  00                                               .
00:31:38.749 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1842: dumping 'client hello extensions' (403 bytes)
00:31:38.751 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1842: 0000:  5a 5a 00 00 00 0d 00 14 00 12 04 03 08 04 04 01  ZZ..............
00:31:38.752 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1842: 0010:  05 03 08 05 05 01 08 06 06 01 02 01 00 0a 00 0a  ................
00:31:38.753 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1842: 0020:  00 08 6a 6a 00 1d 00 17 00 18 00 23 00 00 ff 01  ..jj.......#....
00:31:38.755 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1842: 0030:  00 01 00 44 69 00 05 00 03 02 68 32 00 17 00 00  ...Di.....h2....
00:31:38.756 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1842: 0040:  00 33 00 2b 00 29 6a 6a 00 01 00 00 1d 00 20 49  .3.+.)jj...... I
00:31:38.758 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1842: 0050:  ae af b9 7e 87 5d a5 53 fa 10 d3 5a b6 74 6f e8  ...~.].S...Z.to.
00:31:38.759 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1842: 0060:  7c 32 b6 43 90 85 aa 14 08 9c ba a3 ea d7 7a 00  |2.C..........z.
00:31:38.760 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1842: 0070:  05 00 05 01 00 00 00 00 00 12 00 00 00 0b 00 02  ................
00:31:38.762 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1842: 0080:  01 00 00 10 00 0e 00 0c 02 68 32 08 68 74 74 70  .........h2.http
00:31:38.763 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1842: 0090:  2f 31 2e 31 00 2d 00 02 01 01 00 1b 00 03 02 00  /1.1.-..........
00:31:38.765 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1842: 00a0:  02 00 2b 00 07 06 da da 03 04 03 03 6a 6a 00 01  ..+.........jj..
00:31:38.766 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1842: 00b0:pcb=0x3ffdac80 state=4
00:31:38.766 >   00 00 15 00 de 00 00 00 00 00 00 00 00 00 00 00  ................
00:31:38.767 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1842: 00c0:  00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
00:31:38.769 > H=59200 M=42996 S=IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1842: 00d0:  00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
00:31:38.771 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1842: 00e0:  00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
00:31:38.773 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1842: 00f0:  00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
00:31:38.774 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1842: 0100:  00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
00:31:38.775 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1842: 0110:  00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
00:31:38.777 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1842: 0120:  00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
00:31:38.778 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1842: 0130:  00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
00:31:38.779 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1842: 0140:  00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
00:31:38.781 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1842: 0150:  00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
00:31:38.782 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1842: 0160:  00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
00:31:38.784 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1842: 0170:  00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
00:31:38.785 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1842: 0180:  00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
00:31:38.786 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1842: 0190:  00 00 00                                         ...
00:31:38.787 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:2028: unknown extension found: 23130 (ignoring)
00:31:38.788 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1892: found signature_algorithms extension
00:31:38.789 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0294: client hello v3, signature_algorithm ext: match sig 4 and hash 6
00:31:38.790 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0278: client hello v3, signature_algorithm ext unknown sig alg encoding 4
00:31:38.791 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0294: client hello v3, signature_algorithm ext: match sig 1 and hash 6
00:31:38.793 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0294: client hello v3, signature_algorithm ext: match sig 4 and hash 7
00:31:38.794 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0278: client hello v3, signature_algorithm ext unknown sig alg encoding 5
00:31:38.795 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0294: client hello v3, signature_algorithm ext: match sig 1 and hash 7
00:31:38.797 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0278: client hello v3, signature_algorithm ext unknown sig alg encoding 6
00:31:38.798 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0294: client hello v3, signature_algorithm ext: match sig 1 and hash 8
00:31:38.799 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0294: client hello v3, signature_algorithm ext: match sig 1 and hash 4
00:31:38.801 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1907: found supported elliptic curves extension
00:31:38.802 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1995: found session ticket extension
00:31:38.804 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1878: found renegotiation extension
00:31:38.805 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:2028: unknown extension found: 17513 (ignoring)
00:31:38.806 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1984: found extended master secret extension
00:31:38.806 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:2028: unknown extension found: 51 (ignoring)
00:31:38.807 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:2028: unknown extension found: 5 (ignoring)
00:31:38.808 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:2028: unknown extension found: 18 (ignoring)
00:31:38.809 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1916: found supported point formats extension
00:31:38.810 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:2006: found alpn extension
00:31:38.811 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:2028: unknown extension found: 45 (ignoring)
00:31:38.812 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:2028: unknown extension found: 27 (ignoring)
00:31:38.813 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:2028: unknown extension found: 43 (ignoring)
00:31:38.814 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:2028: unknown extension found: 27242 (ignoring)
00:31:38.815 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:2028: unknown extension found: 21 (ignoring)
00:31:38.816 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1013: trying ciphersuite: 0xc02c (TLS-ECDHE-ECDSA-WITH-AES-256-GCM-SHA384)
00:31:38.817 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0914: ciphersuite requires certificate
00:31:38.818 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924: candidate certificate chain, certificate #1:
00:31:38.819 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924: cert. version     : 3
00:31:38.820 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924: serial number     : 4D:39:38:95:3A:2D:82:2B:5B:9C:C3:FE:12:DF:DE:84:D7:57:3B:01
00:31:38.822 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924: issuer name       : C=JO, ST=AMM, L=AMM, O=H4, CN=H4Tester
00:31:38.823 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924: subject name      : C=JO, ST=AMM, L=AMM, O=H4, CN=H4Tester
00:31:38.824 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924: issued  on        : 2023-06-10 14:08:27
00:31:38.825 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924: expires on        : 2024-06-09 14:08:27
00:31:38.827 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924: signed using      : RSA with SHA-256
00:31:38.827 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924: RSA key size      : 2048 bits
00:31:38.828 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924: basic constraints : CA=true
00:31:38.829 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924: value of 'crt->rsa.N' (2048 bits) is:
00:31:38.830 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924:  bd 0d 52 b2 bd 26 b0 87 7a 8b 04 93 56 80 3c ff
00:31:38.831 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924:  a2 83 09 63 a8 4d a9 1c 71 fb df c4 bc a7 52 af
00:31:38.832 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924:  40 d6 91 b0 45 4e 2e 71 ab 1d ce a8 cb 5a 44 33
00:31:38.834 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924:  9e 6f 93 f0 20 d5 0a c4 05 a2 1b 09 60 d0 3a c8
00:31:38.835 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924:  df 3e 2d 0a 2a 5b 9b e2 79 f9 bc 26 9e df 6a 79
00:31:38.836 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924:  f1 9a 4d 08 87 c4 e8 ac 87 84 75 17 c9 30 88 80
00:31:38.837 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924:  e2 30 b9 27 95 59 82 21 60 4e 1a 16 b4 89 ce 8e
00:31:38.838 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924:  65 55 ad e1 43 3b b8 00 01 59 b6 64 fa a4 f7 f9
00:31:38.839 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924:  66 40 a0 26 3b af c0 28 b5 b6 67 81 ad bd b9 c1
00:31:38.840 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924:  be 12 53 8f 77 23 fc ec 63 af 02 bb b5 ae 83 2a
00:31:38.841 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924:  21 d8 df 5b 9c bc 8a 36 53 32 df 14 7c 2c 71 b6
00:31:38.844 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924:  d6 ca 8c 59 f3 a7 46 2a b1 a7 92 d0 87 91 8b 63
00:31:38.844 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924:  88 6e 3d f5 56 df f8 c9 55 7f 1c 32 de 45 40 fd
00:31:38.852 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924:  e5 24 5a 8c 2a be ba b7 55 6a 59 73 24 d9 e0 31
00:31:38.852 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924:  ad cb 0a 87 c8 74 f2 90 03 d9 81 ab cb 41 6c 78
00:31:38.852 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924:  03 03 9d ea 4e 8a b6 43 3a 82 3d e3 ca 97 dc cf
00:31:38.852 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924: value of 'crt->rsa.E' (17 bits) is:
00:31:38.852 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924:  01 00 01
00:31:38.852 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0927: certificate mismatch: key type
00:31:38.852 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1094: ciphersuite mismatch: no suitable certificate
00:31:38.852 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:1013: trying ciphersuite: 0xc030 (TLS-ECDHE-RSA-WITH-AES-256-GCM-SHA384)
00:31:38.854 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0914: ciphersuite requires certificate
00:31:38.855 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924: candidate certificate chain, certificate #1:
00:31:38.856 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924: cert. version     : 3
00:31:38.857 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924: serial number     : 4D:39:38:95:3A:2D:82:2B:5B:9C:C3:FE:12:DF:DE:84:D7:57:3B:01
00:31:38.859 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924: issuer name       : C=JO, ST=AMM, L=AMM, O=H4, CN=H4Tester
00:31:38.860 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924: subject name      : C=JO, ST=AMM, L=AMM, O=H4, CN=H4Tester
00:31:38.861 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924: issued  on        : 2023-06-10 14:08:27
00:31:38.862 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924: expires on        : 2024-06-09 14:08:27
00:31:38.863 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924: signed using      : RSA with SHA-256
00:31:38.864 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924: RSA key size      : 2048 bits
00:31:38.865 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924: basic constraints : CA=true
00:31:38.866 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924: value of 'crt->rsa.N' (2048 bits) is:
00:31:38.867 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924:  bd 0d 52 b2 bd 26 b0 87 7a 8b 04 93 56 80 3c ff
00:31:38.868 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924:  a2 5292 
00:31:38.869 > 83 09 63 a8 4d a9 1c 71 fb df c4 bc a7 52 af
00:31:38.870 > SLOG: heap 0x00004000 56884
00:31:38.870 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924:  40 d6 91 b0 45 4e 2e 71 ab 1d ce a8 cb 5a 44 33
00:31:38.871 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924:  9e 6f 93 f0 20 d5 0a c4 05 a2 1b 09 60 d0 3a c8
00:31:38.873 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924:  df 3e 2d 0a 2a 5b 9b e2 79 f9 bc 26 9e df 6a 79
00:31:38.874 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924:  f1 9a 4d 08 87 c4 e8 ac 87 84 75 17 c9 30 88 80
00:31:38.875 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924:  e2 30 b9 27 95 59 82 21 60 4e 1a 16 b4 89 ce 8e
00:31:38.876 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924:  65 55 ad e1 43 3b b8 00 01 59 b6 64 fa a4 f7 f9
00:31:38.877 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924:  66 40 a0 26 3b af c0 28 b5 b6 67 81 ad bd b9 c1
00:31:38.878 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924:  be 12 53 8f 77 23 fc ec 63 af 02 bb b5 ae 83 2a
00:31:38.878 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924:  21 d8 df 5b 9c bc 8a 36 53 32 df 14 7c 2c 71 b6
00:31:38.881 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924:  d6 ca 8c 59 f3 a7 46 2a b1 a7 92 d0 87 91 8b 63
00:31:38.882 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924:  88 6e 3d f5 56 df f8 c9 55 7f 1c 32 de 45 40 fd
00:31:38.883 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924:  e5 24 5a 8c 2a be ba b7 55 6a 59 73 24 d9 e0 31
00:31:38.884 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924:  ad cb 0a 87 c8 74 f2 90 03 d9 81 ab cb 41 6c 78
00:31:38.885 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924:  03 03 9d ea 4e 8a b6 43 3a 82 3d e3 ca 97 dc cf
00:31:38.886 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924: value of 'crt->rsa.E' (17 bits) is:
00:31:38.887 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0924:  01 00 01
00:31:38.888 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0983: selected certificate chain, certificate #1:
00:31:38.889 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0983: cert. version     : 3
00:31:38.890 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0983: serial number     : 4D:39:38:95:3A:2D:82:2B:5B:9C:C3:FE:12:DF:DE:84:D7:57:3B:01
00:31:38.891 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0983: issuer name       : C=JO, ST=AMM, L=AMM, O=H4, CN=H4Tester
00:31:38.893 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0983: subject name      : C=JO, ST=AMM, L=AMM, O=H4, CN=H4Tester
00:31:38.894 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0983: issued  on        : 2023-06-10 14:08:27
00:31:38.895 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0983: expires on        : 2024-06-09 14:08:27
00:31:38.896 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0983: signed using      : RSA with SHA-256
00:31:38.897 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0983: RSA key size      : 2048 bits
00:31:38.898 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0983: basic constraints : CA=true
00:31:38.899 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0983: value of 'crt->rsa.N' (2048 bits) is:
00:31:38.900 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0983:  bd 0d 52 b2 bd 26 b0 87 7a 8b 04 93 56 80 3c ff
00:31:38.901 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0983:  a2 83 09 63 a8 4d a9 1c 71 fb df c4 bc a7 52 af
00:31:38.902 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0983:  40 d6 91 b0 45 4e 2e 71 ab 1d ce a8 cb 5a 44 33
00:31:38.903 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0983:  9e 6f 93 f0 20 d5 0a c4 05 a2 1b 09 60 d0 3a c8
00:31:38.904 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0983:  df 3e 2d 0a 2a 5b 9b e2 79 f9 bc 26 9e df 6a 79
00:31:38.905 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0983:  f1 9a 4d 08 87 c4 e8 ac 87 84 75 17 c9 30 88 80
00:31:38.907 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0983:  e2 30 b9 27 95 59 82 21 60 4e 1a 16 b4 89 ce 8e
00:31:38.908 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0983:  65 55 ad e1 43 3b b8 00 01 59 b6 64 fa a4 f7 f9
00:31:38.909 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0983:  66 40 a0 26 3b af c0 28 b5 b6 67 81 ad bd b9 c1
00:31:38.910 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0983:  be 12 53 8f 77 23 fc ec 63 af 02 bb b5 ae 83 2a
00:31:38.911 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0983:  21 d8 df 5b 9c bc 8a 36 53 32 df 14 7c 2c 71 b6
00:31:38.912 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0983:  d6 ca 8c 59 f3 a7 46 2a b1 a7 92 d0 87 91 8b 63
00:31:38.913 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0983:  88 6e 3d f5 56 df f8 c9 55 7f 1c 32 de 45 40 fd
00:31:38.915 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0983:  e5 24 5a 8c 2a be ba b7 55 6a 59 73 24 d9 e0 31
00:31:38.916 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0983:  ad cb 0a 87 c8 74 f2 90 03 d9 81 ab cb 41 6c 78
00:31:38.917 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0983:  03 03 9d ea 4e 8a b6 43 3a 82 3d e3 ca 97 dc cf
00:31:38.918 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0983: value of 'crt->rsa.E' (17 bits) is:
00:31:38.919 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:0983:  01 00 01
00:31:38.920 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:2192: selected ciphersuite: TLS-ECDHE-RSA-WITH-AES-256-GCM-SHA384
00:31:38.921 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:2215: client hello v3, signature_algorithm ext: 4
00:31:38.922 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:2223: <= parse client hello
00:31:38.923 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:4511: server state: 2
00:31:38.924 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:2033: => flush output
00:31:38.924 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:2042: <= flush output
00:31:38.925 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:2755: => write server hello
00:31:38.926 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:2787: server hello, chosen version: [3:3]
00:31:38.927 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:2795: server hello, current time: 204
00:31:38.928 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:2812: dumping 'server hello, random bytes' (32 bytes)
00:31:38.929 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:2812: 0000:  00 00 00 cc 2d 5a cb ed 9c fc 1f ee 13 df b1 b5  ....-Z..........
00:31:38.930 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:2812: 0010:  99 87 11 0f 44 13 c4 09 9b cc 22 b3 41 6d 3a 16  ....D.....".Am:.
00:31:38.931 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:2865: server hello, session id len.: 32
00:31:38.932 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:2866: dumping 'server hello, session id' (32 bytes)
00:31:38.934 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:2866: 0000:  ff 28 07 e3 8a 79 08 36 27 f3 7c 2a 57 b3 4c 26  .(...y.6'.|*W.L&
00:31:38.935 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:2866: 0010:  bc ea 95 7e 97 08 01 ff 14 90 57 be 2b a9 15 41  ...~......W.+..A
00:31:38.937 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:2868: no session has been resumed
00:31:38.938 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:2875: server hello, chosen ciphersuite: TLS-ECDHE-RSA-WITH-AES-256-GCM-SHA384
00:31:38.939 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:2877: server hello, compress alg.: 0x00
00:31:38.940 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:2403: server hello, secure renegotiation extension
00:31:38.941 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:2356: server hello, adding extended master secret extension
00:31:38.942 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:2470: server hello, supported_point_formats extension
00:31:38.944 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:2945: server hello, total extension length: 15
00:31:38.945 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:2451: => write handshake message
00:31:38.946 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:2598: => write record
00:31:38.946 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:2706: output record: msgtype = 22, version = [3:3], msglen = 91
00:31:38.948 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:2033: => flush output
00:31:38.948 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:2049: message length: 96, out_left: 96
00:31:38.949 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:2054: ssl->f_send() returned 96 (-0xffffffa0)
00:31:38.950 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:2081: <= flush output
00:31:38.951 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:2756: <= write record
00:31:38.952 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:2575: <= write handshake message
00:31:38.953 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:2962: <= write server hello
00:31:38.954 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:4511: server state: 3
00:31:38.954 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:2033: => flush output
00:31:38.955 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:2042: <= flush output
00:31:38.956 > IDF/components/mbedtls/mbedtls/library/ssl_tls.c:2161: => write certificate
00:31:38.957 > IDF/components/mbedtls/mbedtls/library/ssl_tls.c:2204: own certificate #1:
00:31:38.958 > IDF/components/mbedtls/mbedtls/library/ssl_tls.c:2204: cert. version     : 3
00:31:38.958 > IDF/components/mbedtls/mbedtls/library/ssl_tls.c:2204: serial number     : 4D:39:38:95:3A:2D:82:2B:5B:9C:C3:FE:12:DF:DE:84:D7:57:3B:01
00:31:38.960 > IDF/components/mbedtls/mbedtls/library/ssl_tls.c:2204: issuer name       : C=JO, ST=AMM, L=AMM, O=H4, CN=H4Tester
00:31:38.961 > IDF/components/mbedtls/mbedtls/library/ssl_tls.c:2204: subject name      : C=JO, ST=AMM, L=AMM, O=H4, CN=H4Tester
00:31:38.962 > IDF/components/mbedtls/mbedtls/library/ssl_tls.c:2204: issued  on        : 2023-06-10 14:08:27
00:31:38.963 > IDF/components/mbedtls/mbedtls/library/ssl_tls.c:2204: expires on        : 2024-06-09 14:08:27
00:31:38.965 > IDF/components/mbedtls/mbedtls/library/ssl_tls.c:2204: signed using      : RSA with SHA-256
00:31:38.966 > IDF/components/mbedtls/mbedtls/library/ssl_tls.c:2204: RSA key size      : 2048 bits
00:31:38.966 > IDF/components/mbedtls/mbedtls/library/ssl_tls.c:2204: basic constraints : CA=true
00:31:38.967 > IDF/components/mbedtls/mbedtls/library/ssl_tls.c:2204: value of 'crt->rsa.N' (2048 bits) is:
00:31:38.968 > IDF/components/mbedtls/mbedtls/library/ssl_tls.c:2204:  bd 0d 52 b2 bd 26 b0 87 7a 8b 04 93 56 80 3c ff
00:31:38.970 > IDF/components/mbedtls/mbedtls/library/ssl_tls.c:2204:  a2 83 09 63 a8 4d a9 1c 71 fb df c4 bc a7 52 af
00:31:38.971 > IDF/components/mbedtls/mbedtls/library/ssl_tls.c:2204:  40 d6 91 b0 45 4e 2e 71 ab 1d ce a8 cb 5a 44 33
00:31:38.972 > IDF/components/mbedtls/mbedtls/library/ssl_tls.c:2204:  9e 6f 93 f0 20 d5 0a c4 05 a2 1b 09 60 d0 3a c8
00:31:38.974 > IDF/components/mbedtls/mbedtls/library/ssl_tls.c:2204:  df 3e 2d 0a 2a 5b 9b e2 79 f9 bc 26 9e df 6a 79
00:31:38.975 > IDF/components/mbedtls/mbedtls/library/ssl_tls.c:2204:  f1 9a 4d 08 87 c4 e8 ac 87 84 75 17 c9 30 88 80
00:31:38.976 > IDF/components/mbedtls/mbedtls/library/ssl_tls.c:2204:  e2 30 b9 27 95 59 82 21 60 4e 1a 16 b4 89 ce 8e
00:31:38.978 > IDF/components/mbedtls/mbedtls/library/ssl_tls.c:2204:  65 55 ad e1 43 3b b8 00 01 59 b6 64 fa a4 f7 f9
00:31:38.979 > IDF/components/mbedtls/mbedtls/library/ssl_tls.c:2204:  66 40 a0 26 3b af c0 28 b5 b6 67 81 ad bd b9 c1
00:31:38.980 > IDF/components/mbedtls/mbedtls/library/ssl_tls.c:2204:  be 12 53 8f 77 23 fc ec 63 af 02 bb b5 ae 83 2a
00:31:38.981 > IDF/components/mbedtls/mbedtls/library/ssl_tls.c:2204:  21 d8 df 5b 9c bc 8a 36 53 32 df 14 7c 2c 71 b6
00:31:38.982 > IDF/components/mbedtls/mbedtls/library/ssl_tls.c:2204:  d6 ca 8c 59 f3 a7 46 2a b1 a7 92 d0 87 91 8b 63
00:31:38.982 > IDF/components/mbedtls/mbedtls/library/ssl_tls.c:2204:  88 6e 3d f5 56 df f8 c9 55 7f 1c 32 de 45 40 fd
00:31:38.983 > IDF/components/mbedtls/mbedtls/library/ssl_tls.c:2204:  e5 24 5a 8c 2a be ba b7 55 6a 59 73 24 d9 e0 31
00:31:38.985 > IDF/components/mbedtls/mbedtls/library/ssl_tls.c:2204:  ad cb 0a 87 c8 74 f2 90 03 d9 81 ab cb 41 6c 78
00:31:38.986 > IDF/components/mbedtls/mbedtls/library/ssl_tls.c:2204:  03 03 9d ea 4e 8a b6 43 3a 82 3d e3 ca 97 dc cf
00:31:38.987 > IDF/components/mbedtls/mbedtls/library/ssl_tls.c:2204: value of 'crt->rsa.E' (17 bits) is:
00:31:38.988 > IDF/components/mbedtls/mbedtls/library/ssl_tls.c:2204:  01 00 01
00:31:38.989 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:2451: => write handshake message
00:31:38.989 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:2598: => write record
00:31:38.990 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:2706: output record: msgtype = 22, version = [3:3], msglen = 897
00:31:38.991 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:2033: => flush output
00:31:38.992 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:2049: message length: 902, out_left: 902
00:31:38.993 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:2054: ssl->f_send() returned 902 (-0xfffffc7a)
00:31:38.994 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:2081: <= flush output
00:31:38.995 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:2756: <= write record
00:31:38.996 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:2575: <= write handshake message
00:31:38.997 > IDF/components/mbedtls/mbedtls/library/ssl_tls.c:2254: <= write certificate
00:31:38.998 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:4511: server state: 4
00:31:38.998 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:2033: => flush output
00:31:39.000 > IDF/components/mbedtls/mbedtls/library/ssl_msg.c:2042: <= flush output
00:31:39.000 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:3565: => write server key exchange
00:31:39.002 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:3353: ECDHE curve: secp384r1
00:31:39.031 > SLOG: tick 0x80000000 205
00:31:39.032 > SLOG: upTime 0x00004000   0 00:03:25
00:31:39.169 > H=53216 M=42996 S=5292 
00:31:39.171 > SLOG: heap 0x00004000 52996
00:31:39.469 > H=51752 M=42996 S=5292 
00:31:39.470 > SLOG: heap 0x00004000 51420
00:31:39.771 > H=50792 M=42996 S=5292 
00:31:39.772 > SLOG: heap 0x00004000 50716
00:31:39.932 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:3377: value of 'ECDH: Q(X)' (384 bits) is:
00:31:39.934 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:3377:  d3 8d 3c 55 6b 98 68 fb 51 cf 3d ee 04 20 58 52
00:31:39.935 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:3377:  a4 71 d5 66 c0 14 f0 60 d6 90 e3 6b 5b ad cd 03
00:31:39.936 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:3377:  d8 70 7a 3f a6 53 ec 31 e9 cf 5e 6e 3e 81 83 a9
00:31:39.937 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:3377: value of 'ECDH: Q(Y)' (383 bits) is:
00:31:39.938 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:3377:  47 46 41 b3 5a c0 3e 16 b8 cb 31 94 fc 6e e0 79
00:31:39.939 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:3377:  6d 41 f8 e8 9a 53 fe 4a de 64 ae 38 63 f7 a1 b4
00:31:39.941 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:3377:  bd e6 f3 4e a0 6f 17 36 7f 39 68 9e 24 3c 3c 06
00:31:39.942 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:3438: pick hash algorithm 6 for signing
00:31:39.943 > IDF/components/mbedtls/mbedtls/library/ssl_tls.c:7575: Perform mbedtls-based computation of digest of ServerKeyExchange
00:31:39.944 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:3474: dumping 'parameters hash' (32 bytes)
00:31:39.945 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:3474: 0000:  55 6e 08 d5 49 ea 86 99 3e 1a 89 da cd c8 16 77  Un..I...>......w
00:31:39.946 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:3474: 0010:  ee 74 15 b9 28 53 09 f5 2c de 7c 3c b3 26 96 15  .t..(S..,.|<.&..
00:31:40.031 > SLOG: tick 0x80000000 206
00:31:40.033 > SLOG: upTime 0x00004000   0 00:03:26
00:31:40.072 > H=47440 M=42996 S=5292 
00:31:40.073 > SLOG: heap 0x00004000 47492
00:31:40.342 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:3542: mbedtls_pk_sign() returned -17280 (-0x4380)
00:31:40.344 > IDF/components/mbedtls/mbedtls/library/ssl_tls.c:5815: <= handshake
00:31:40.345 > tcp_recved: received 517 bytes, wnd 5744 (0).
00:31:40.345 > mbedtls_ssl_handshake failed: -17280
gilles-peskine-arm commented 1 year ago

I've noticed that some times the preceeding handshake's error code is -17168 (-0x4310), which I've tried to find the represented meaning, but failed to

Use programs/util/strerror to see the error message corresponding to a numerical value. The values don't depend on the architecture or on the compile-time configuration, so you can build a copy of the library in the default configuration on your development machine for this program.

mbedtls-strerror -0x4310
Last error was: -0x4310 - RSA - The private key operation failed : BIGNUM - Memory allocation failed

So something is leaking memory.

The memory leak is probably the cause of the signature verification failure, not a consequence. Although I am a bit surprised that the error is consistently MBEDTLS_ERR_RSA_VERIFY_FAILED: looking at our RSA code, it never returns this exact error for out-of-memory. So I suspect that there's an uncaught malloc failure somewhere else which leads to an invalid key object or invalid buffer content at some point.

HamzaHajeir commented 1 year ago

Use programs/util/strerror to see the error message corresponding to a numerical value. The values don't depend on the architecture or on the compile-time configuration, so you can build a copy of the library in the default configuration on your development machine for this program.

mbedtls-strerror -0x4310
Last error was: -0x4310 - RSA - The private key operation failed : BIGNUM - Memory allocation failed

I've missed it when writing, I was looking for the bit-mask corresponding codes and it's right, 0x0010 corresponds to a failed allocation.

So something is leaking memory.

The memory leak is probably the cause of the signature verification failure, not a consequence. Although I am a bit surprised that the error is consistently MBEDTLS_ERR_RSA_VERIFY_FAILED: looking at our RSA code, it never returns this exact error for out-of-memory. So I suspect that there's an uncaught malloc failure somewhere else which leads to an invalid key object or invalid buffer content at some point.

But the heap memory is available here, except it's an allocation within a pool managed by mbedtls, what do you think? As my calculation over 48 failed handshake, it was ~165 Bytes leaked per failed connection on average.

HamzaHajeir commented 1 year ago

I could narrow down the issue to the state which the error being return:

Debug level 1.

00:12:25.015 > --> mbedtls_ssl_handshake_step state 4 heap 57868 -->
00:12:25.803 > IDF/components/mbedtls/mbedtls/library/ssl_srv.c:3542: mbedtls_pk_sign() returned -17280 (-0x4380)
00:12:25.805 > <-- mbedtls_ssl_handshake_step state 4 ret -17280 heap 44964 <--

This corresponds to code:

    bool mbedtls_is_ssl_handshake_over = false;
    int ret;
    do {
      LWIP_DEBUGF(ALTCP_MBEDTLS_DEBUG, ("--> mbedtls_ssl_handshake_step state %d heap %u -->\n", state->ssl_context.state, get_heap()));
      ret = mbedtls_ssl_handshake_step(&state->ssl_context);
      mbedtls_is_ssl_handshake_over = (state->ssl_context.state == MBEDTLS_SSL_HANDSHAKE_OVER);
      LWIP_DEBUGF(ALTCP_MBEDTLS_DEBUG, ("<-- mbedtls_ssl_handshake_step state %d ret %d heap %u <--\n", state->ssl_context.state, ret, get_heap()));
    }
    while (!mbedtls_is_ssl_handshake_over && !ret);
HamzaHajeir commented 1 year ago

As a continuation of debug, an attached log of several https requests happen, where SSL session is also managed.

There happens memory leak for every new HTTPS connection handshake.

device-monitor-230629-161033 copy 2.log

A manual memory leak calculation per handshake suggests multiple probable bytes per handshake (ranges from 203B to 299B).

No memory leak encountered by a reconnect handshake as a client.

gilles-peskine-arm commented 1 year ago

Can you use tools like Asan to identify the memory leak precisely? If not, can you at least find the exact amount that's leaked, and look for a structure that has that size?

We run a lot of tests with Asan and they validate that the library doesn't have memory leaks. But of course that only validates that there are no memory leaks for the settings that we test: there can be a leak in a different configuration or scenario.

HamzaHajeir commented 1 year ago

I'll check that out soon, meanwhile can you mention which structures I should check against?

On Thu, Jun 29, 2023, 17:54 Gilles Peskine @.***> wrote:

Can you use tools like Asan https://github.com/google/sanitizers/wiki/AddressSanitizer to identify the memory leak precisely? If not, can you at least find the exact amount that's leaked, and look for a structure that has that size?

We run a lot of tests with Asan and they validate that the library doesn't have memory leaks. But of course that only validates that there are no memory leaks for the settings that we test: there can be a leak in a different configuration or scenario.

— Reply to this email directly, view it on GitHub https://github.com/Mbed-TLS/mbedtls/issues/7833#issuecomment-1613326900, or unsubscribe https://github.com/notifications/unsubscribe-auth/AH3O7J4XGHCCMPOEESXLZHTXNWJKXANCNFSM6AAAAAAZTGBEBY . You are receiving this because you authored the thread.Message ID: @.***>

gilles-peskine-arm commented 1 year ago

Probably one of the SSL structures (mbedtls_ssl_context, mbedtls_ssl_session or mbedtls_ssl_handshake — their size heavily depends on the configuration), or the RSA key (mbedtls_rsa_context) but that's less than 200B (or far more if it's the RSA context and the embedded MPI objects). But it could be something else, like a certificate mbedtls_x509_crt.

HamzaHajeir commented 1 year ago

Given the size of SSL structures in my setup:

mbedtls_ssl_session size = 128
mbedtls_ssl_context size = 552
mbedtls_ssl_config size = 232
mbedtls_ssl_transform size = 212
mbedtls_ssl_handshake_params size = 2264
mbedtls_ssl_sig_hash_set_t size = 8
mbedtls_ssl_key_cert size = 12
mbedtls_ssl_flight_item size = 16

And given that I've identified the exact amount of memory leaked per handshake, which is 164 Bytes, which is the sum of the following structures:

Given that I'm not initiating any session for server requests, should my code manage them even so? and how further?

** My previous calculation was based on Web refresh with the browser, which initiates more than a connection simultaneously as needed by. Last calculation is based on CURL command line which initiates exactly one connection against the server.

gilles-peskine-arm commented 1 year ago

Given that I'm not initiating any session for server requests, should my code manage them even so?

I think your code should only reference mbedtls_ssl_session in a server that does session resumption (with tickets or a cache). Otherwise the session structure is just internal to the mbedtls_ssl_context and should be freed when you free or reset the context.

HamzaHajeir commented 1 year ago

In the current setup I've the tickets and cache enabled and managed, but it's shared across requests (at the server level): https://github.com/HamzaHajeir/esp-lwip/blob/2.1.2-esp-patch/src/apps/altcp_tls/altcp_tls_mbedtls.c#L115-L121

Initialization: https://github.com/HamzaHajeir/esp-lwip/blob/2.1.2-esp-patch/src/apps/altcp_tls/altcp_tls_mbedtls.c#L848-L868

Freeing is done when the listening connection (in LwIP it's LISTEN Protocol Control Block - PCB) gets closed, only: https://github.com/HamzaHajeir/esp-lwip/blob/2.1.2-esp-patch/src/apps/altcp_tls/altcp_tls_mbedtls.c#L1067-L1072

Should these be managed on request-level .. not server-level?

It's insured that the mbedtls_ssl_context is freed upon any connection close, see: https://github.com/HamzaHajeir/esp-lwip/blob/2.1.2-esp-patch/src/apps/altcp_tls/altcp_tls_mbedtls.c#L1357

What do you think?

gilles-peskine-arm commented 1 year ago

I had a quick look at your code and I don't see anything obviously wrong. But I'm not familiar at all with LWIP, it might be worth asking people who are familiar with it.

One thing to pay attention is, if there has ever been an error on the connection, then you must close it: attempting to use the connection may put the SSL object in a bad state. But the error handling for the handshake looks fine to me.

HamzaHajeir commented 1 year ago

I've just noticed missing updates to esp-lwip repo meeting latest changes, occured when I was preparing lwip patches.

One thing to pay attention is, if there has ever been an error on the connection, then you must close it: attempting to use the connection may put the SSL object in a bad state. But the error handling for the handshake looks fine to me.

Correct, the TCP connection reset is well managed there, but we might further check these lines which are TLS protocol related. Although logs across history show only one occurance of connection was closed gracefully.

Also what I've suspected, but couldn't confirm due to not-enough experience in C, is the memory initialization of configuration struct which seems out of order compared to the structure sequence. But however, this is done per server setup, not every connection.

Another note: In a previous manual calculation of memory leak per handshake (browser refreshes "some with full refresh") resulted an average leak of 165B across 48 refresh instances. Which seems very close to the observed 164B.

So this might relate to a full handshake process; wherein the browser initiates more than a connection, and when one has succeeded it aborts the other, shortening the probability of leak to be in advanced states (MBEDTLS_SSL_CLIENT_CERTIFICATEto MBEDTLS_SSL_HANDSHAKE_WRAPUP) if it was true.

What do you think?

gilles-peskine-arm commented 1 year ago

seems out of order compared to the structure sequence

That doesn't matter.

the browser initiates more than a connection, and when one has succeeded it aborts the other

This is a promising lead. We have a lot of negative tests where the client sends an invalid message, but I'm not sure we have tests where the client just closes the connection. However, I do see a call to mbedtls_ssl_free in altcp_mbedtls_dealloc, and that does free all the session data (it's not missable). So as long as this function is called, there should be no leak of mbedtls data. And if the struct altcp_pcb isn't leaking then presumably altcp_mbedtls_dealloc is getting called.

HamzaHajeir commented 1 year ago

I've just confirmed that altcp_close(conn) is being called to a given connection, also old logs that enabled LwIP debug showed altcp_mbedtls_dealloc is being called. (debug line in a local build).

I've further made another test wherein I've turned it to ALTCP_TCP rather ALTCP_TLS, to check whether it's an application/TCP leak or not, it initially showed a leak, but the memory did recover after a while (I think by LwIP internal operation in freeing closed PCBs).

Suspecting my code which is a library I maintain, I've failed in finding any source of memory leak, really (One can trace H4AT_TLS macro for TLS-related code).