Skip to content

Commit d8c28be

Browse files
mhightower83JeroenSt
mhightower83
authored and
JeroenSt
committed
Corrected missed edit for _recv() in ASYNC_TCP_SSL_ENABLED in AsyncServer::_poll().
And other missed edit for errorTracker around ASYNC_TCP_SSL_ENABLED. This should resolve @kasedy comment me-no-dev#115 (comment) and @mcspr. Tested ASYNC_TCP_SSL_ENABLED using marvinroger/async-mqtt-client/ .. examples/FullyFeaturedSSL. Ran test against test.mosquitto.org's server. Thanks to @mcspr for suggesting. Updated tcp_ssl_read() to check for fd_data being freed by callback functions. I observed this with asyncmqttclient example. When finger print did not match during fd_data->on_handshake callback, the mqtt library did a close(true) which rippled down to an tcp_ssl_free(). Improvements in debug printing to handle debug print from tcp.axtls.c.
1 parent 1547686 commit d8c28be

File tree

4 files changed

+105
-37
lines changed

4 files changed

+105
-37
lines changed

‎src/DebugPrintMacros.h

+33-17
Original file line numberDiff line numberDiff line change
@@ -27,18 +27,34 @@ inline struct _DEBUG_TIME_STAMP debugTimeStamp(void) {
2727
}
2828
#endif
2929

30+
#if defined(DEBUG_ESP_PORT) && !defined(DEBUG_ESP_PORT_PRINTF)
31+
32+
#ifdef __cplusplus
33+
#define DEBUG_ESP_PORT_PRINTF(format, ...) DEBUG_ESP_PORT.printf((format), ##__VA_ARGS__)
34+
#define DEBUG_ESP_PORT_PRINTF_F(format, ...) DEBUG_ESP_PORT.printf_P(PSTR(format), ##__VA_ARGS__)
35+
#define DEBUG_ESP_PORT_FLUSH DEBUG_ESP_PORT.flush
36+
#else
37+
// Handle debug printing from .c without CPP Stream, Print, ... classes
38+
// Cannot handle flash strings in this setting
39+
#define DEBUG_ESP_PORT_PRINTF ets_uart_printf
40+
#define DEBUG_ESP_PORT_PRINTF_F ets_uart_printf
41+
#define DEBUG_ESP_PORT_FLUSH (void)0
42+
#endif
43+
44+
#endif
45+
3046
#if defined(DEBUG_ESP_PORT) && !defined(DEBUG_GENERIC)
3147
#define DEBUG_GENERIC( module, format, ... ) \
3248
do { \
3349
struct _DEBUG_TIME_STAMP st = debugTimeStamp(); \
34-
DEBUG_ESP_PORT.printf( DEBUG_TIME_STAMP_FMT module " " format, st.whole, st.dec, ##__VA_ARGS__ ); \
50+
DEBUG_ESP_PORT_PRINTF( (DEBUG_TIME_STAMP_FMT module " " format), st.whole, st.dec, ##__VA_ARGS__ ); \
3551
} while(false)
3652
#endif
37-
#if defined(DEBUG_ESP_PORT) && !defined(DEBUG_GENERIC_P)
38-
#define DEBUG_GENERIC_P( module, format, ... ) \
53+
#if defined(DEBUG_ESP_PORT) && !defined(DEBUG_GENERIC_F)
54+
#define DEBUG_GENERIC_F( module, format, ... ) \
3955
do { \
4056
struct _DEBUG_TIME_STAMP st = debugTimeStamp(); \
41-
DEBUG_ESP_PORT.printf_P(PSTR( DEBUG_TIME_STAMP_FMT module " " format ), st.whole, st.dec, ##__VA_ARGS__ ); \
57+
DEBUG_ESP_PORT_PRINTF_F( (DEBUG_TIME_STAMP_FMT module " " format), st.whole, st.dec, ##__VA_ARGS__ ); \
4258
} while(false)
4359
#endif
4460

@@ -47,16 +63,16 @@ inline struct _DEBUG_TIME_STAMP debugTimeStamp(void) {
4763
do { \
4864
if ( !(a) ) { \
4965
DEBUG_GENERIC( module, "%s:%s:%u: ASSERT("#a") failed!\n", __FILE__, __func__, __LINE__); \
50-
DEBUG_ESP_PORT.flush(); \
66+
DEBUG_ESP_PORT_FLUSH(); \
5167
} \
5268
} while(false)
5369
#endif
54-
#if defined(DEBUG_GENERIC_P) && !defined(ASSERT_GENERIC_P)
55-
#define ASSERT_GENERIC_P( a, module ) \
70+
#if defined(DEBUG_GENERIC_F) && !defined(ASSERT_GENERIC_F)
71+
#define ASSERT_GENERIC_F( a, module ) \
5672
do { \
5773
if ( !(a) ) { \
58-
DEBUG_GENERIC_P( module, "%s:%s:%u: ASSERT("#a") failed!\n", __FILE__, __func__, __LINE__); \
59-
DEBUG_ESP_PORT.flush(); \
74+
DEBUG_GENERIC_F( module, "%s:%s:%u: ASSERT("#a") failed!\n", __FILE__, __func__, __LINE__); \
75+
DEBUG_ESP_PORT_FLUSH(); \
6076
} \
6177
} while(false)
6278
#endif
@@ -65,32 +81,32 @@ inline struct _DEBUG_TIME_STAMP debugTimeStamp(void) {
6581
#define DEBUG_GENERIC(...) do { (void)0;} while(false)
6682
#endif
6783

68-
#ifndef DEBUG_GENERIC_P
69-
#define DEBUG_GENERIC_P(...) do { (void)0;} while(false)
84+
#ifndef DEBUG_GENERIC_F
85+
#define DEBUG_GENERIC_F(...) do { (void)0;} while(false)
7086
#endif
7187

7288
#ifndef ASSERT_GENERIC
7389
#define ASSERT_GENERIC(...) do { (void)0;} while(false)
7490
#endif
7591

76-
#ifndef ASSERT_GENERIC_P
77-
#define ASSERT_GENERIC_P(...) do { (void)0;} while(false)
92+
#ifndef ASSERT_GENERIC_F
93+
#define ASSERT_GENERIC_F(...) do { (void)0;} while(false)
7894
#endif
7995

8096
#ifndef DEBUG_ESP_PRINTF
81-
#define DEBUG_ESP_PRINTF( format, ...) DEBUG_GENERIC_P("[%s]", format, &_FILENAME_[1], ##__VA_ARGS__)
97+
#define DEBUG_ESP_PRINTF( format, ...) DEBUG_GENERIC_F("[%s]", format, &_FILENAME_[1], ##__VA_ARGS__)
8298
#endif
8399

84100
#if defined(DEBUG_ESP_ASYNC_TCP) && !defined(ASYNC_TCP_DEBUG)
85-
#define ASYNC_TCP_DEBUG( format, ...) DEBUG_GENERIC_P("[ASYNC_TCP]", format, ##__VA_ARGS__)
101+
#define ASYNC_TCP_DEBUG( format, ...) DEBUG_GENERIC_F("[ASYNC_TCP]", format, ##__VA_ARGS__)
86102
#endif
87103

88104
#ifndef ASYNC_TCP_ASSERT
89-
#define ASYNC_TCP_ASSERT( a ) ASSERT_GENERIC_P( (a), "[ASYNC_TCP]")
105+
#define ASYNC_TCP_ASSERT( a ) ASSERT_GENERIC_F( (a), "[ASYNC_TCP]")
90106
#endif
91107

92108
#if defined(DEBUG_ESP_TCP_SSL) && !defined(TCP_SSL_DEBUG)
93-
#define TCP_SSL_DEBUG( format, ...) DEBUG_GENERIC_P("[TCP_SSL]", format, ##__VA_ARGS__)
109+
#define TCP_SSL_DEBUG( format, ...) DEBUG_GENERIC_F("[TCP_SSL]", format, ##__VA_ARGS__)
94110
#endif
95111

96112
#endif //_DEBUG_PRINT_MACROS_H

‎src/ESPAsyncTCP.cpp

+32-9
Original file line numberDiff line numberDiff line change
@@ -70,6 +70,7 @@ yield(), etc.
7070
7171
7272
*/
73+
7374
#include "Arduino.h"
7475

7576
#include "ESPAsyncTCP.h"
@@ -355,10 +356,12 @@ void AsyncClient::abort(){
355356
void AsyncClient::close(bool now){
356357
if(_pcb)
357358
tcp_recved(_pcb, _rx_ack_len);
358-
if(now)
359+
if(now) {
360+
ASYNC_TCP_DEBUG("close[%u]: AsyncClient 0x%" PRIXPTR "\n", getConnectionId(), uintptr_t(this));
359361
_close();
360-
else
362+
} else {
361363
_close_pcb = true;
364+
}
362365
}
363366

364367
void AsyncClient::stop() {
@@ -503,6 +506,7 @@ void AsyncClient::_close(){
503506
err_t err = tcp_close(_pcb);
504507
if(ERR_OK == err) {
505508
setCloseError(err);
509+
ASYNC_TCP_DEBUG("_close[%u]: AsyncClient 0x%" PRIXPTR "\n", getConnectionId(), uintptr_t(this));
506510
} else {
507511
ASYNC_TCP_DEBUG("_close[%u]: abort() called for AsyncClient 0x%" PRIXPTR "\n", getConnectionId(), uintptr_t(this));
508512
abort();
@@ -664,6 +668,7 @@ void AsyncClient::_poll(std::shared_ptr<ACErrorTracker>& errorTracker, tcp_pcb*
664668

665669
// Close requested
666670
if(_close_pcb){
671+
ASYNC_TCP_DEBUG("_poll[%u]: Process _close_pcb.\n", errorTracker->getConnectionId() );
667672
_close_pcb = false;
668673
_close();
669674
return;
@@ -679,12 +684,14 @@ void AsyncClient::_poll(std::shared_ptr<ACErrorTracker>& errorTracker, tcp_pcb*
679684
}
680685
// RX Timeout
681686
if(_rx_since_timeout && (now - _rx_last_packet) >= (_rx_since_timeout * 1000)){
687+
ASYNC_TCP_DEBUG("_poll[%u]: RX Timeout.\n", errorTracker->getConnectionId() );
682688
_close();
683689
return;
684690
}
685691
#if ASYNC_TCP_SSL_ENABLED
686692
// SSL Handshake Timeout
687693
if(_pcb_secure && !_handshake_done && (now - _rx_last_packet) >= 2000){
694+
ASYNC_TCP_DEBUG("_poll[%u]: SSL Handshake Timeout.\n", errorTracker->getConnectionId() );
688695
_close();
689696
return;
690697
}
@@ -762,19 +769,28 @@ err_t AsyncClient::_s_connected(void* arg, void* tpcb, err_t err){
762769

763770
#if ASYNC_TCP_SSL_ENABLED
764771
void AsyncClient::_s_data(void *arg, struct tcp_pcb *tcp, uint8_t * data, size_t len){
772+
(void)tcp;
765773
AsyncClient *c = reinterpret_cast<AsyncClient*>(arg);
766774
if(c->_recv_cb)
767775
c->_recv_cb(c->_recv_cb_arg, c, data, len);
768776
}
769777

770778
void AsyncClient::_s_handshake(void *arg, struct tcp_pcb *tcp, SSL *ssl){
779+
(void)tcp;
780+
(void)ssl;
771781
AsyncClient *c = reinterpret_cast<AsyncClient*>(arg);
772782
c->_handshake_done = true;
773783
if(c->_connect_cb)
774784
c->_connect_cb(c->_connect_cb_arg, c);
775785
}
776786

777787
void AsyncClient::_s_ssl_error(void *arg, struct tcp_pcb *tcp, int8_t err){
788+
(void)tcp;
789+
#ifdef DEBUG_ESP_ASYNC_TCP
790+
AsyncClient *c = reinterpret_cast<AsyncClient*>(arg);
791+
auto errorTracker = c->getACErrorTracker();
792+
ASYNC_TCP_DEBUG("_ssl_error[%u] err = %d\n", errorTracker->getConnectionId(), err);
793+
#endif
778794
reinterpret_cast<AsyncClient*>(arg)->_ssl_error(err);
779795
}
780796
#endif
@@ -1230,7 +1246,7 @@ err_t AsyncServer::_accept(tcp_pcb* pcb, err_t err){
12301246
}
12311247
return ERR_OK;
12321248
}
1233-
ASYNC_TCP_DEBUG("### put to wait: %d\n", _clients_waiting);
1249+
//1 ASYNC_TCP_DEBUG("### put to wait: %d\n", _clients_waiting);
12341250
new_item->pcb = pcb;
12351251
new_item->pb = NULL;
12361252
new_item->next = NULL;
@@ -1252,6 +1268,7 @@ err_t AsyncServer::_accept(tcp_pcb* pcb, err_t err){
12521268
if(c){
12531269
ASYNC_TCP_DEBUG("_accept[%u]: SSL connected\n", c->getConnectionId());
12541270
c->onConnect([this](void * arg, AsyncClient *c){
1271+
(void)arg;
12551272
_connect_cb(_connect_cb_arg, c);
12561273
}, this);
12571274
} else {
@@ -1303,6 +1320,7 @@ err_t AsyncServer::_s_accept(void *arg, tcp_pcb* pcb, err_t err){
13031320

13041321
#if ASYNC_TCP_SSL_ENABLED
13051322
err_t AsyncServer::_poll(tcp_pcb* pcb){
1323+
err_t err = ERR_OK;
13061324
if(!tcp_ssl_has_client() && _pending){
13071325
struct pending_pcb * p = _pending;
13081326
if(p->pcb == pcb){
@@ -1314,29 +1332,34 @@ err_t AsyncServer::_poll(tcp_pcb* pcb){
13141332
p->next = b->next;
13151333
p = b;
13161334
}
1317-
ASYNC_TCP_DEBUG("### remove from wait: %d\n", _clients_waiting);
1335+
//1 ASYNC_TCP_DEBUG("### remove from wait: %d\n", _clients_waiting);
13181336
AsyncClient *c = new (std::nothrow) AsyncClient(pcb, _ssl_ctx);
13191337
if(c){
13201338
c->onConnect([this](void * arg, AsyncClient *c){
1339+
(void)arg;
13211340
_connect_cb(_connect_cb_arg, c);
13221341
}, this);
1323-
if(p->pb)
1324-
c->_recv(pcb, p->pb, 0);
1342+
if(p->pb) {
1343+
auto errorTracker = c->getACErrorTracker();
1344+
c->_recv(errorTracker, pcb, p->pb, 0);
1345+
err = errorTracker->getCallbackCloseError();
1346+
}
13251347
}
13261348
// Should there be error handling for when "new AsynClient" fails??
13271349
free(p);
13281350
}
1329-
return ERR_OK;
1351+
return err;
13301352
}
13311353

13321354
err_t AsyncServer::_recv(struct tcp_pcb *pcb, struct pbuf *pb, err_t err){
1355+
(void)err;
13331356
if(!_pending)
13341357
return ERR_OK;
13351358

13361359
struct pending_pcb * p;
13371360

13381361
if(!pb){
1339-
ASYNC_TCP_DEBUG("### close from wait: %d\n", _clients_waiting);
1362+
//1 ASYNC_TCP_DEBUG("### close from wait: %d\n", _clients_waiting);
13401363
p = _pending;
13411364
if(p->pcb == pcb){
13421365
_pending = _pending->next;
@@ -1357,7 +1380,7 @@ err_t AsyncServer::_recv(struct tcp_pcb *pcb, struct pbuf *pb, err_t err){
13571380
return ERR_ABRT;
13581381
}
13591382
} else {
1360-
ASYNC_TCP_DEBUG("### wait _recv: %u %d\n", pb->tot_len, _clients_waiting);
1383+
//1 ASYNC_TCP_DEBUG("### wait _recv: %u %d\n", pb->tot_len, _clients_waiting);
13611384
p = _pending;
13621385
while(p && p->pcb != pcb)
13631386
p = p->next;

‎src/async_config.h

+5-1
Original file line numberDiff line numberDiff line change
@@ -20,9 +20,11 @@
2020
// Starting with Arduino Core 2.4.0 and up the define of DEBUG_ESP_PORT
2121
// can be handled through the Arduino IDE Board options instead of here.
2222
// #define DEBUG_ESP_PORT Serial
23-
2423
// #define DEBUG_ESP_ASYNC_TCP 1
2524
// #define DEBUG_ESP_TCP_SSL 1
25+
26+
#ifndef DEBUG_SKIP__DEBUG_PRINT_MACROS
27+
2628
#include <DebugPrintMacros.h>
2729

2830
#ifndef ASYNC_TCP_ASSERT
@@ -35,4 +37,6 @@
3537
#define TCP_SSL_DEBUG(...) do { (void)0;} while(false)
3638
#endif
3739

40+
#endif
41+
3842
#endif /* LIBRARIES_ESPASYNCTCP_SRC_ASYNC_CONFIG_H_ */

‎src/tcp_axtls.c

+35-10
Original file line numberDiff line numberDiff line change
@@ -22,7 +22,13 @@
2222
* Compatibility for AxTLS with LWIP raw tcp mode (http://lwip.wikia.com/wiki/Raw/TCP)
2323
* Original Code and Inspiration: Slavey Karadzhov
2424
*/
25+
26+
// To handle all the definitions needed for debug printing, we need to delay
27+
// macro definitions till later.
28+
#define DEBUG_SKIP__DEBUG_PRINT_MACROS 1
2529
#include <async_config.h>
30+
#undef DEBUG_SKIP__DEBUG_PRINT_MACROS
31+
2632
#if ASYNC_TCP_SSL_ENABLED
2733

2834
#include "lwip/opt.h"
@@ -34,6 +40,13 @@
3440
#include <stdbool.h>
3541
#include <tcp_axtls.h>
3642

43+
// ets_uart_printf is defined in esp8266_undocumented.h, in newer Arduino ESP8266 Core.
44+
extern int ets_uart_printf(const char *format, ...) __attribute__ ((format (printf, 1, 2)));
45+
#include <DebugPrintMacros.h>
46+
#ifndef TCP_SSL_DEBUG
47+
#define TCP_SSL_DEBUG(...) do { (void)0;} while(false)
48+
#endif
49+
3750
uint8_t * default_private_key = NULL;
3851
uint16_t default_private_key_len = 0;
3952

@@ -377,7 +390,8 @@ int tcp_ssl_read(struct tcp_pcb *tcp, struct pbuf *p) {
377390

378391
do {
379392
read_bytes = ssl_read(fd_data->ssl, &read_buf);
380-
//TCP_SSL_DEBUG("tcp_ssl_ssl_read: %d\n", read_bytes);
393+
TCP_SSL_DEBUG("tcp_ssl_ssl_read: %d\n", read_bytes);
394+
381395
if(read_bytes < SSL_OK) {
382396
if(read_bytes != SSL_CLOSE_NOTIFY) {
383397
TCP_SSL_DEBUG("tcp_ssl_read: read error: %d\n", read_bytes);
@@ -387,20 +401,31 @@ int tcp_ssl_read(struct tcp_pcb *tcp, struct pbuf *p) {
387401
} else if(read_bytes > 0){
388402
if(fd_data->on_data){
389403
fd_data->on_data(fd_data->arg, tcp, read_buf, read_bytes);
404+
// fd_data may have been freed in callback
405+
fd_data = tcp_ssl_get(tcp);
406+
if(NULL == fd_data)
407+
return SSL_CLOSE_NOTIFY;
390408
}
391409
total_bytes+= read_bytes;
392410
} else {
393411
if(fd_data->handshake != SSL_OK) {
394-
fd_data->handshake = ssl_handshake_status(fd_data->ssl);
395-
if(fd_data->handshake == SSL_OK){
396-
//TCP_SSL_DEBUG("tcp_ssl_read: handshake OK\n");
412+
// fd_data may be freed in callbacks.
413+
int handshake = fd_data->handshake = ssl_handshake_status(fd_data->ssl);
414+
if(handshake == SSL_OK){
415+
TCP_SSL_DEBUG("tcp_ssl_read: handshake OK\n");
397416
if(fd_data->on_handshake)
398417
fd_data->on_handshake(fd_data->arg, fd_data->tcp, fd_data->ssl);
399-
} else if(fd_data->handshake != SSL_NOT_OK){
400-
TCP_SSL_DEBUG("tcp_ssl_read: handshake error: %d\n", fd_data->handshake);
418+
fd_data = tcp_ssl_get(tcp);
419+
if(NULL == fd_data)
420+
return SSL_CLOSE_NOTIFY;
421+
} else if(handshake != SSL_NOT_OK){
422+
TCP_SSL_DEBUG("tcp_ssl_read: handshake error: %d\n", handshake);
401423
if(fd_data->on_error)
402-
fd_data->on_error(fd_data->arg, fd_data->tcp, fd_data->handshake);
403-
return fd_data->handshake;
424+
fd_data->on_error(fd_data->arg, fd_data->tcp, handshake);
425+
return handshake;
426+
// With current code APP gets called twice at onError handler.
427+
// Once here and again after return when handshake != SSL_CLOSE_NOTIFY.
428+
// As always APP must never free resources at onError only at onDisconnect.
404429
}
405430
}
406431
}
@@ -525,13 +550,13 @@ int ax_port_write(int fd, uint8_t *data, uint16_t len) {
525550
TCP_SSL_DEBUG("ax_port_write: No memory %d (%d)\n", tcp_len, len);
526551
return err;
527552
}
528-
TCP_SSL_DEBUG("ax_port_write: tcp_write error: %d\n", err);
553+
TCP_SSL_DEBUG("ax_port_write: tcp_write error: %ld\n", err);
529554
return err;
530555
} else if (err == ERR_OK) {
531556
//TCP_SSL_DEBUG("ax_port_write: tcp_output: %d / %d\n", tcp_len, len);
532557
err = tcp_output(fd_data->tcp);
533558
if(err != ERR_OK) {
534-
TCP_SSL_DEBUG("ax_port_write: tcp_output err: %d\n", err);
559+
TCP_SSL_DEBUG("ax_port_write: tcp_output err: %ld\n", err);
535560
return err;
536561
}
537562
}

0 commit comments

Comments
 (0)