tests/subsys/logging/log_msg2 failes on qemu_cortex_a53

[dcpleung]

Describe the bug
There is build error with tests/subsys/logging/log_msg2 on qemu_cortex_a53 due to uninitialized variable. However, after setting a default value to lli, the test would fail.

To Reproduce
Steps to reproduce the behavior:

1. west build -d /tmp/build -p -b qemu_cortex_a53 tests/subsys/logging/log_msg2/

Expected behavior
Should build without errors.

Impact
Prevents verifying local changes via twister.

Logs and console output

zephyr/rtos/zephyr/subsys/logging/log_core.c: In function 'log_hexdump':
zephyr/rtos/zephyr/subsys/logging/log_core.c:341:6: note: parameter passing for argument of type 'struct log_msg_ids' changed in GCC 9.1
  341 | void log_hexdump(const char *str, const void *data, uint32_t length,
      |      ^~~~~~~~~~~
[118/129] Building C object CMakeFiles/app.dir/src/main.c.obj
In file included from zephyr/rtos/zephyr/tests/subsys/logging/log_msg2/src/main.c:12:
zephyr/rtos/zephyr/tests/subsys/logging/log_msg2/src/main.c: In function 'test_log_msg2_fp':
zephyr/rtos/zephyr/include/logging/log_msg2.h:420:3: warning: 'lli' is used uninitialized in this function [-Wuninitialized]
  420 |   z_log_msg2_runtime_create(_domain_id, (void *)_source, \
      |   ^~~~~~~~~~~~~~~~~~~~~~~~~
zephyr/rtos/zephyr/tests/subsys/logging/log_msg2/src/main.c:311:12: note: 'lli' was declared here
  311 |  long long lli;
      |            ^~~
In file included from zephyr/rtos/zephyr/include/logging/log_msg2.h:655,
                 from zephyr/rtos/zephyr/tests/subsys/logging/log_msg2/src/main.c:12:
zephyr/include/generated/syscalls/log_msg2.h: In function 'z_log_msg2_static_create.constprop':
zephyr/include/generated/syscalls/log_msg2.h:25:20: note: parameter passing for argument of type 'const struct log_msg2_desc' changed in GCC 9.1
   25 | static inline void z_log_msg2_static_create(const void * source, const struct log_msg2_desc desc, uint8_t * package, const void * data)
      |                    ^~~~~~~~~~~~~~~~~~~~~~~~

After setting a default value to lli, test would fail:

START - test_log_msg2_fp

    Assertion failed at WEST_TOPDIR/zephyr/tests/subsys/logging/log_msg2/src/main.c:321: test_log_msg2_fp: mode not equal to EXP_MODE(ZERO_COPY)

 FAIL - test_log_msg2_fp in 0.1 seconds
===================================================================
START - test_mode_size_plain_string

    Assertion failed at WEST_TOPDIR/zephyr/tests/subsys/logging/log_msg2/src/main.c:344: get_msg_validate_length: (len not equal to exp_len)
Unexpected message length 20 (exp:8)
 FAIL - test_mode_size_plain_string in 0.1 seconds
===================================================================
START - test_mode_size_data_only

    Assertion failed at WEST_TOPDIR/zephyr/tests/subsys/logging/log_msg2/src/main.c:344: get_msg_validate_length: (len not equal to exp_len)
Unexpected message length 8 (exp:6)
 FAIL - test_mode_size_data_only in 0.1 seconds
===================================================================
START - test_mode_size_plain_str_data

    Assertion failed at WEST_TOPDIR/zephyr/tests/subsys/logging/log_msg2/src/main.c:344: get_msg_validate_length: (len not equal to exp_len)
Unexpected message length 8 (exp:10)
 FAIL - test_mode_size_plain_str_data in 0.1 seconds
===================================================================
START - test_mode_size_str_with_2strings

    Assertion failed at WEST_TOPDIR/zephyr/tests/subsys/logging/log_msg2/src/main.c:344: get_msg_validate_length: (len not equal to exp_len)
Unexpected message length 6 (exp:12)
 FAIL - test_mode_size_str_with_2strings in 0.1 seconds

Environment (please complete the following information):

• Linux
• Zephyr SDK 0.12.4
• commit 556baa2

[nixchun]

I don't have this compilation problem on Zephyr 0.12.4.
log_msg2.txt

[galak]

@npitre this seems to be introduced with f1f63dd. Not sure if your #34793 might address this.

[npitre]

@npitre this seems to be introduced with f1f63dd. Not sure if your #34793 might address this.

No. #34793 won't do anything here.

…

-- You are receiving this because you were mentioned. Reply to this email directly or view it on GitHub: #34838 (comment)

[galak]

No. #34793 won't do anything here.

Yeah, I was hoping it might magically fix this issue. :)

[npitre]

The first warning can be reproduced with this small test:

struct foo {
	short a : 3;
	short b : 3;
	short c : 10;
};

void bar(struct foo f) { }

This produces the following:

$ aarch64-zephyr-elf-gcc -c test.c
test.c: In function 'bar':
test.c:7:6: note: parameter passing for argument of type 'struct foo' changed in GCC 9.1
    7 | void bar(struct foo f) { }
      |      ^~~

It appears that the only way to shut it up is to use -Wno-psabi.
However this could have unexpected impact elsewhere if people link against
libraries that might have that a mismatched ABI. Some project-wide policy
might be needed here.

[dcpleung]

The warning about GCC 9.1 does not result in twister failure. It's just annoyance during build.

[galak]

we're able to build, but the test fails to run correctly in qemu is what I was seeing.

[npitre]

A few things look wrong here.

Z_LOG_MSG2_CREATE2() is passed a char str[256] making
CBPRINTF_MUST_RUNTIME_PACKAGE() to always be true. The resulting mode is
RUNTIME and not ZERO_COPY which fails the first zassert_equal().

Then, removing the str argument makes it pass, but the test fails further
down. It turns out that the static package produces a payload of 56 bytes
whereas the runtime package is 64 bytes. The hex dump shows 8 extra zero bytes
in the middle, probably due to some padding.

I tried twister -p qemu_cortex_a53 -T tests/lib/cbprintf_package to
validate proper padding around doubles. This is a simpler test without the
the logging stuff. But that failed to build for yet another reason:

zephyr/tests/lib/cbprintf_package/src/test.inc:
In function 'void test_cbprintf_package()':
zephyr/include/sys/cbprintf_internal.h:244:15: error: non-constant condition for static assertion
  244 |  BUILD_ASSERT(!((sizeof(double) < VA_STACK_ALIGN(long double)) && \
      |               ^~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
  245 |    Z_CBPRINTF_IS_LONGDOUBLE(_arg) && \
      |    ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
  246 |    !IS_ENABLED(CONFIG_CBPRINTF_PACKAGE_LONGDOUBLE)),\
      |    ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

WTF?? Here CONFIG_CBPRINTF_PACKAGE_LONGDOUBLE is not even enabled.
In fact the whole build.log file has 7429 lines in it!
The amount of macro recursion is simply overwelming and gcc list them all.

There is a bit too much magic in this static packing code.

@nordic-krch You are the magician. Could you please have a look?

[npitre]

This appears to be fixed with #34951