Skip to content

Commit 0d71d14

Browse files
krish2718nordicjm
authored andcommitted
[nrf noup] logging: Add ratelimited variants
These are helpful for logging in data-path, not to overwhelm the console but still keep the user informed about the issues. This is similar to printk_ratelimited in Linux kernel. Add only basic build tests for now. Upstream PR #: 93536 [To avoid release notes churn, marking as noup] Signed-off-by: Chaitanya Tata <[email protected]>
1 parent b0331c4 commit 0d71d14

File tree

7 files changed

+636
-0
lines changed

7 files changed

+636
-0
lines changed

doc/services/logging/index.rst

Lines changed: 99 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -32,6 +32,7 @@ Summary of the logging features:
3232
- Support for logging floating point variables and long long arguments.
3333
- Built-in copying of transient strings used as arguments.
3434
- Support for multi-domain logging.
35+
- Rate-limited logging macros to prevent log flooding when messages are generated frequently.
3536

3637
Logging API is highly configurable at compile time as well as at run time. Using
3738
Kconfig options (see :ref:`logging_kconfig`) logs can be gradually removed from
@@ -59,6 +60,16 @@ The warning level also exposes the following additional macro:
5960

6061
- :c:macro:`LOG_WRN_ONCE` for warnings where only the first occurrence is of interest.
6162

63+
Rate-limited logging macros are also available for all severity levels to prevent log flooding:
64+
65+
- ``LOG_X_RATELIMIT`` for rate-limited standard printf-like messages using default rate, e.g. :c:macro:`LOG_ERR_RATELIMIT`.
66+
- ``LOG_X_RATELIMIT_RATE`` for rate-limited standard printf-like messages with custom rate, e.g. :c:macro:`LOG_ERR_RATELIMIT_RATE`.
67+
- ``LOG_HEXDUMP_X_RATELIMIT`` for rate-limited data dumping using default rate, e.g. :c:macro:`LOG_HEXDUMP_WRN_RATELIMIT`.
68+
- ``LOG_HEXDUMP_X_RATELIMIT_RATE`` for rate-limited data dumping with custom rate, e.g. :c:macro:`LOG_HEXDUMP_WRN_RATELIMIT_RATE`.
69+
70+
The convenience macros use the default rate specified by ``CONFIG_LOG_RATELIMIT_INTERVAL_MS``,
71+
while the explicit rate macros take a rate parameter (in milliseconds) that specifies the minimum interval between log messages.
72+
6273
There are two configuration categories: configurations per module and global
6374
configuration. When logging is enabled globally, it works for modules. However,
6475
modules can disable logging locally. Every module can specify its own logging
@@ -341,6 +352,94 @@ If logs are processed from a thread (user or internal) then it is possible to en
341352
a feature which will wake up processing thread when certain amount of log messages are
342353
buffered (see :kconfig:option:`CONFIG_LOG_PROCESS_TRIGGER_THRESHOLD`).
343354

355+
.. _logging_ratelimited:
356+
357+
Rate-limited logging
358+
********************
359+
360+
Rate-limited logging macros provide a way to prevent log flooding when messages are
361+
generated frequently. These macros ensure that log messages are not output more
362+
frequently than a specified interval, similar to Linux's ``printk_ratelimited``
363+
functionality.
364+
365+
The rate-limited logging system provides two types of macros:
366+
367+
**Convenience macros (using default rate):**
368+
- :c:macro:`LOG_ERR_RATELIMIT` - Rate-limited error messages
369+
- :c:macro:`LOG_WRN_RATELIMIT` - Rate-limited warning messages
370+
- :c:macro:`LOG_INF_RATELIMIT` - Rate-limited info messages
371+
- :c:macro:`LOG_DBG_RATELIMIT` - Rate-limited debug messages
372+
- :c:macro:`LOG_HEXDUMP_ERR_RATELIMIT` - Rate-limited error hexdump
373+
- :c:macro:`LOG_HEXDUMP_WRN_RATELIMIT` - Rate-limited warning hexdump
374+
- :c:macro:`LOG_HEXDUMP_INF_RATELIMIT` - Rate-limited info hexdump
375+
- :c:macro:`LOG_HEXDUMP_DBG_RATELIMIT` - Rate-limited debug hexdump
376+
377+
**Explicit rate macros (with custom rate):**
378+
- :c:macro:`LOG_ERR_RATELIMIT_RATE` - Rate-limited error messages with custom rate
379+
- :c:macro:`LOG_WRN_RATELIMIT_RATE` - Rate-limited warning messages with custom rate
380+
- :c:macro:`LOG_INF_RATELIMIT_RATE` - Rate-limited info messages with custom rate
381+
- :c:macro:`LOG_DBG_RATELIMIT_RATE` - Rate-limited debug messages with custom rate
382+
- :c:macro:`LOG_HEXDUMP_ERR_RATELIMIT_RATE` - Rate-limited error hexdump with custom rate
383+
- :c:macro:`LOG_HEXDUMP_WRN_RATELIMIT_RATE` - Rate-limited warning hexdump with custom rate
384+
- :c:macro:`LOG_HEXDUMP_INF_RATELIMIT_RATE` - Rate-limited info hexdump with custom rate
385+
- :c:macro:`LOG_HEXDUMP_DBG_RATELIMIT_RATE` - Rate-limited debug hexdump with custom rate
386+
387+
The convenience macros use the default rate specified by :kconfig:option:`CONFIG_LOG_RATELIMIT_INTERVAL_MS`
388+
(5000ms by default). The explicit rate macros take a rate parameter (in milliseconds) that specifies
389+
the minimum interval between log messages. The rate limiting is per-macro-call-site, meaning
390+
that each unique call to a rate-limited macro has its own independent rate limit.
391+
392+
Example usage:
393+
394+
.. code-block:: c
395+
396+
#include <zephyr/logging/log.h>
397+
#include <zephyr/kernel.h>
398+
399+
LOG_MODULE_REGISTER(my_module, CONFIG_LOG_DEFAULT_LEVEL);
400+
401+
void process_data(void)
402+
{
403+
/* Convenience macros using default rate (CONFIG_LOG_RATELIMIT_INTERVAL_MS) */
404+
LOG_WRN_RATELIMIT("Data processing warning: %d", error_code);
405+
LOG_ERR_RATELIMIT("Critical error occurred: %s", error_msg);
406+
LOG_INF_RATELIMIT("Processing status: %d items", item_count);
407+
LOG_HEXDUMP_WRN_RATELIMIT(data_buffer, data_len, "Data buffer:");
408+
409+
/* Explicit rate macros with custom intervals */
410+
LOG_WRN_RATELIMIT_RATE(1000, "Fast rate warning: %d", error_code);
411+
LOG_ERR_RATELIMIT_RATE(30000, "Slow rate error: %s", error_msg);
412+
LOG_INF_RATELIMIT_RATE(2000, "Custom rate status: %d items", item_count);
413+
LOG_HEXDUMP_ERR_RATELIMIT_RATE(5000, data_buffer, data_len, "Error data:");
414+
}
415+
416+
Rate-limited logging is particularly useful for:
417+
418+
- Error conditions that might occur frequently but don't need to flood the logs
419+
- Status updates in tight loops or high-frequency callbacks
420+
- Debug information that could overwhelm the logging system
421+
- Network or I/O operations that might fail repeatedly
422+
423+
Configuration
424+
==============
425+
426+
Rate-limited logging can be configured using the following Kconfig options:
427+
428+
- :kconfig:option:`CONFIG_LOG_RATELIMIT` - Master switch to enable/disable rate-limited logging
429+
- :kconfig:option:`CONFIG_LOG_RATELIMIT_INTERVAL_MS` - Default interval for convenience macros (5000ms)
430+
431+
When :kconfig:option:`CONFIG_LOG_RATELIMIT` is disabled, the behavior of rate-limited macros is controlled
432+
by the :kconfig:option:`CONFIG_LOG_RATELIMIT_FALLBACK` choice:
433+
434+
- :kconfig:option:`CONFIG_LOG_RATELIMIT_FALLBACK_LOG` - All rate-limited macros behave as regular logging macros
435+
- :kconfig:option:`CONFIG_LOG_RATELIMIT_FALLBACK_DROP` - All rate-limited macros expand to no-ops (default)
436+
437+
This allows you to control whether rate-limited log macros should always print or be completely
438+
suppressed when rate limiting is not available.
439+
440+
The rate limiting is implemented using static variables and :c:func:`k_uptime_get_32`
441+
to track the last log time for each call site.
442+
344443
.. _logging_panic:
345444

346445
Logging panic

0 commit comments

Comments
 (0)