Logging refactoring which supports macros redefinition

Author: mathieucarbou

platformio.ini

@@ -1,5 +1,5 @@
 [platformio]
-default_envs = arduino-2, arduino-3
+default_envs = arduino-2, arduino-3, arduino-libretiny
 lib_dir = .
 ; src_dir = examples/Client
 ; src_dir = examples/FetchWebsite

src/AsyncTCP.cpp

@@ -2,31 +2,13 @@
 // Copyright 2016-2025 Hristo Gochkov, Mathieu Carbou, Emil Muratov
 
 #include "AsyncTCP.h"
+#include "AsyncTCPLogging.h"
 #include "AsyncTCPSimpleIntrusiveList.h"
 
-#ifndef LIBRETINY
-#include <esp_log.h>
-
-#ifdef ARDUINO
-#include <esp32-hal.h>
-#include <esp32-hal-log.h>
-#if (ESP_IDF_VERSION_MAJOR >= 5)
-#include <NetworkInterface.h>
-#endif
-#else
-#include "esp_timer.h"
-#define log_e(...) ESP_LOGE(__FILE__, __VA_ARGS__)
-#define log_w(...) ESP_LOGW(__FILE__, __VA_ARGS__)
-#define log_i(...) ESP_LOGI(__FILE__, __VA_ARGS__)
-#define log_d(...) ESP_LOGD(__FILE__, __VA_ARGS__)
-#define log_v(...) ESP_LOGV(__FILE__, __VA_ARGS__)
-static unsigned long millis() {
-  return (unsigned long)(esp_timer_get_time() / 1000ULL);
-}
-#endif
-#endif
-
-#ifdef LIBRETINY
+/**
+ * LibreTiny specific configurations
+ */
+#if defined(LIBRETINY)
 #include <Arduino.h>
 // LibreTiny does not support IDF - disable code that expects it to be available
 #define ESP_IDF_VERSION_MAJOR (0)
@@ -35,7 +17,27 @@ static unsigned long millis() {
 // ESP watchdog is not available
 #undef CONFIG_ASYNC_TCP_USE_WDT
 #define CONFIG_ASYNC_TCP_USE_WDT 0
-#endif
+#endif  // LIBRETINY
+
+/**
+ * Arduino specific configurations
+ */
+#if defined(ARDUINO) && !defined(LIBRETINY)
+#include <esp_idf_version.h>
+#if (ESP_IDF_VERSION_MAJOR >= 5)
+#include <NetworkInterface.h>
+#endif  // ESP_IDF_VERSION_MAJOR
+#endif  // ARDUINO
+
+/**
+ * ESP-IDF specific configurations
+ */
+#if !defined(LIBRETINY) && !defined(ARDUINO)
+#include "esp_timer.h"
+static unsigned long millis() {
+  return (unsigned long)(esp_timer_get_time() / 1000ULL);
+}
+#endif  // !LIBRETINY && !ARDUINO
 
 extern "C" {
 #include "lwip/dns.h"
@@ -146,7 +148,7 @@ struct lwip_tcp_event_packet_t {
     } dns;
   };
 
-  inline lwip_tcp_event_packet_t(lwip_tcp_event_t _event, AsyncClient *_client) : next(nullptr), event(_event), client(_client){};
+  inline lwip_tcp_event_packet_t(lwip_tcp_event_t _event, AsyncClient *_client) : next(nullptr), event(_event), client(_client) {};
 };
 
 // Detail class for interacting with AsyncClient internals, but without exposing the API
@@ -172,7 +174,7 @@ class queue_mutex_guard {
   bool holds_mutex;
 
 public:
-  inline queue_mutex_guard() : holds_mutex(xSemaphoreTake(_async_queue_mutex, portMAX_DELAY)){};
+  inline queue_mutex_guard() : holds_mutex(xSemaphoreTake(_async_queue_mutex, portMAX_DELAY)) {};
   inline ~queue_mutex_guard() {
     if (holds_mutex) {
       xSemaphoreGive(_async_queue_mutex);
@@ -231,7 +233,7 @@ static inline lwip_tcp_event_packet_t *_get_async_event() {
          next_pkt = _async_queue.begin()) {
       // if the next event that will come is a poll event for the same connection, we can discard it and continue
       _free_event(_async_queue.pop_front());
-      log_d("coalescing polls, network congestion or async callbacks might be too slow!");
+      async_tcp_log_d("coalescing polls, network congestion or async callbacks might be too slow!");
     }
 
     /*
@@ -245,7 +247,7 @@ static inline lwip_tcp_event_packet_t *_get_async_event() {
     */
     if (_async_queue.size() > (rand() % CONFIG_ASYNC_TCP_QUEUE_SIZE / 4 + CONFIG_ASYNC_TCP_QUEUE_SIZE * 3 / 4)) {
       _free_event(e);
-      log_d("discarding poll due to queue congestion");
+      async_tcp_log_d("discarding poll due to queue congestion");
       continue;
     }
 
@@ -308,7 +310,7 @@ void AsyncTCP_detail::handle_async_event(lwip_tcp_event_packet_t *e) {
 static void _async_service_task(void *pvParameters) {
 #if CONFIG_ASYNC_TCP_USE_WDT
   if (esp_task_wdt_add(NULL) != ESP_OK) {
-    log_w("Failed to add async task to WDT");
+    async_tcp_log_w("Failed to add async task to WDT");
   }
 #endif
   for (;;) {
@@ -404,7 +406,7 @@ static int8_t _tcp_connected(void *arg, tcp_pcb *pcb, int8_t err) {
   AsyncClient *client = reinterpret_cast<AsyncClient *>(arg);
   lwip_tcp_event_packet_t *e = new (std::nothrow) lwip_tcp_event_packet_t{LWIP_TCP_CONNECTED, client};
   if (!e) {
-    log_e("Failed to allocate event packet");
+    async_tcp_log_e("Failed to allocate event packet");
     return ERR_MEM;
   }
   e->connected.pcb = pcb;
@@ -418,9 +420,9 @@ int8_t AsyncTCP_detail::tcp_poll(void *arg, struct tcp_pcb *pcb) {
   // throttle polling events queueing when event queue is getting filled up, let it handle _onack's
   {
     queue_mutex_guard guard;
-    // log_d("qs:%u", _async_queue.size());
+    // async_tcp_log_d("qs:%u", _async_queue.size());
     if (_async_queue.size() > (rand() % CONFIG_ASYNC_TCP_QUEUE_SIZE / 2 + CONFIG_ASYNC_TCP_QUEUE_SIZE / 4)) {
-      log_d("throttling");
+      async_tcp_log_d("throttling");
       return ERR_OK;
     }
   }
@@ -429,7 +431,7 @@ int8_t AsyncTCP_detail::tcp_poll(void *arg, struct tcp_pcb *pcb) {
   AsyncClient *client = reinterpret_cast<AsyncClient *>(arg);
   lwip_tcp_event_packet_t *e = new (std::nothrow) lwip_tcp_event_packet_t{LWIP_TCP_POLL, client};
   if (!e) {
-    log_e("Failed to allocate event packet");
+    async_tcp_log_e("Failed to allocate event packet");
     return ERR_MEM;
   }
   e->poll.pcb = pcb;
@@ -443,7 +445,7 @@ int8_t AsyncTCP_detail::tcp_recv(void *arg, struct tcp_pcb *pcb, struct pbuf *pb
   AsyncClient *client = reinterpret_cast<AsyncClient *>(arg);
   lwip_tcp_event_packet_t *e = new (std::nothrow) lwip_tcp_event_packet_t{LWIP_TCP_RECV, client};
   if (!e) {
-    log_e("Failed to allocate event packet");
+    async_tcp_log_e("Failed to allocate event packet");
     return ERR_MEM;
   }
   if (pb) {
@@ -470,7 +472,7 @@ int8_t AsyncTCP_detail::tcp_sent(void *arg, struct tcp_pcb *pcb, uint16_t len) {
   AsyncClient *client = reinterpret_cast<AsyncClient *>(arg);
   lwip_tcp_event_packet_t *e = new (std::nothrow) lwip_tcp_event_packet_t{LWIP_TCP_SENT, client};
   if (!e) {
-    log_e("Failed to allocate event packet");
+    async_tcp_log_e("Failed to allocate event packet");
     return ERR_MEM;
   }
   e->sent.pcb = pcb;
@@ -493,7 +495,7 @@ void AsyncTCP_detail::tcp_error(void *arg, int8_t err) {
   // enqueue event to be processed in the async task for the user callback
   lwip_tcp_event_packet_t *e = new (std::nothrow) lwip_tcp_event_packet_t{LWIP_TCP_ERROR, client};
   if (!e) {
-    log_e("Failed to allocate event packet");
+    async_tcp_log_e("Failed to allocate event packet");
     return;
   }
   e->error.err = err;
@@ -508,7 +510,7 @@ static void _tcp_dns_found(const char *name, ip_addr_t *ipaddr, void *arg) {
 
   lwip_tcp_event_packet_t *e = new (std::nothrow) lwip_tcp_event_packet_t{LWIP_TCP_DNS, client};
   if (!e) {
-    log_e("Failed to allocate event packet");
+    async_tcp_log_e("Failed to allocate event packet");
     return;
   }
 
@@ -819,11 +821,11 @@ void AsyncClient::onPoll(AcConnectHandler cb, void *arg) {
 
 bool AsyncClient::connect(ip_addr_t addr, uint16_t port) {
   if (_pcb) {
-    log_d("already connected, state %d", _pcb->state);
+    async_tcp_log_d("already connected, state %d", _pcb->state);
     return false;
   }
   if (!_start_async_task()) {
-    log_e("failed to start task");
+    async_tcp_log_e("failed to start task");
     return false;
   }
 
@@ -836,7 +838,7 @@ bool AsyncClient::connect(ip_addr_t addr, uint16_t port) {
     pcb = tcp_new_ip_type(IPADDR_TYPE_V4);
 #endif
     if (!pcb) {
-      log_e("pcb == NULL");
+      async_tcp_log_e("pcb == NULL");
       return false;
     }
     _bind_tcp_callbacks(pcb, this);
@@ -878,7 +880,7 @@ bool AsyncClient::connect(const char *host, uint16_t port) {
   ip_addr_t addr;
 
   if (!_start_async_task()) {
-    log_e("failed to start task");
+    async_tcp_log_e("failed to start task");
     return false;
   }
 
@@ -905,7 +907,7 @@ bool AsyncClient::connect(const char *host, uint16_t port) {
     _connect_port = port;
     return true;
   }
-  log_d("error: %d", err);
+  async_tcp_log_d("error: %d", err);
   return false;
 }
 
@@ -1018,7 +1020,7 @@ void AsyncClient::_error(int8_t err) {
 // In LwIP Thread
 int8_t AsyncClient::_lwip_fin(tcp_pcb *pcb, int8_t err) {
   if (!_pcb || pcb != _pcb) {
-    log_d("0x%08" PRIx32 " != 0x%08" PRIx32, (uint32_t)pcb, (uint32_t)_pcb);
+    async_tcp_log_d("0x%08" PRIx32 " != 0x%08" PRIx32, (uint32_t)pcb, (uint32_t)_pcb);
     return ERR_OK;
   }
   _reset_tcp_callbacks(_pcb, this);
@@ -1072,11 +1074,11 @@ int8_t AsyncClient::_recv(tcp_pcb *pcb, pbuf *pb, int8_t err) {
 
 int8_t AsyncClient::_poll(tcp_pcb *pcb) {
   if (!_pcb) {
-    // log_d("pcb is NULL");
+    // async_tcp_log_d("pcb is NULL");
     return ERR_OK;
   }
   if (pcb != _pcb) {
-    log_d("0x%08" PRIx32 " != 0x%08" PRIx32, (uint32_t)pcb, (uint32_t)_pcb);
+    async_tcp_log_d("0x%08" PRIx32 " != 0x%08" PRIx32, (uint32_t)pcb, (uint32_t)_pcb);
     return ERR_OK;
   }
 
@@ -1087,7 +1089,7 @@ int8_t AsyncClient::_poll(tcp_pcb *pcb) {
     const uint32_t one_day = 86400000;
     bool last_tx_is_after_last_ack = (_rx_last_ack - _tx_last_packet + one_day) < one_day;
     if (last_tx_is_after_last_ack && (now - _tx_last_packet) >= _ack_timeout) {
-      log_d("ack timeout %d", pcb->state);
+      async_tcp_log_d("ack timeout %d", pcb->state);
       if (_timeout_cb) {
         _timeout_cb(_timeout_cb_arg, this, (now - _tx_last_packet));
       }
@@ -1096,7 +1098,7 @@ int8_t AsyncClient::_poll(tcp_pcb *pcb) {
   }
   // RX Timeout
   if (_rx_timeout && (now - _rx_last_packet) >= (_rx_timeout * 1000)) {
-    log_d("rx timeout %d", pcb->state);
+    async_tcp_log_d("rx timeout %d", pcb->state);
     _close();
     return ERR_OK;
   }
@@ -1485,7 +1487,7 @@ void AsyncServer::begin() {
   }
 
   if (!_start_async_task()) {
-    log_e("failed to start task");
+    async_tcp_log_e("failed to start task");
     return;
   }
   int8_t err;
@@ -1498,22 +1500,22 @@ void AsyncServer::begin() {
 #endif
   }
   if (!_pcb) {
-    log_e("_pcb == NULL");
+    async_tcp_log_e("_pcb == NULL");
     return;
   }
 
   err = _tcp_bind(&_pcb, &_addr, _port);
 
   if (err != ERR_OK) {
     // pcb was closed by _tcp_bind
-    log_e("bind error: %d", err);
+    async_tcp_log_e("bind error: %d", err);
     return;
   }
 
   static uint8_t backlog = 5;
   _pcb = _tcp_listen_with_backlog(_pcb, backlog);
   if (!_pcb) {
-    log_e("listen_pcb == NULL");
+    async_tcp_log_e("listen_pcb == NULL");
     return;
   }
   tcp_core_guard tcg;
@@ -1536,7 +1538,7 @@ void AsyncServer::end() {
 // runs on LwIP thread
 int8_t AsyncTCP_detail::tcp_accept(void *arg, tcp_pcb *pcb, int8_t err) {
   if (!pcb) {
-    log_e("_accept failed: pcb is NULL");
+    async_tcp_log_e("_accept failed: pcb is NULL");
     return ERR_ABRT;
   }
   auto server = reinterpret_cast<AsyncServer *>(arg);
@@ -1558,20 +1560,20 @@ int8_t AsyncTCP_detail::tcp_accept(void *arg, tcp_pcb *pcb, int8_t err) {
       // We can't let the client object call in to close, as we're on the LWIP thread; it could deadlock trying to RPC to itself
       c->_pcb = nullptr;
       tcp_abort(pcb);
-      log_e("_accept failed: couldn't accept client");
+      async_tcp_log_e("_accept failed: couldn't accept client");
       return ERR_ABRT;
     }
     if (c) {
       // Couldn't complete setup
       // pcb has already been aborted
       delete c;
       pcb = nullptr;
-      log_e("_accept failed: couldn't complete setup");
+      async_tcp_log_e("_accept failed: couldn't complete setup");
       return ERR_ABRT;
     }
-    log_e("_accept failed: couldn't allocate client");
+    async_tcp_log_e("_accept failed: couldn't allocate client");
   } else {
-    log_e("_accept failed: no onConnect callback");
+    async_tcp_log_e("_accept failed: no onConnect callback");
   }
   tcp_abort(pcb);
   return ERR_OK;

src/AsyncTCP.h

@@ -7,10 +7,6 @@
 #include "AsyncTCPVersion.h"
 #define ASYNCTCP_FORK_ESP32Async
 
-#ifndef LIBRETINY
-#include <esp_idf_version.h>
-#endif
-
 #ifdef ARDUINO
 #include "IPAddress.h"
 #if __has_include(<IPv6Address.h>)

src/AsyncTCPLogging.h

@@ -0,0 +1,49 @@
+// SPDX-License-Identifier: LGPL-3.0-or-later
+// Copyright 2016-2025 Hristo Gochkov, Mathieu Carbou, Emil Muratov
+
+#pragma once
+
+#ifdef CONFIG_ASYNC_TCP_LOG_CUSTOM
+
+// The user is responsible to provide the right macros
+#include <AsyncTCPLoggingCustom.h>
+
+#else  // CONFIG_ASYNC_TCP_LOG_CUSTOM
+
+/**
+ * LibreTiny specific configurations
+ */
+#if defined(LIBRETINY)
+#include <Arduino.h>
+#define async_tcp_log_e(...) log_e(__VA_ARGS__)
+#define async_tcp_log_w(...) log_w(__VA_ARGS__)
+#define async_tcp_log_i(...) log_i(__VA_ARGS__)
+#define async_tcp_log_d(...) log_d(__VA_ARGS__)
+#define async_tcp_log_v(...) log_v(__VA_ARGS__)
+#endif  // LIBRETINY
+
+/**
+ * Arduino specific configurations
+ */
+#if defined(ARDUINO) && !defined(LIBRETINY)
+#include <esp32-hal-log.h>
+#define async_tcp_log_e(...) log_e(__VA_ARGS__)
+#define async_tcp_log_w(...) log_w(__VA_ARGS__)
+#define async_tcp_log_i(...) log_i(__VA_ARGS__)
+#define async_tcp_log_d(...) log_d(__VA_ARGS__)
+#define async_tcp_log_v(...) log_v(__VA_ARGS__)
+#endif  // ARDUINO
+
+/**
+ * ESP-IDF specific configurations
+ */
+#if !defined(LIBRETINY) && !defined(ARDUINO)
+#include <esp_log.h>
+#define async_tcp_log_e(...) ESP_LOGE("async_tcp", __VA_ARGS__)
+#define async_tcp_log_w(...) ESP_LOGW("async_tcp", __VA_ARGS__)
+#define async_tcp_log_i(...) ESP_LOGI("async_tcp", __VA_ARGS__)
+#define async_tcp_log_d(...) ESP_LOGD("async_tcp", __VA_ARGS__)
+#define async_tcp_log_v(...) ESP_LOGV("async_tcp", __VA_ARGS__)
+#endif  // !LIBRETINY && !ARDUINO
+
+#endif  // CONFIG_ASYNC_TCP_LOG_CUSTOM