sys/log: avoid log_color adding to _ namespace #18379

kfessel · 2022-07-27T15:00:33Z

Contribution description

A concern was raised in #18328 that including of log.h might add to _ namespace, this fixes that making the constat local to its only using function.

while doing that i also found a potential (only small) out of bound read and put a check for that into the assert of that function

Testing procedure

run
tests/log_color

for the potential out of bound array read add a
LOG(-1,format, value, string); to the main.c of that test.

Issues/PRs references

Fixes #18328

benpicco · 2022-07-27T15:02:25Z

sys/log/log_color/log_module.h

+        [LOG_INFO] = LOG_INFO_ANSI_COLOR_CODE,
+        [LOG_DEBUG] = LOG_DEBUG_ANSI_COLOR_CODE,
+    };
+    assert(level > 0 && level < sizeof(_ansi_codes)/sizeof(_ansi_codes[0]));


Suggested change

assert(level > 0 && level < sizeof(_ansi_codes)/sizeof(_ansi_codes[0]));

assert(level > 0 && level < ARRAY_SIZE(_ansi_codes));

I don't think i should include "kernel_defines.h" that would counter_act the intention of this PR to have a cleaner Namespace

miri64 · 2022-07-28T07:47:58Z

sys/log/log_color/log_module.h

+    static const char * const _ansi_codes[] =
+    {
+        [LOG_ERROR] = LOG_ERROR_ANSI_COLOR_CODE,
+        [LOG_WARNING] = LOG_WARNING_ANSI_COLOR_CODE,
+        [LOG_INFO] = LOG_INFO_ANSI_COLOR_CODE,
+        [LOG_DEBUG] = LOG_DEBUG_ANSI_COLOR_CODE,
+    };


Please test or argue against: does this, if log.h is included by multiple compile units and log_write() is called by those compile units, does this increase the ROM, since _ansi_codes is defined multiple times. This might have been the case before as well, if so, the next step (so, if already the case not in this PR) should be to make log_write not a static inline.

This following debugging session show that at least the strings aren't doubled.
If the the log_write is inlined or not will depend on the optimization level and the nuber of uses in that compile unit with the log_color test there are 4(with modification 5) users of that function and gcc (nativ) choose to not inline. I got one implementation per compile unit but both are using the same location to get the string literals (color codes) from.

For the test i copied main.c to another.c (renamed the main() to another()) and called it from the main()

<RIOT>/tests/log_color$ make debug gdb -q --args <RIOT>/tests/log_color/bin/native/tests_log_color.elf /dev/ttyACM0 Reading symbols from <RIOT>/tests/log_color/bin/native/tests_log_color.elf... (gdb) b log_write Breakpoint 1 at 0x80495d6: log_write. (5 locations) (gdb) r Starting program: <RIOT>/tests/log_color/bin/native/tests_log_color.elf /dev/ttyACM0 RIOT native interrupts/signals initialized. RIOT native board initialized. RIOT native hardware initialization complete. Help: Press s to start test, r to print it is ready s START Breakpoint 1, log_write (level=3, format=0x804d0cc "main(): This is RIOT! (Version: tool-test-fixed-1703-g208d4-p-fix-18328)\n") at <RIOT>/sys/log/log_color/log_module.h:82 82 { (gdb) (gdb) bt #0 log_write (level=3, format=0x804d0cc "main(): This is RIOT! (Version: tool-test-fixed-1703-g208d4-p-fix-18328)\n") at <RIOT>/sys/log/log_color/log_module.h:82 #1 0x080499d4 in main_trampoline (arg=0x0) at <RIOT>/core/lib/init.c:55 #2 0xf7ddfa19 in makecontext () from /lib/i386-linux-gnu/libc.so.6 #3 0x00000000 in ?? () (gdb) n 90 assert(level > 0 && level < sizeof(_ansi_codes)/sizeof(_ansi_codes[0])); (gdb) n 92 printf("%s", _ansi_codes[level]); (gdb) p _ansi_codes $1 = {0x0, 0x804d04c "\033[1;31m", 0x804d054 "\033[1;33m", 0x804d05c "\033[1m", 0x804d061 "\033[0;32m"} (gdb) r The program being debugged has been started already. Start it from the beginning? (y or n) n Program not restarted. (gdb) c Continuing. main(): This is RIOT! (Version: tool-test-fixed-1703-g208d4-p-fix-18328) Breakpoint 1, log_write (level=1, format=0x804d028 "Logging value '%d' and string '%s'\n") at <RIOT>/sys/log/log_color/log_module.h:82 82 { (gdb) p _ansi_codes $2 = {0x0, 0x804d04c "\033[1;31m", 0x804d054 "\033[1;33m", 0x804d05c "\033[1m", 0x804d061 "\033[0;32m"} (gdb) c Continuing. Logging value '42' and string 'test' Breakpoint 1, log_write (level=2, format=0x804d028 "Logging value '%d' and string '%s'\n") at <RIOT>/sys/log/log_color/log_module.h:82 82 { (gdb) c Continuing. Logging value '42' and string 'test' Breakpoint 1, log_write (level=3, format=0x804d028 "Logging value '%d' and string '%s'\n") at <RIOT>/sys/log/log_color/log_module.h:82 82 { (gdb) c Continuing. Logging value '42' and string 'test' Breakpoint 1, log_write (level=4, format=0x804d028 "Logging value '%d' and string '%s'\n") at <RIOT>/sys/log/log_color/log_module.h:82 82 { (gdb) c Continuing. Logging value '42' and string 'test' Breakpoint 1, log_write (level=1, format=0x804d028 "Logging value '%d' and string '%s'\n") at <RIOT>/sys/log/log_color/log_module.h:82 82 { (gdb) bt #0 log_write (level=1, format=0x804d028 "Logging value '%d' and string '%s'\n") at <RIOT>/sys/log/log_color/log_module.h:82 #1 0x080496a0 in another () at <RIOT>/tests/log_color/another.c:29 #2 0x080497f7 in main () at <RIOT>/tests/log_color/main.c:35 (gdb) p _ansi_codes $3 = {0x0, 0x804d04c "\033[1;31m", 0x804d054 "\033[1;33m", 0x804d05c "\033[1m", 0x804d061 "\033[0;32m"} (gdb) x _ansi_codes 0x8051dc0 <_ansi_codes.0>: 0x00000000 (gdb)

just to highlight Breakpoint 1 at 0x80495d6: log_write. (5 locations) there are 5 implementation of log_write in that very small program maybe miri is right and we should make this a regular function:

the _ansi_codes.0 are also at 5 locations

objdump: SYMBOL TABLE: 00000000 l df *ABS* 00000000 another.c 080495d6 l F .text 00000093 log_write 08051dc0 l O .data.rel.ro 00000014 _ansi_codes.0 00000000 l df *ABS* 00000000 main.c 080496f1 l F .text 00000093 log_write 08051dd4 l O .data.rel.ro 00000014 _ansi_codes.0 00000000 l df *ABS* 00000000 auto_init.c 00000000 l df *ABS* 00000000 board_init.c 00000000 l df *ABS* 00000000 assert.c 00000000 l df *ABS* 00000000 init.c 0804990c l F .text 00000093 log_write 08051de8 l O .data.rel.ro 00000014 _ansi_codes.0 0804999f l F .text 00000074 main_trampoline 080520a0 l O .bss 00002000 idle_stack 08049a13 l F .text 00000026 idle_thread 080540a0 l O .bss 00003000 main_stack 00000000 l df *ABS* 00000000 panic.c 08049ab5 l F .text 00000093 log_write 08051dfc l O .data.rel.ro 00000014 _ansi_codes.0 080570a0 l O .bss 00000004 crashed 00000000 l df *ABS* 00000000 msg.c 00000000 l df *ABS* 00000000 sched.c 08049bf2 l F .text 00000093 log_write 08051e10 l O .data.rel.ro 00000014 _ansi_codes.0

and yes the same thing happens if the _ansi_codes are a static const outside of that static inline log_write the only difference in the symbol table being it name _ansi_codes instead of _ansi_codes.0

e.g.:

00000000 l df *ABS* 00000000 another.c 080495d6 l F .text 00000093 log_write 08051dc0 l O .data.rel.ro 00000014 _ansi_codes 00000000 l df *ABS* 00000000 main.c 080496f1 l F .text 00000093 log_write 08051dd4 l O .data.rel.ro 00000014 _ansi_codes

kfessel · 2022-10-17T14:16:56Z

superseded by #18425

sys/log: avoid log_color adding to _ namespace

208d4d2

github-actions bot added the Area: sys Area: System label Jul 27, 2022

kfessel requested review from aabadie and benpicco July 27, 2022 15:01

benpicco added the CI: ready for build If set, CI server will compile all applications for all available boards for the labeled PR label Jul 27, 2022

benpicco reviewed Jul 27, 2022

View reviewed changes

miri64 reviewed Jul 28, 2022

View reviewed changes

kfessel mentioned this pull request Aug 5, 2022

sys/log: make log_write nonstatic for log_color #18403

Closed

kfessel mentioned this pull request Sep 15, 2022

sys/log_*: modularize log into log_color and log_printfnoformat #18425

Merged

kfessel closed this Oct 17, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

sys/log: avoid log_color adding to _ namespace #18379

sys/log: avoid log_color adding to _ namespace #18379

Uh oh!

kfessel commented Jul 27, 2022

Uh oh!

benpicco Jul 27, 2022

Uh oh!

kfessel Jul 27, 2022

Uh oh!

miri64 Jul 28, 2022

Uh oh!

kfessel Jul 28, 2022

Uh oh!

kfessel Jul 28, 2022 •

edited

Loading

Uh oh!

kfessel Jul 28, 2022

Uh oh!

kfessel commented Oct 17, 2022

Uh oh!

Uh oh!

	assert(level > 0 && level < sizeof(_ansi_codes)/sizeof(_ansi_codes[0]));
	assert(level > 0 && level < ARRAY_SIZE(_ansi_codes));

sys/log: avoid log_color adding to _ namespace #18379

sys/log: avoid log_color adding to _ namespace #18379

Uh oh!

Conversation

kfessel commented Jul 27, 2022

Contribution description

Testing procedure

Issues/PRs references

Uh oh!

benpicco Jul 27, 2022

Choose a reason for hiding this comment

Uh oh!

kfessel Jul 27, 2022

Choose a reason for hiding this comment

Uh oh!

miri64 Jul 28, 2022

Choose a reason for hiding this comment

Uh oh!

kfessel Jul 28, 2022

Choose a reason for hiding this comment

Uh oh!

kfessel Jul 28, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

kfessel Jul 28, 2022

Choose a reason for hiding this comment

Uh oh!

kfessel commented Oct 17, 2022

Uh oh!

Uh oh!

kfessel Jul 28, 2022 •

edited

Loading