shell: avoid immediate logging to a shell that might not be setup

[ckhardin]

During a boot process bringup an MPU error was triggered because the log process was being called before the shell was initialized which should be avoided by a configuration guard. It seems that using log immediate intends to bypass the shell to just use a backend that is raw - ie. console, serial, etc.

So, just add the configuration guard in addition to the minimal mode

[sonarqubecloud]

Quality Gate passed

Issues
0 New issues
0 Accepted issues

Measures
0 Security Hotspots
0.0% Coverage on New Code
0.0% Duplication on New Code

See analysis details on SonarQube Cloud

[jakub-uC]

@nordic-krch can you please take a look?

[nordic-krch]

It should not be needed. Immediate mode in shell log backend ensures correct multiplexing of logging data with shell data so using raw backend will degrade user expirience.

Shell log backend processing is dropping all messages which come before backend is enabled:

zephyr/subsys/shell/shell_log_backend.c

Line 237 in ad7beb5

case SHELL_LOG_BACKEND_ENABLED:

It would be good figure out why messages were not dropped.

[nordic-krch]

Immediate logging should be supported by shell and any logs coming before shell backend is ready shall be dropped.

[ckhardin]

Here is the crash info - seems a corrupt stack ... we've reproduced this on an stm32f4 and make sure this is in the config so far.

[00:00:00.014,000] <err> os: ***** MPU FAULT *****
[00:00:00.022,000] <err> os:   Stacking error (context area might be not valid)
[00:00:00.032,000] <err> os:   Data Access Violation
[00:00:00.041,000] <err> os:   MMFAR Address: 0x2000f464
[00:00:00.049,000] <err> os: r0/a1:  0xaaaaaaaa  r1/a2:  0xaaaaaaaa  r2/a3:  0xaaaaaaaa
[00:00:00.060,000] <err> os: r3/a4:  0xaaaaaaaa r12/ip:  0xaaaaaaaa r14/lr:  0xaaaaaaaa
[00:00:00.072,000] <err> os:  xpsr:  0xaaaaaa00
[00:00:00.079,000] <err> os: Faulting instruction address (r15/pc): 0xaaaaaaaa
[00:00:00.090,000] <err> os: >>> ZEPHYR FATAL ERROR 2: Stack overflow on CPU 0
[00:00:00.100,000] <err> os: Current thread: 0x20003368 (shell_uart)
[00:00:00.110,000] <err> os: Halting system

and this is the gdb backtrace - but the stack looks a bit corrupted

Thread 1 (Remote target):
#0  arch_system_halt (reason=reason@entry=2) at /Volumes/Workspace/mcu-caboodle/firmware/zephyr/kernel/fatal.c:30
#1  0x080576c6 in k_sys_fatal_error_handler (reason=reason@entry=2, esf=esf@entry=0x20012c84 <z_interrupt_stacks+2052>) at /Volumes/Workspace/mcu-caboodle/firmware/zephyr/kernel/fatal.c:44
#2  0x0805772e in z_fatal_error (reason=reason@entry=2, esf=esf@entry=0x20012c84 <z_interrupt_stacks+2052>) at /Volumes/Workspace/mcu-caboodle/firmware/zephyr/kernel/fatal.c:119
#3  0x0802820c in z_arm_fatal_error (reason=reason@entry=2, esf=esf@entry=0x20012c84 <z_interrupt_stacks+2052>) at /Volumes/Workspace/mcu-caboodle/firmware/zephyr/arch/arm/core/fatal.c:86
#4  0x08028ac8 in z_arm_fault (msp=<optimized out>, psp=<optimized out>, exc_return=<optimized out>, callee_regs=<optimized out>) at /Volumes/Workspace/mcu-caboodle/firmware/zephyr/arch/arm/core/cortex_m/fault.c:1080
#5  0x08028af8 in z_arm_usage_fault () at /Volumes/Workspace/mcu-caboodle/firmware/zephyr/arch/arm/core/cortex_m/fault_s.S:102
#6  <signal handler called>
#7  0x20001ba8 in log_dynamic_os ()
#8  0x00000000 in ?? ()

And this was in the prj.conf

CONFIG_LOG=y
CONFIG_LOG_MODE_IMMEDIATE=y
CONFIG_LOG_DEFAULT_LEVEL=4

[ckhardin]

Immediate logging should be supported by shell and any logs coming before shell backend is ready shall be dropped.

So, when we disable the shell backend and leave immediate the fault would no longer occur and we just use the uart backend of the logging to get the debug. If there is a better path to debugging the corrupt stack then that would be useful. This might be specific to the stm32 since we don't use any other MCUs at this time.