Skip to content

logging: log_cmds: backend ID is wrong for backend(s) that do not autostart #84952

@ycsin

Description

@ycsin

Describe the bug

The log backend cb id is initialized on startup by the OS if the autostart flag is set, otherwise it relies on the user application to invoke the log_backend_init() & log_backend_enable() to set it up properly.

Until the user application initializes the backends manually, the logging shell commands (and possibly other logging APIs) are going to access locations pointed-to by the uninitialized backend index, which looks worrying:

% grep -rnw ./subsys/logging -e 'log_backend_id_get' 
./subsys/logging/log_mgmt.c:460:                        uint32_t current = filter_set(log_backend_id_get(log_backend_get(i)),
./subsys/logging/log_mgmt.c:480:        int id = (backend == NULL) ? -1 : log_backend_id_get(backend);
./subsys/logging/log_mgmt.c:582:        int id = (backend == NULL) ? -1 : log_backend_id_get(backend);

To Reproduce
Steps to reproduce the behavior:

  1. Check out current main branch, I'm on b6f8eff
  2. west build -b qemu_riscv64 -p auto -t run zephyr/samples/hello_world -- -DCONFIG_LOG=y -DCONFIG_SHELL=y -DCONFIG_LOG_CMDS=y -DCONFIG_LOG_BACKEND_UART=y -DCONFIG_LOG_BACKEND_UART_AUTOSTART=n
  3. See the console log below:
uart:~$ log list_backends
log_backend_uart
        - Status: disabled
        - ID: 0

shell_uart_backend
        - Status: enabled
        - ID: 2

uart:~$ log backend shell_uart_backend status
module_name                              | current | built-in 
----------------------------------------------------------
cbprintf_package                         | inf     | inf
getopt                                   | inf     | inf
log                                      | inf     | inf
log_mgmt                                 | inf     | inf
log_uart                                 | inf     | inf
mpu                                      | inf     | inf
os                                       | inf     | inf
shell.shell_uart                         | inf     | inf
shell_uart                               | inf     | inf
uart_ns16550                             | inf     | inf
uart:~$ log backend log_backend_uart status
Logs are halted!
module_name                              | current | built-in 
----------------------------------------------------------
cbprintf_package                         | inf     | inf
getopt                                   | inf     | inf
log                                      | inf     | inf
log_mgmt                                 | inf     | inf
log_uart                                 | inf     | inf
mpu                                      | inf     | inf
os                                       | inf     | inf
shell.shell_uart                         | inf     | inf
shell_uart                               | inf     | inf
uart_ns16550                             | inf     | inf
uart:~$ log backend shell_uart_backend enable wrn
uart:~$ log backend shell_uart_backend status
module_name                              | current | built-in 
----------------------------------------------------------
cbprintf_package                         | wrn     | inf
getopt                                   | wrn     | inf
log                                      | wrn     | inf
log_mgmt                                 | wrn     | inf
log_uart                                 | wrn     | inf
mpu                                      | wrn     | inf
os                                       | wrn     | inf
shell.shell_uart                         | wrn     | inf
shell_uart                               | wrn     | inf
uart_ns16550                             | wrn     | inf
uart:~$ log backend log_backend_uart status
Logs are halted!
module_name                              | current | built-in 
----------------------------------------------------------
cbprintf_package                         | wrn     | inf
getopt                                   | wrn     | inf
log                                      | wrn     | inf
log_mgmt                                 | wrn     | inf
log_uart                                 | wrn     | inf
mpu                                      | wrn     | inf
os                                       | wrn     | inf
shell.shell_uart                         | wrn     | inf
shell_uart                               | wrn     | inf
uart_ns16550                             | wrn     | inf

Expected behavior
A few things are off in the console output above:

  1. The ID of the log_backend_uart shouldn't be 0, since LOG_FILTER_FIRST_BACKEND_SLOT_IDX is defined to be 1
  2. The current log level of an uninitialized backend like log_backend_uart should be none
  3. Configuring the log-level of shell_uart_backend erroneously affects the log-level of log_backend_uart

Impact

Logging shell commands do not function as expected and causes confusion.

Logs and console output

Full console log
Hello World! qemu_riscv64/qemu_virt_riscv64

*** Booting Zephyr OS build v4.0.0-3714-gb6f8eff2f322 ***
uart:~$ log list_backends
log_backend_uart
        - Status: disabled
        - ID: 0

shell_uart_backend
        - Status: enabled
        - ID: 2

uart:~$ log backend shell_uart_backend status
module_name                              | current | built-in 
----------------------------------------------------------
cbprintf_package                         | inf     | inf
getopt                                   | inf     | inf
log                                      | inf     | inf
log_mgmt                                 | inf     | inf
log_uart                                 | inf     | inf
mpu                                      | inf     | inf
os                                       | inf     | inf
shell.shell_uart                         | inf     | inf
shell_uart                               | inf     | inf
uart_ns16550                             | inf     | inf
uart:~$ log backend log_backend_uart status
Logs are halted!
module_name                              | current | built-in 
----------------------------------------------------------
cbprintf_package                         | inf     | inf
getopt                                   | inf     | inf
log                                      | inf     | inf
log_mgmt                                 | inf     | inf
log_uart                                 | inf     | inf
mpu                                      | inf     | inf
os                                       | inf     | inf
shell.shell_uart                         | inf     | inf
shell_uart                               | inf     | inf
uart_ns16550                             | inf     | inf
uart:~$ log backend shell_uart_backend enable wrn
uart:~$ log backend shell_uart_backend status
module_name                              | current | built-in 
----------------------------------------------------------
cbprintf_package                         | wrn     | inf
getopt                                   | wrn     | inf
log                                      | wrn     | inf
log_mgmt                                 | wrn     | inf
log_uart                                 | wrn     | inf
mpu                                      | wrn     | inf
os                                       | wrn     | inf
shell.shell_uart                         | wrn     | inf
shell_uart                               | wrn     | inf
uart_ns16550                             | wrn     | inf
uart:~$ log backend log_backend_uart status
Logs are halted!
module_name                              | current | built-in 
----------------------------------------------------------
cbprintf_package                         | wrn     | inf
getopt                                   | wrn     | inf
log                                      | wrn     | inf
log_mgmt                                 | wrn     | inf
log_uart                                 | wrn     | inf
mpu                                      | wrn     | inf
os                                       | wrn     | inf
shell.shell_uart                         | wrn     | inf
shell_uart                               | wrn     | inf
uart_ns16550                             | wrn     | inf
uart:~$ log backend log_backend_uart go
uart:~$ log backend log_backend_uart status
module_name                              | current | built-in 
----------------------------------------------------------
cbprintf_package                         | wrn     | inf
getopt                                   | wrn     | inf
log                                      | wrn     | inf
log_mgmt                                 | wrn     | inf
log_uart                                 | wrn     | inf
mpu                                      | wrn     | inf
os                                       | wrn     | inf
shell.shell_uart                         | wrn     | inf
shell_uart                               | wrn     | inf
uart_ns16550                             | wrn     | inf
uart:~$ log backend shell_uart_backend status
module_name                              | current | built-in 
----------------------------------------------------------
cbprintf_package                         | wrn     | inf
getopt                                   | wrn     | inf
log                                      | wrn     | inf
log_mgmt                                 | wrn     | inf
log_uart                                 | wrn     | inf
mpu                                      | wrn     | inf
os                                       | wrn     | inf
shell.shell_uart                         | wrn     | inf
shell_uart                               | wrn     | inf
uart_ns16550                             | wrn     | inf
uart:~$ log backend log_backend_uart enable err
uart:~$ log backend log_backend_uart status
module_name                              | current | built-in 
----------------------------------------------------------
cbprintf_package                         | wrn     | inf
getopt                                   | wrn     | inf
log                                      | wrn     | inf
log_mgmt                                 | wrn     | inf
log_uart                                 | wrn     | inf
mpu                                      | wrn     | inf
os                                       | wrn     | inf
shell.shell_uart                         | wrn     | inf
shell_uart                               | wrn     | inf
uart_ns16550                             | wrn     | inf
uart:~$ log backend shell_uart_backend status
module_name                              | current | built-in 
----------------------------------------------------------
cbprintf_package                         | wrn     | inf
getopt                                   | wrn     | inf
log                                      | wrn     | inf
log_mgmt                                 | wrn     | inf
log_uart                                 | wrn     | inf
mpu                                      | wrn     | inf
os                                       | wrn     | inf
shell.shell_uart                         | wrn     | inf
shell_uart                               | wrn     | inf
uart_ns16550                             | wrn     | inf

Environment (please complete the following information):

  • OS: MacOS
  • Toolchain: Zephyr SDK 0.17.0
  • Commit SHA or Version used: b6f8eff, this issue exists in v3.7 and earlier versions

Additional context
See also #84954

Metadata

Metadata

Assignees

Labels

area: LoggingbugThe issue is a bug, or the PR is fixing a bug

Type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions