QEMU with board qemu_x86 crashes in snprintf()- source code missing, hard to debug

[Johan]

Have a strange crash when calling snprintf (using qemu x86):

1.  I flash the ztest to the board, it works, but running qemu in windows x86, it crashes on that snprintf-line below.
   
   Use Nordic open connect sdk version (2.2).
   
   I see it's declared as: int snprintf (char __restrict, size_t, const charrestrict, ...) _ATTRIBUTE ((format (printf__, 3, 4)));
   
   Problem causing lines:

   int m_unique_id_sent = 124568;
   char unique_id_sent_buf[36];
   int len = snprintf(unique_id_sent_buf, sizeof(unique_id_sent_buf), "%d", m_unique_id_sent);
   
   I get a crash (in qemu, running a unit test I wrote, for a module I want to test).
   LOG (with decoded crash address pointers
   E: Double Fault E:
   EAX: 0x002c4200,
   EBX: 0x002c4200,
   ECX: 0x0025c22c,
   EDX: 0x0013b254
   E: ESI: 0x0013a9f0,
   EDI: 0x00120a8b,
   EBP: 0x0025c168,
   ESP: 0x0025bfe4
   E: EFLAGS: 0x00000206
   CS: 0x0008
   CR3: 0x002ca000
   E: call trace:
   E: EIP: 0x001065af
   
   E: 0x00105f88 (0x2c4200) - (zephyr: snprint) no debug info available. Will look at zephyr_final.map for this one (see below after crash log) (1st parameters is defined on stack as: char unique_id_sent_buf[36];
   
   E: 0x00116f9d (0x25c214) - (my code) rpc.c: 401 - calling snprintf(unique_id_sent_buf, sizeof(unique_id_sent_buf), "%d", m_unique_id_sent);
   E: 0x001172ed (0x25c4fc) - (my code) rpc.c : 532 // calling new function (4 parameters)
   E: 0x001173ce (0x25c4fc) - (my code) rpc.c : 583 // Inside function - calling other function (char * buf, int size)
   E: 0x00114014 (0x25c4fc) - (my code)..server_response.c: line 74 - calling function pointer to other module (all good)
   E: 0x00112ed5 (0x1173ac) - (my code) test_function: line 403 (all good)
   E: 0x001140d8 (0xaaaaaaaa) - ztest main.c // zassert_true(ztest_test_function(), "Error when testing test_function");
   E: 0x0011409e (0xaaaaaaaa) - ztest main.c // ZTEST(ocpp_client_tests, test_use_case_a1)
   
   E: >>> ZEPHYR FATAL ERROR 2: Stack overflow on CPU 0 E: Current thread: 0x149dc0 (main) E: Halting system

   I have defined stacks good for the emulator. Didn't help.

   CONFIG_HEAP_MEM_POOL_SIZE=128000

   CONFIG_MAIN_STACK_SIZE=128000

   CONFIG_SYSTEM_WORKQUEUE_STACK_SIZE=128000
   FAILED: zephyr/CMakeFiles/debugserver_qemu cmd.exe /C "cd /D C:\k\np\v2.2.0\ocpp-9160\apps\ocpp_client\tests_build_ocpp_qemu_x86_ZTEST && "C:\Program Files\qemu\qemu-system-i386.exe" -m 4 -cpu qevice isa-debug-exit,iobase=0xf4,iosize=0x04 -nographic -no-acpi -net none -pidfile qemu.pid -chardev stdio,id=con,mux=on -serial chardev:con -mon chardrnel C:/k/np/v2.2.0/ocpp-9160/apps/ocpp_client/tests/_build_ocpp_qemu_x86_ZTEST/zephyr/zephyr.elf" ninja: build stopped: subcommand failed. make[1]: [Makefile:37: debug_qemu_x86] Error 1 make[1]: Leaving directory 'C:/k/np/v2.2.0/ocpp-9160/apps/ocpp_client/tests' make: [Makefile:108: start_qemu_x86_gdb_sever] Error
   
   MAP FILE INSPECTION
   LOOKING AT the zephyr_final.map I find this: .
   
   text.
   snprintf 0x0000000000105f40 0xae   C:/k/np/toolchains/v2.2.0/opt/zephyr-sdk/x86_64-zephyr-elf/x86_64-zephyr-elf/lib/32/soft-float\libc.a(lib_a-snprintf.o)
   0x0000000000105f40 snprintf
   
   So it's somewhere inside the snprintf it crashes with fault or double fault. I'm not sure where to find the source code and map what c-code line this offset of 0x00105f88 maps to. Can someone give me some helpful advice on the above generally?
   
   Cheers,
   JOhan

[Sigurd Hellesvik]

Hi Johan,

 I flash the ztest to the board, it works, but running qemu in windows x86, it crashes on that snprintf-line below.

Do you use one of ther samples in  the nRF Connect SDK for this?
If yes, can you give the command you use to build for qemu?

Regards,
Sigurd Hellesvik

[Johan]

We use our own project, no sample code.
We use QEMU x86 to test our code, with controlled inputs and outputs.
Our code has e few threads running for example, and hardware interfaces (simulated).

build command is:
west build --build-dir _build_xyz_qemu_x86_ZTEST -b qemu_x86 -t run

.conf file for qemu x86 used contains this:

CONFIG_ASSERT=y

CONFIG_NEWLIB_LIBC=y

CONFIG_NEWLIB_LIBC_FLOAT_PRINTF=y

CONFIG_EVENTS=y

CONFIG_REBOOT=y

CONFIG_DEBUG=y

CONFIG_LOG=y

CONFIG_LOG_BACKEND_RTT=n

CONFIG_LOG_PRINTK=y

CONFIG_LOG_BUFFER_SIZE=256

# JSON

CONFIG_JSON_LIBRARY=y

#CONFIG_QEMU_ICOUNT=n

#CONFIG_ENTROPY_GENERATOR=y

#CONFIG_TEST_RANDOM_GENERATOR=y

# Network

CONFIG_NETWORKING=y

CONFIG_NET_NATIVE=n

CONFIG_NET_SOCKETS=y

CONFIG_NET_SOCKETS_OFFLOAD=y

CONFIG_NET_SOCKETS_POSIX_NAMES=y

# mbed TLS and security

CONFIG_MBEDTLS_PK_C=y

CONFIG_MBEDTLS_RSA_C=y

CONFIG_MBEDTLS_PKCS1_V15=y

CONFIG_MBEDTLS_ENABLE_HEAP=y

CONFIG_MBEDTLS_HEAP_SIZE=55936

CONFIG_MBEDTLS_TLS_LIBRARY=y

CONFIG_MBEDTLS_X509_LIBRARY=y

CONFIG_NRF_SECURITY_ADVANCED=y

CONFIG_NORDIC_SECURITY_BACKEND=y

# You can enable mbed TLS debug with

CONFIG_MBEDTLS_DEBUG_C=y

CONFIG_MBEDTLS_SHA1_C=y

# AT host library

# CONFIG_AT_HOST_LIBRARY=y

CONFIG_UART_INTERRUPT_DRIVEN=y

# Net related

CONFIG_NET_SOCKETS_SOCKOPT_TLS=n

CONFIG_NET_IPV4=y

CONFIG_NET_IPV6=n

CONFIG_DEBUG_OPTIMIZATIONS=n

# Heap and stacks

# Extended memory heap size needed for encoding nRF Cloud messages to JSON

CONFIG_HEAP_MEM_POOL_SIZE=4096

CONFIG_MAIN_STACK_SIZE=4096

CONFIG_SYSTEM_WORKQUEUE_STACK_SIZE=4096

CONFIG_NO_OPTIMIZATIONS=y

# settings

CONFIG_SETTINGS=y

CONFIG_SETTINGS_RUNTIME=y

CONFIG_STDOUT_CONSOLE=y

CONFIG_FLASH=y

CONFIG_FLASH_MAP=y

CONFIG_NVS=y

CONFIG_SETTINGS_NVS=y

CONFIG_SHELL_CMDS_SELECT=y

CONFIG_INIT_STACKS=y

CONFIG_THREAD_STACK_INFO=y

CONFIG_ENTROPY_GENERATOR=y

CONFIG_TEST_RANDOM_GENERATOR=y

CONFIG_THREAD_MONITOR=y

# ZTEST

CONFIG_ZTEST=y

CONFIG_ZTEST_NEW_API=y

# ZTEST enable test shuffling for more testing

#CONFIG_ZTEST_SHUFFLE=y

#CONFIG_ZTEST_SHUFFLE_SUITE_REPEAT_COUNT=0

#CONFIG_ZTEST_SHUFFLE_TEST_REPEAT_COUNT=0

# ZTEST more log output

CONFIG_ZTEST_VERBOSE_OUTPUT=y

CONFIG_ZTEST_VERBOSE_SUMMARY=y

[Johan]

Saw this: not sure if related.

github.com/.../304

[Johan]

The zephyr-sdk compiled in toolchain 2.2.0 is:

0.15.1

Quite old.

Latest is: Zephyr SDK 0.16.1

[Johan]

Perhaps we need to switch to Connect SDK 2.4.0, if that is using the latest Zephyr SDK 0.16.1, possibly.
I see Connect SDK 2.4.0 uses 0.16.0, so quite new.

[Sigurd Hellesvik]

Johan said:

Saw this: not sure if related.

github.com/.../304

Could look related.

A comment here suggests CONFIG_FPU=y, which could look related to your error, as it is in soft-float.

snprintf 0x0000000000105f40 0xae   C:/k/np/toolchains/v2.2.0/opt/zephyr-sdk/x86_64-zephyr-elf/x86_64-zephyr-elf/lib/32/soft-float

So if we are lucky CONFIG_FPU is all you need?

Johan said:

Perhaps we need to switch to Connect SDK 2.4.0, if that is using the latest Zephyr SDK 0.16.1, possibly.
I see Connect SDK 2.4.0 uses 0.16.0, so quite new.

Switching could be worth a try as well.

[Johan]

No difference with CONFIG_FPU=y

I wonder how I can debug from "source" of zephyr-sdk instead of precompiled .a-files.

How do you suggest I do that with your Connect SDK?

To see where it "dies" in snprintf.