Logging refactoring to supports macros redefinition and -D USE_ESP_IDF_LOG

[mathieucarbou]

This PR refactors the logging layer of async_tcp to give more flexibility.

By default, the lib internally uses these variants for logging:

• async_tcp_log_e
• async_tcp_log_w
• async_tcp_log_i
• async_tcp_log_d
• async_tcp_log_v (for dev traces)

Each call is by forwarded to the framework under the hood: log_x for Arduino and Libretiny, ESP_LOGx for ESP-IDF, or when using Arduino with -D USE_ESP_IDF_LOG

If the flag -D CONFIG_ASYNC_TCP_DEBUG is set, the library switches in DEBUG mode and all the logs, regardless of their level, are sent to Serial output.

If the flag -D CONFIG_ASYNC_TCP_LOG_CUSTOM is set, the user can provide in his project AsyncTCPLoggingCustom.h header and has the ability to then define the macros / function like he wants.

The library will now support -D USE_ESP_IDF_LOG and has its own tag: async_tcp, to use esp_log_level_set("async_tcp", ESP_LOG_INFO);

[willmmiles]

From a design standpoint, I'd caution against replicating all the different log levels provided by ESP-IDF. I don't think the logging requirements of this particular library need that much depth; and carrying around a bunch of unused functions is asking for bit-rot unless there's some testing or validation suite, which seems like overkill in this case.

Instead I'd suggest providing log functions that fit the use cases in this library:

• error tracing (usally log_e, the one log_w could be included here, and probably a couple of the log_ds should probably be moved here)
• full tracing (usually // ets_printf() currently); I think it would be better to make these properly supported logs than leave commented out lines
• miscellaneous internal debugging (usually log_d)

..and then switch on some #define ASYNC_TCP_LOG (ASYNC_TCP_LOG_ERROR | ASYNC_TCP_LOG_TRACE | ASYNC_TCP_LOG_DEBUG) to enable the required outputs.

So maybe we want only:
async_tcp_log_error - enabled if (ASYNC_TCP_LOG & ASYNC_TCP_LOG_ERROR)
async_tcp_log_trace - enabled if (ASYNC_TCP_LOG & ASYNC_TCP_LOG_TRACE )
async_tcp_log_debug - enabled if (ASYNC_TCP_LOG & ASYNC_TCP_LOG_DEBUG)
?

[me-no-dev]

can AsyncTCP compile without Arduino?

[mathieucarbou]

yes it can now. there has been a recent PR and even an example in the project that you have reviewed. The dependency to Arduino is now gone.

[mathieucarbou]

but I still see that:

espressif/arduino-esp32:
    version: ">=3.2.0"
    require: public

[mathieucarbou]

@me-no-dev : found the PR: #48

[mathieucarbou]

maybe this pr's title is misleading and should be - without arduino BUT with arduino as component maybe ?

[mathieucarbou]

So maybe we want only:
async_tcp_log_error - enabled if (ASYNC_TCP_LOG & ASYNC_TCP_LOG_ERROR)
async_tcp_log_trace - enabled if (ASYNC_TCP_LOG & ASYNC_TCP_LOG_TRACE )
async_tcp_log_debug - enabled if (ASYNC_TCP_LOG & ASYNC_TCP_LOG_DEBUG)

We need also to support USE_ESP_IDF_LOG and Libretiny,... So at the end any the solution quite leads to the same amount of code I think. Right now, all cases are isolated in 1 file and what I did is only a refactoring to isolate the redirections that wre already there:

• on libretiny: log_x were used
• on arduino: log_x were used
• on esp_idf: log_x redirects to ESP_LOG so I am now using directly ESP_LOGx
• on arduino with USE_ESP_IDF_LOG, I am using directly ESP_LOG with appropriate tag, which will help compatibility with projects using USE_ESP_IDF_LOG with dynamic logging for arduino.

In any case there is nothing more or less than we had except the some mapping macros, which would be empty anyway depending on the compilation flags

also warning is good to have. if we do not support it now it can break backward compatibility when will need to use it.
But if we add it now, in most cases it will lead to a blank macro by default, and will allow usage in the future.

i removed verbose though. I agree this one is not needed. kept them for traces (see last update)

[willmmiles]

So maybe we want only:
async_tcp_log_error - enabled if (ASYNC_TCP_LOG & ASYNC_TCP_LOG_ERROR)
async_tcp_log_trace - enabled if (ASYNC_TCP_LOG & ASYNC_TCP_LOG_TRACE )
async_tcp_log_debug - enabled if (ASYNC_TCP_LOG & ASYNC_TCP_LOG_DEBUG)

We need also to support USE_ESP_IDF_LOG and Libretiny,... So at the end any the solution quite leads to the same amount of code I think. Right now, all cases are isolated in 1 file and what I did is only a refactoring to isolate the redirections that wre already there:

Right, I understand that you've done the minimal possible port of the logs in the current code. I appreciate that you've added CONFIG_ASYNC_TCP_DEBUG to support my use case better. It still feels to me a bit like we're trying to cram our square logging peg into a round ESP-IDF logger-shaped hole, but I'm happy enough to put that in the bikeshed and move on.

---

Elsewhere on the API design front: the only other thing that comes to mind is maybe to spec an async_tcp_init_log() hook, called in _start_async_task(). Hooks to regular platform logs could leave this empty, but it could be quite valuable for custom integration (allocating a ring buffer, opening a file, or calling esp_log_level_set("async_tcp", ESP_LOG_VERBOSE)). What do you think?

[mathieucarbou]

Elsewhere on the API design front: the only other thing that comes to mind is maybe to spec an async_tcp_init_log() hook, called in _start_async_task(). Hooks to regular platform logs could leave this empty, but it could be quite valuable for custom integration (allocating a ring buffer, opening a file, or calling esp_log_level_set("async_tcp", ESP_LOG_VERBOSE)). What do you think?

_start_async_task is the consequence of a user action (i.e. call to connect or begin). So the user should be able to control his own code to init what's needed before any call to async_tcp (or a using lib) is done, right ?

[willmmiles]

Elsewhere on the API design front: the only other thing that comes to mind is maybe to spec an async_tcp_init_log() hook, called in _start_async_task(). Hooks to regular platform logs could leave this empty, but it could be quite valuable for custom integration (allocating a ring buffer, opening a file, or calling esp_log_level_set("async_tcp", ESP_LOG_VERBOSE)). What do you think?

_start_async_task is the consequence of a user action (i.e. call to connect or begin). So the user should be able to control his own code to init what's needed before any call to async_tcp (or a using lib) is done, right ?

Alas, in C++ we have to deal with static construction order indeterminacy -- someone might declare an AsyncClient object as a member of some global object, at which point there's no guarantee as to what order the constructors might be run in. There are various solutions to guard one's own code against this, but they all boil down to "add a check if the initialization has been run in every code path where it matters" ... just like we already do in _start_async_task.

(To be fair, I haven't tested if static AsyncClients could even work -- I rather suspect they'll run afoul of LwIP itself not being fully initialized.)

It seemed to me like an init hook would be useful as way to allow custom log solutions to be more self contained, without potentially having to replicate the init check on every log call, or add explicit integration somewhere else in the user's code (ie. include this header, get more logs -- as opposed to include this header, and also add this call to your setup()). That said, if you're not confident that it's worthwhile today, such a feature could potentially be added later if someone needed it. Thanks for taking the time to consider it.

[mathieucarbou]

Elsewhere on the API design front: the only other thing that comes to mind is maybe to spec an async_tcp_init_log() hook, called in _start_async_task(). Hooks to regular platform logs could leave this empty, but it could be quite valuable for custom integration (allocating a ring buffer, opening a file, or calling esp_log_level_set("async_tcp", ESP_LOG_VERBOSE)). What do you think?

_start_async_task is the consequence of a user action (i.e. call to connect or begin). So the user should be able to control his own code to init what's needed before any call to async_tcp (or a using lib) is done, right ?

Alas, in C++ we have to deal with static construction order indeterminacy -- someone might declare an AsyncClient object as a member of some global object, at which point there's no guarantee as to what order the constructors might be run in. There are various solutions to guard one's own code against this, but they all boil down to "add a check if the initialization has been run in every code path where it matters" ... just like we already do in _start_async_task.

(To be fair, I haven't tested if static AsyncClients could even work -- I rather suspect they'll run afoul of LwIP itself not being fully initialized.)

It seemed to me like an init hook would be useful as way to allow custom log solutions to be more self contained, without potentially having to replicate the init check on every log call, or add explicit integration somewhere else in the user's code (ie. include this header, get more logs -- as opposed to include this header, and also add this call to your setup()). That said, if you're not confident that it's worthwhile today, such a feature could potentially be added later if someone needed it. Thanks for taking the time to consider it.

But in this case, why call it from _start_async_task ? _start_async_task can only be called from connect or begin and those 2 are more likely to not be called during static initialization because anyway there won't be any network layer ready to begin with (eth or wifi).

I would understand if we had to call init from this static method if _start_async_task was called from a constructor, which would be likely to be statically called, yes, but I do not understand in which use case we would need this trick in AsyncTCP at the moment ?

Especially that _start_async_task is called from begin or connect... So this is far away... There could be some log lines called (from ctor or from some validation methods) even before _start_async_task is called, so even before the init hook is called.