Commit Graph

28 Commits

Author SHA1 Message Date
Michael Scott
6575e84002 logging: start log processing thread in enable_logger()
Currently, if CONFIG_LOG_PROCESS_THREAD is enabled, log processing
does not start until just before the main() function is called in
the user sample.  This means that no real-time logging information
will be sent to the backends while drivers and/or other processes
which are triggered during kernel boot are processing their tasks.
Worse, if they take a longish time to finish, the user is
presented with a blank log backend regardless of the debug levels.

Let's start processing logs earlier to avoid this issue.

NOTE: Since this thread is now triggered specifically rather than
started during static thread init, let's also name it.

Signed-off-by: Michael Scott <mike@foundries.io>
2018-11-07 14:39:55 +02:00
Krzysztof Chruscinski
4213dbb2e6 logging: add arguments counting in log_generic
Log_generic() can be used by external logger systems to map to zephyr
logger subsystem. Function has variable number of arguments. So far
logger assumed maximal number of arguments to avoid scanning
string to count number of arguments. In outcome, uninitialized memory
was treated as valid argument in a message (but discarded when actual
string formatting took place). Valgrind complained about that so
log_generic() has been extended to scan the string and count number
of arguments and build message with valid number of arguments.

Signed-off-by: Krzysztof Chruscinski <krzysztof.chruscinski@nordicsemi.no>
2018-10-31 14:32:21 +01:00
qianfan Zhao
02bd01e856 subsys: logging: Using struct to manger log_strdup buffer.
log_strdup requested for a piece of memory, with the first 4 bytes as
the number of references and the next used to copy strings. In the
implementation of this function, the memory is managed by user and
is a little hard to understand.

Rewriting this part of code, using structure to manage the memory
requested, make it easier to understand.

Signed-off-by: qianfan Zhao <qianfanguijin@163.com>
2018-10-29 09:46:01 -04:00
Johann Fischer
ce4be3af86 logging: fix out of bounds write in log_strdup
log_strdup writes out of bounds of a strdup slab.
e.g: CONFIG_LOG_STRDUP_MAX_STRING=46 and
     LOG_STRBUF_STR_SIZE=47 then in the line L:529
sdupl[LOG_STRBUF_STR_SIZE - 1] = '\0';
writes out of bounds because the available buffer space
is only 44 bytes (rounded up to 48 bytes and minus 4 bytes
for the allocated flag).

Signed-off-by: Johann Fischer <j.fischer@phytec.de>
2018-10-24 16:41:21 +01:00
Krzysztof Chruscinski
c696e68bb9 logging: Added support for 10 arguments in log message
Extended supported number of arguments in log message. Support for
messages consisting of more than 2 chunks had to be added. So far
messages could consist of one chunk (up to 3 args) or two chunks
(2 args in first chunk and 7 in second chunk). Once 2+ chunks
support is added number of arguments is techinically limited to
15 (4 bit field). log_core and log_output extended to suppor 10
arguments.

Signed-off-by: Krzysztof Chruscinski <krzysztof.chruscinski@nordicsemi.no>
2018-10-24 11:14:26 +01:00
Krzysztof Chruscinski
05b854c168 logging: Postpone log processing when no backends enabled
In initial state of the system it is possible that no backends are
yet enabled and log processing is triggered. In that case logs were
discarded. A flag has been added to the log core to do processing
only if at least one backend is enabled. It is applicable only to
initial phase. If backends are disabled in application lifetime
logs will be discarded.

Signed-off-by: Krzysztof Chruscinski <krzysztof.chruscinski@nordicsemi.no>
2018-10-11 13:29:50 +03:00
Krzysztof Chruscinski
5f6070e2f7 logging: Add autostart option to LOG_BACKEND_DEFINE
Extended macro to accept flag indicating if given backend must be
initialized and enabled when log subsystem starts. Typically, simple
backends will have autostart flag set. More complex may require
explicit enabling (e.g. shell over BLE can only be enabled when
BLE connection is established).

Signed-off-by: Krzysztof Chruscinski <krzysztof.chruscinski@nordicsemi.no>
2018-10-11 13:29:50 +03:00
Michael Scott
518444487c logging: init strdup mem_slab with aligned buffer size
We are using a non-32-bit aligned value as the block size
when initializing the strdup mem_slab for Logger.

When the non-aligned pointer is being freed, it's converted
to a u32_t and this generates the following:
***** USAGE FAULT *****
  Unaligned memory access

Let's use the aligned buffer size as the block size instead.

Signed-off-by: Michael Scott <mike@foundries.io>
2018-10-11 13:20:32 +03:00
Jukka Rissanen
65477b7391 logging: Make log_strdup() parameter const
The string parameter needs to be const as otherwise calling this
function using a const string pointer will lead to a warning.
Besides the function does not modify the parameter so should be
const anyway.

Signed-off-by: Jukka Rissanen <jukka.rissanen@linux.intel.com>
2018-10-03 13:05:49 +03:00
Krzysztof Chruscinski
a15438e8f5 logging: add mechanism for handling transient strings
Extending logger to support logging transient strings (with %s).
With dedicated call (log_strdup), string is duplicated to a buffer
from internal logger pool. Logger implicitly manages the pool.

Signed-off-by: Krzysztof Chruscinski <krzysztof.chruscinski@nordicsemi.no>
2018-10-01 15:26:14 -04:00
Krzysztof Chruscinski
87d177a6fb logging: allow mulitple log_panic calls
Ensure that only first log_panic() sends panic signal to backends

Signed-off-by: Krzysztof Chruscinski <krzysztof.chruscinski@nordicsemi.no>
2018-09-27 13:11:26 +05:30
Anas Nashif
1aed3858ac logging: rename log_process_thread to logging
Keep the name short to make usuable when thread names are enabled.

Signed-off-by: Anas Nashif <anas.nashif@intel.com>
2018-09-27 08:58:55 +05:30
Krzysztof Chruscinski
ba01a3952f logging: Add shell commands
Added commands for getting current status and controlling which log
messages are forwared to available backends.

Signed-off-by: Krzysztof Chruscinski <krzysztof.chruscinski@nordicsemi.no>
2018-09-19 09:30:29 -04:00
Andrei Emeltchenko
8fc5fd55de logger: Simplify UART backend initialization
Move definition to sources of UART backend.

Signed-off-by: Andrei Emeltchenko <andrei.emeltchenko@intel.com>
2018-09-18 14:56:10 +02:00
Andrei Emeltchenko
94bae6a462 logger: Move native_posix_backend definition
Move definition to appropriate place removing ugly defines.

Signed-off-by: Andrei Emeltchenko <andrei.emeltchenko@intel.com>
2018-09-18 14:56:10 +02:00
Andrei Emeltchenko
6162caf787 logger: Add init() api and simplify init and activate
Simplify logger initialization process using already existing loops.

Signed-off-by: Andrei Emeltchenko <andrei.emeltchenko@intel.com>
2018-09-18 14:56:10 +02:00
Alberto Escolar Piedras
f8b97ab70e subsys: logging: Fix for no CONFIG_LOG_PROCESS_THREAD
When CONFIG_LOG_PROCESS_THREAD was not set the logger
was not initialized.
Register a POST_KERNEL init for that case.

Also added an assert in the logger thread in case there
is no backends, instead of having that thread spinning
forever.

Signed-off-by: Alberto Escolar Piedras <alpi@oticon.com>
2018-09-18 14:56:10 +02:00
Andrei Emeltchenko
e65ee6870e logger: Add native backend for native_posix
Add backend to be used in native_posix arch.

Signed-off-by: Andrei Emeltchenko <andrei.emeltchenko@intel.com>
2018-09-18 14:56:10 +02:00
Krzysztof Chruscinski
3c63d05dfc logging: Add metadata to hexdump
Extended hexdump API with a raw string attached to the data.

Signed-off-by: Krzysztof Chruscinski <krzysztof.chruscinski@nordicsemi.no>
2018-08-14 07:14:34 -07:00
Krzysztof Chruscinski
c859e2a254 logging: Replace ifdefs with if
Replacing preprocessor with compiler in UART backend initialization.

Signed-off-by: Krzysztof Chruscinski <krzysztof.chruscinski@nordicsemi.no>
2018-08-13 13:20:27 -07:00
Marti Bolivar
55327a183d logging: fix runtime filtering initialization
The runtime filters (both aggregated and per-backend) are all getting
initialized to the default level CONFIG_LOG_DEFAULT_LEVEL. This is not
correct behavior: the initial runtime setting for each source ID
should match its compile-time level setting.

Otherwise, setting CONFIG_LOG_RUNTIME_FILTERING=y changes the logging
behavior for messages that pass the compile time filter check, but not
the runtime check (this currently happens when LOG_LEVEL=4, since
CONFIG_LOG_DEFAULT_LEVEL=3).

Fix this by initializing all filters to their module's compile time
settings. Also make sure that filters are set up before backends are
activated, to avoid race conditions.

Fix a stray documentation typo while we are here.

Signed-off-by: Marti Bolivar <marti@foundries.io>
2018-08-02 19:18:05 +02:00
Johan Hedberg
1292609458 logging: Use vsnprintk instead of vsnprintf
The printk family of functions is used elsewhere, so make this
consistent. Also, printk has a smaller stack footprint.

Signed-off-by: Johan Hedberg <johan.hedberg@intel.com>
2018-07-25 17:41:05 +03:00
Marti Bolivar
1bfcea244b subsys: logging: fix trigger threshold corner case
The CONFIG_LOG_PROCESS_TRIGGER_THRESHOLD option can be used to wake up
the background log processing thread when a given number of messages
have been queued.

Currently, the msg_finalize() routine which is responsible for
queueing a log message for later handling appends messages to the
global list after performing the threshold check and waking up the
thread.

This leads to a race condition with undesirable behavior if the
threshold == 1:

- the msg_finalize() thread is scheduled out by calling k_wakeup()
- the log processing thread wakes up, notice that no messages are
  queued, and goes back to sleep
- the msg_finalize() thread is scheduled back in and the message is
  queued for processing

This defers the handling of the message until the processing thread
wakes up again after the CONFIG_LOG_PROCESS_THREAD_SLEEP_MS timeout,
which is not what the user wants.

Fix this by queueing the message before waking up the handler thread.
(This also may improve responsiveness for larger threshold values.)

Signed-off-by: Marti Bolivar <marti@foundries.io>
2018-07-25 07:14:16 -04:00
Krzysztof Chruscinski
46db70ac4c doc: subsys: logging: internal thread and thread wake up
Documenting new logger features: waking up processing thread
and internal logger processing thread.

Signed-off-by: Krzysztof Chruscinski <krzysztof.chruscinski@nordicsemi.no>
2018-07-16 11:12:16 -04:00
Krzysztof Chruscinski
000aaf96fb logging: Add internal thread for log processing
When enabled, logger is creating own thread which processes buffered
logs. When no logs to process, thread sleeps for configurable period.
Thread can be waken up if number of buffered log messages exceeds
configured threshold. Logging sample aligned to use new feature.

Signed-off-by: Krzysztof Chruscinski <krzysztof.chruscinski@nordicsemi.no>
2018-07-16 11:12:16 -04:00
Krzysztof Chruscinski
1ba542c352 logging: Logger to wake up logs processing thread
Added configurable threshold of number of buffered log messages
on which log wakes up thread which processes buffered logs. Thread
ID is provided during logger initialization. Feature is optional
and can be disabled by setting CONFIG_LOG_PROCESS_TRIGGER_THR to 0.

Signed-off-by: Krzysztof Chruscinski <krzysztof.chruscinski@nordicsemi.no>
2018-07-16 11:12:16 -04:00
Krzysztof Chruscinski
6b01c89935 logging: Add log initialization to system startup
Log API can be used before user can explicitly initialize the logger.
In order to ensure that logger core is ready to buffer log messages
it must be initialize as early as possible. Initialization does not
include initialization of default backend since driver may not be
ready and backend is needed only when log messages are processed.

Signed-off-by: Krzysztof Chruscinski <krzysztof.chruscinski@nordicsemi.no>
2018-07-14 08:32:44 -04:00
Krzysztof Chruściński
bbeef4155c logging: subsystem major redesign
Adding new implementation of logging subsystem. New features
includes: support for multiple backends, improving performance
by deferring log processing to the known context, adding
timestamps and logs filtering options (compile time, runtime,
module level, instance level). Console backend added as the
example backend.

Signed-off-by: Krzysztof Chruściński <krzysztof.chruscinski@nordicsemi.no>
2018-06-29 10:16:45 +02:00