esp-idf/components/log
Jeff H 628b633e50 log: Add master log option
Closes https://github.com/espressif/esp-idf/issues/11049
Closes https://github.com/espressif/esp-idf/pull/11057

Signed-off-by: KonstantinKondrashov <konstantin@espressif.com>

Result from an example in 11057:
When this option is not enabled:
1000 iterations took 10914 microseconds (10.9 microseconds per invocation)
1000 iterations took 10909 microseconds (10.9 microseconds per invocation)

When this option is enabled:
1000 iterations took 10960 microseconds (10.9 microseconds per invocation)
1000 iterations took 107 microseconds (0.1 microseconds per invocation)
2023-05-18 18:35:19 +08:00
..
host_test/log_test Merge branch 'bugfix/linux_target_gen_partition_table' into 'master' 2023-01-18 11:57:08 +08:00
include log: Add master log option 2023-05-18 18:35:19 +08:00
test_apps log: Add master log option 2023-05-18 18:35:19 +08:00
.build-test-rules.yml log: Add master log option 2023-05-18 18:35:19 +08:00
CMakeLists.txt log: support ESP_LOG_BUFFER* functions for Linux target 2022-04-11 13:29:01 +02:00
esp_log_private.h log: refactoring to make compatible with no-FreeRTOS builds 2019-11-22 11:41:35 +01:00
Kconfig log: Add master log option 2023-05-18 18:35:19 +08:00
linker.lf log: refactoring to make compatible with no-FreeRTOS builds 2019-11-22 11:41:35 +01:00
log_buffers.c log: support ESP_LOG_BUFFER* functions for Linux target 2022-04-11 13:29:01 +02:00
log_freertos.c hal: Deprecate interrupt_controller_hal.h, cpu_hal.h and cpu_ll.h interfaces 2022-07-22 00:06:06 +08:00
log_linux.c [esp_rom]: Partially buildable for linux 2021-08-03 12:03:24 +08:00
log_noos.c log: Fix function name in OS-independent implementation 2023-03-16 01:50:21 +08:00
log.c log: Add master log option 2023-05-18 18:35:19 +08:00
README.rst log: Add master log option 2023-05-18 18:35:19 +08:00

Logging library
===============

Overview
--------

The logging library provides three ways for setting log verbosity:

- **At compile time**: in menuconfig, set the verbosity level using the option :ref:`CONFIG_LOG_DEFAULT_LEVEL`.
- Optionally, also in menuconfig, set the maximum verbosity level using the option :ref:`CONFIG_LOG_MAXIMUM_LEVEL`. By default, this is the same as the default level, but it can be set higher in order to compile more optional logs into the firmware.
- **At runtime**: all logs for verbosity levels lower than :ref:`CONFIG_LOG_DEFAULT_LEVEL` are enabled by default. The function :cpp:func:`esp_log_level_set` can be used to set a logging level on a per-module basis. Modules are identified by their tags, which are human-readable ASCII zero-terminated strings.
- **At runtime**: if :ref:`CONFIG_LOG_MASTER_LEVEL` is enabled then a ``Master logging level`` can be set using :cpp:func:`esp_log_set_level_master`. This option adds an additional logging level check for all compiled logs. Note that this will increase application size. This feature is useful if you want to compile in a lot of logs that are selectable at runtime, but also want to avoid the performance hit from looking up the tags and their log level when you don't want log output.

There are the following verbosity levels:

- Error (lowest)
- Warning
- Info
- Debug
- Verbose (highest)

.. note::

    The function :cpp:func:`esp_log_level_set` cannot set logging levels higher than specified by :ref:`CONFIG_LOG_MAXIMUM_LEVEL`. To increase log level for a specific file above this maximum at compile time, use the macro `LOG_LOCAL_LEVEL` (see the details below).


How to use this library
-----------------------

In each C file that uses logging functionality, define the TAG variable as shown below:

.. code-block:: c

   static const char* TAG = "MyModule";

Then use one of logging macros to produce output, e.g:

.. code-block:: c

   ESP_LOGW(TAG, "Baud rate error %.1f%%. Requested: %d baud, actual: %d baud", error * 100, baud_req, baud_real);

Several macros are available for different verbosity levels:

* ``ESP_LOGE`` - error (lowest)
* ``ESP_LOGW`` - warning
* ``ESP_LOGI`` - info
* ``ESP_LOGD`` - debug
* ``ESP_LOGV`` - verbose (highest)

Additionally, there are ``ESP_EARLY_LOGx`` versions for each of these macros, e.g. :c:macro:`ESP_EARLY_LOGE`. These versions have to be used explicitly in the early startup code only, before heap allocator and syscalls have been initialized. Normal ``ESP_LOGx`` macros can also be used while compiling the bootloader, but they will fall back to the same implementation as ``ESP_EARLY_LOGx`` macros.

There are also ``ESP_DRAM_LOGx`` versions for each of these macros, e.g. :c:macro:`ESP_DRAM_LOGE`. These versions are used in some places where logging may occur with interrupts disabled or with flash cache inaccessible. Use of this macros should be as sparing as possible, as logging in these types of code should be avoided for performance reasons.

.. note::

   Inside critical sections interrupts are disabled so it's only possible to use ``ESP_DRAM_LOGx`` (preferred) or ``ESP_EARLY_LOGx``. Even though it's possible to log in these situations, it's better if your program can be structured not to require it.

To override default verbosity level at file or component scope, define the ``LOG_LOCAL_LEVEL`` macro.

At file scope, define it before including ``esp_log.h``, e.g.:

.. code-block:: c

   #define LOG_LOCAL_LEVEL ESP_LOG_VERBOSE
   #include "esp_log.h"

At component scope, define it in the component CMakeLists:

.. code-block:: cmake

   target_compile_definitions(${COMPONENT_LIB} PUBLIC "-DLOG_LOCAL_LEVEL=ESP_LOG_VERBOSE")

To configure logging output per module at runtime, add calls to the function :cpp:func:`esp_log_level_set` as follows:

.. code-block:: c

   esp_log_level_set("*", ESP_LOG_ERROR);        // set all components to ERROR level
   esp_log_level_set("wifi", ESP_LOG_WARN);      // enable WARN logs from WiFi stack
   esp_log_level_set("dhcpc", ESP_LOG_INFO);     // enable INFO logs from DHCP client

.. note::

   The "DRAM" and "EARLY" log macro variants documented above do not support per module setting of log verbosity. These macros will always log at the "default" verbosity level, which can only be changed at runtime by calling ``esp_log_level("*", level)``.

Even when logs are disabled by using a tag name they will still require a processing time of around 10.9 microseconds per entry.

Master Logging Level
^^^^^^^^^^^^^^^^^^^^

To enable the Master logging level feature, the :ref:`CONFIG_LOG_MASTER_LEVEL` option must be enabled. It adds an additional level check for ``ESP_LOGx`` macros before calling :cpp:func:`esp_log_write`. This allows to set a higher :ref:`CONFIG_LOG_MAXIMUM_LEVEL`, but not inflict a performance hit during normal operation (only when directed). An application may set the master logging level (:cpp:func:`esp_log_set_level_master`) globally to enforce a maximum log level. ``ESP_LOGx`` macros above this level will be skipped immediately, rather than calling :cpp:func:`esp_log_write` and doing a tag lookup. It is recommended to only use this in an top-level application and not in shared components as this would override the global log level for any user using the component. By default, at startup, the Master logging level is :ref:`CONFIG_LOG_DEFAULT_LEVEL`.

Note that this feature increases application size because the additional check is added into all ``ESP_LOGx`` macros.

The snippet below shows how it works. Setting the Master logging level to ``ESP_LOG_NONE`` disables all logging globally. :cpp:func:`esp_log_level_set` does not currently affect logging. But after the Master logging level is released, the logs will be printed as set by :cpp:func:`esp_log_level_set`.

.. code-block:: c

   // Master logging level is CONFIG_LOG_DEFAULT_LEVEL at start up and = ESP_LOG_INFO
   ESP_LOGI("lib_name", "Message for print");          // prints a INFO message
   esp_log_level_set("lib_name", ESP_LOG_WARN);        // enables WARN logs from lib_name

   esp_log_set_level_master(ESP_LOG_NONE);             // disables all logs globally. esp_log_level_set has no effect at the moment.

   ESP_LOGW("lib_name", "Message for print");          // no print, Master logging level blocks it
   esp_log_level_set("lib_name", ESP_LOG_INFO);        // enable INFO logs from lib_name
   ESP_LOGI("lib_name", "Message for print");          // no print, Master logging level blocks it

   esp_log_set_level_master(ESP_LOG_INFO);             // enables all INFO logs globally.

   ESP_LOGI("lib_name", "Message for print");          // prints a INFO message

Logging to Host via JTAG
^^^^^^^^^^^^^^^^^^^^^^^^

By default, the logging library uses the vprintf-like function to write formatted output to the dedicated UART. By calling a simple API, all log output may be routed to JTAG instead, making logging several times faster. For details, please refer to Section :ref:`app_trace-logging-to-host`.

Thread Safety
^^^^^^^^^^^^^

The log string is first written into a memory buffer and then sent to the UART for printing. Log calls are thread-safe, i.e., logs of different threads do not conflict with each other.