sof-logger: ensure NULL is not passed to printf/fprintf #6848

kv2019i · 2022-12-19T15:34:34Z

Due to allocation failures, or invalid content in dictionary,
"params" entries in "struct proc_ldc_entry" may be NULL.

In print_entry_params(), the NULL entries may be passed
as arguments to fprintf(). While e.g. glibc handles these without
error, this is not guaranteed behaviour and may result in segfault
on some platforms.

Fix the issue by replacing any NULL entries in process_params()
and separately handling the NULL case in dump_ldc_info().

Signed-off-by: Kai Vehmanen kai.vehmanen@linux.intel.com

kv2019i · 2022-12-19T19:32:27Z

V2:

oops, compiler did not like "stdderr", fixed. thanks @ranj063 for spotting

marc-hb

I see format_uid_raw() being used in at least one other place.

Morever format_uid_raw() is not even calling malloc() directly, there is more indirection.

=> Please fix log_vasprintf() once for all instead; that is the function not checking the malloc() return value.

marc-hb · 2022-12-19T23:52:53Z

Also, please use abort() instead of exit() in cases like this because it creates a useful coredump. Demo:

--- a/tools/logger/logger.c
+++ b/tools/logger/logger.c
@@ -86,6 +86,8 @@ static void usage(void)
        fprintf(stdout, "%s:\t -F filter\t\tUpdate trace filter, format: "
                "<level>=<comp1>[, <comp2>]\n",
                APP_NAME);
+
+       abort();
        exit(0);
 }

./tools/build_tools/logger/sof-logger   


Aborted (core dumped)

coredumpctl list
TIME                           PID  UID  GID SIG     COREFILE EXE                                                             SIZE
Mon 2022-12-19 23:45:19 UTC 236154 1005 1005 SIGABRT present  /home/me/SOF/sof/tools/build_tools/logger/sof-logger 16.8K

coredumpctl gdb 236154

(gdb) backtrace
#4  0x0000563e885ef7cb in usage () at /home/me/SOF/sof/tools/logger/logger.c:90
#5  0x0000563e885f02b4 in main (argc=2, argv=0x7fff61f5dea8) at /home/me/SOF/sof/tools/logger/logger.c:392

marc-hb · 2022-12-20T00:21:27Z

abort() is debug-friendly on Windows too:
https://learn.microsoft.com/en-us/cpp/c-runtime-library/reference/abort?view=msvc-170

When the program is compiled in debug mode, the message box displays options to Abort, Retry, or Ignore. If the user chooses Abort, the program terminates immediately and returns an exit code of 3. If the user chooses Retry, a debugger is invoked for just-in-time debugging, if available

kv2019i · 2022-12-20T10:15:24Z

@marc-hb wrote:

@@ -86,6 +86,8 @@ static void usage(void)
fprintf(stdout, "%s:\t -F filter\t\tUpdate trace filter, format: "
"=[, ]\n",
APP_NAME);
+
  abort();

Coredumping when wrong option passed is not really a good option right (in usage()). UPDATE: I guess this was just for the demo, right.

I'm not a fan of abort() in application code, it really should be reserved to system library / runtime code in most cases.

Let me check if I can clean this up.

kv2019i · 2022-12-20T12:30:17Z

@marc-hb wrote:

I see format_uid_raw() being used in at least one other place.

Morever format_uid_raw() is not even calling malloc() directly, there is more indirection.

=> Please fix log_vasprintf() once for all instead; that is the function not checking the malloc() return value.

I looked at this again and misc.c is clearly designed to handle out of memory cases, so I don't think it's appropriate to abort there.

In convert.c, "format_uid_raw() -> log_asprintf()", "asprintf_entry_text()" and "asprintf_uuid()" are all used to fill "pe->params[i]" which is later fed to printf().

On most systems this actually is safe as "(null)" is printed, but I guess this is not universally true and some ANSI C runtimes may segfault in this case. So I think the correct fix is to protect against printing a NULL. Let me modify the patch accordingly.

stale

lyakh · 2022-12-20T17:37:15Z

tools/logger/convert.c

you could just use a single static const char missing[] = "<missing>"; string and not set subst_mask

@lyakh Actually yes, that would be potentially cleaner. This still requires mucking with the subst_mask (which is a bit iffy as in theory subst_mask is not just to indicate how the object was allocated). Let me update the patch.

kv2019i · 2022-12-20T17:56:10Z

V3 update:

implemented @lyakh 's idea

tools/logger/convert.c

kv2019i · 2022-12-20T20:30:36Z

V4:

dropped the no-longer-needed check in V3, no other changes

marc-hb · 2022-12-20T23:26:16Z

https://sof-ci.01.org/sofpr/PR6848/build3091/devicetest/index.html has a worryingly large number of failures but they're all unrelated - sof-logger is not tested anymore on the main branch

marc-hb · 2022-12-21T00:06:58Z

I looked at this again and misc.c is clearly designed to handle out of memory cases, so I don't think it's appropriate to abort there.

I think you're making this much more complicated than it needs to be.

So we have f1() and f2() calling log_vasprintf() which invokes malloc() and does something stupid when malloc returns NULL.

I think you're saying "f1() does not trust log_vasprintf(), so let's make sure f2() does not either".

If malloc() starts failing in this tool (in practice: never) then all bets are off and log_vasprintf() should abort() ASAP. One-line fix.

kv2019i · 2022-12-21T07:35:56Z

@marc-hb wrote:

I think you're making this much more complicated than it needs to be.
[...]
If malloc() starts failing in this tool (in practice: never) then all bets are off and log_vasprintf() should abort() ASAP. One-line fix.

It's not just malloc fails, but asprintf_entry_text() (calling read_entry_from_ldc_file()) may return NULL for non-alloc failures as well.

paulstelian97 · 2022-12-21T08:45:49Z

tools/logger/convert.c

This feels sketchy. Do we even support strings in the parameters in the first place? I thought only stuff like %d (%x, %o) and %p are supported in parameters. I feel like this is a correctness issue. But then you would also have to scan the format string to "ban" the %s specifier which is more complicated.

strings not supported today and unlikely to be since this is all free with the Zephyr logger.

@paulstelian97 we do support strings. Here's example print for params when subst_mask is set:

params[0] 0x9E19E370 (subst_mas clear) params[1] 'dma-trace-task <2b972272-c5b1-4b7e-926f-0fc5cb4c4690>' (subst_mask set)

And matching log output:

[ 131.770828] ( 131.770828) c0 ll-schedule ./schedule/ll_schedule.c:513 INFO task add 0x9e19e370 dma-trace-task <2b972272-c5b1-4b7e-926f-0fc5cb4c4690>

It's still sketchy. Let me see if I can do a simpler change.

I'm confused how strings can be supported because sof-logger uses dictionary logging and I'm not aware of any support for strings in there. Zephyr logging I think is not based on dictionary logging by default?

@paulstelian97 I think Zephyr now has the string dictionary support, initially all the strings were baked into the Zephyr image (sorry, I don't know the Zephyr internals here). xtos config does not support %s strings as we cant do stuff like __func__ in our trace today, only strings are in the trace body via the dictionary.

Okay, I want to learn about the Zephyr logger and see if (after NXP migrates to fully Zephyr) we can use that. Right now we still have to use sof-logger due to still keeping the xtos builds (Zephyr isn't fully stable for us, there's a good few quirks left to fix)

@paulstelian97 @lgirdwood There's still code to handle "%s" but this is not used by any code in SOF FW and sof-logger emits a warning if one is seen. But we have two indirect usages of "%s", FW traces with "%pUx" and "%pQ" are converted to "%s" and the argument passed from FW (in raw log stream) is converted to a string that is passed as argument to (f)printf. And these steps can hit an alloc failure, or just missing conversion, leading to NULL being used.

But right, "plain %s" usage where you'd have %s used directly in FW code, is not there.

jsarha

Looks Ok. Then again being scared about a null parameter for format string and dealing with risking heap corruption is counter productive, as printf deals gracefully with NULL and even if it did not, finding the error would be easy. In case of heap corruption its not. But this is what it is these static analysis errors.

jsarha · 2022-12-21T08:47:02Z

tools/logger/convert.c

Mixing malloced pointers with static pointers is a bit scary, but I guess subst_mask is enough to make sure free is never called for "" .

@jsarha Just a note: the code is already doing that.

ok, looks good then.

lgirdwood

Lets fix the potential NULL issue today, we can always come back and circle back on other updates if needed.

kv2019i · 2022-12-21T10:58:50Z

V5 update:

rebased and simplified implementation to abort on plain alloc fails and only handle the ldc entry lookup fail with explicit error handling

Due to allocation failures, or invalid content in dictionary, "params" entries in "struct proc_ldc_entry" may be NULL. In print_entry_params(), the NULL entries may be passed as arguments to fprintf(). While e.g. glibc handles these without error, this is not guaranteed behaviour and may result in segfault on some platforms. Fix the issue by aborting program if allocation fails and explicitly handling the cases when asprintf_entry_text returns NULL. Signed-off-by: Kai Vehmanen <kai.vehmanen@linux.intel.com>

kv2019i · 2022-12-21T11:02:06Z

tools/logger/convert.c

+				pe->subst_mask |= 1 << i;
+			else
+				pe->params[i] = (uintptr_t)missing;
+


This branch is now only used for one trace in SOF:

./trace/trace.c:139: _TRACE_INV_ID, _TRACE_INV_ID, "Suppressed %u similar messages: %pQ",

But still, for correctness, the entry may not be found.

kv2019i requested review from akloniex and bkokoszx as code owners December 19, 2022 15:34

kv2019i requested review from juimonen, lgirdwood, lyakh and singalsu December 19, 2022 15:34

marc-hb mentioned this pull request Dec 19, 2022

fix Klocwork errors and criticals from logger sources #6738

Closed

kv2019i force-pushed the 202212-soflogger-uidraw-fail branch from 4cc5409 to 6b34135 Compare December 19, 2022 19:27

ranj063 approved these changes Dec 19, 2022

View reviewed changes

marc-hb previously requested changes Dec 19, 2022

View reviewed changes

marc-hb mentioned this pull request Dec 19, 2022

sof-logger: exit with error if malloc fails #6847

Merged

kv2019i force-pushed the 202212-soflogger-uidraw-fail branch from 6b34135 to 9f4805a Compare December 20, 2022 13:17

kv2019i changed the title ~~sof-logger: exit with error if format_uid_raw() fails~~ sof-logger: ensure NULL is not passed to printf/fprintf Dec 20, 2022

kv2019i requested a review from marc-hb December 20, 2022 13:18

kv2019i added the P1 Blocker bugs or important features label Dec 20, 2022

lgirdwood approved these changes Dec 20, 2022

View reviewed changes

lyakh reviewed Dec 20, 2022

View reviewed changes

kv2019i force-pushed the 202212-soflogger-uidraw-fail branch from 9f4805a to cee70a7 Compare December 20, 2022 17:55

kv2019i requested a review from lyakh December 20, 2022 18:09

marc-hb requested review from dbaluta and paulstelian97 December 20, 2022 20:01

kv2019i commented Dec 20, 2022

View reviewed changes

tools/logger/convert.c Outdated Show resolved Hide resolved

kv2019i force-pushed the 202212-soflogger-uidraw-fail branch from cee70a7 to 2e7f445 Compare December 20, 2022 20:29

lyakh approved these changes Dec 21, 2022

View reviewed changes

paulstelian97 reviewed Dec 21, 2022

View reviewed changes

jsarha approved these changes Dec 21, 2022

View reviewed changes

lgirdwood approved these changes Dec 21, 2022

View reviewed changes

kv2019i changed the title ~~sof-logger: ensure NULL is not passed to printf/fprintf~~ [DNM] sof-logger: ensure NULL is not passed to printf/fprintf Dec 21, 2022

kv2019i force-pushed the 202212-soflogger-uidraw-fail branch from 2e7f445 to adb3466 Compare December 21, 2022 10:55

kv2019i changed the title ~~[DNM] sof-logger: ensure NULL is not passed to printf/fprintf~~ sof-logger: ensure NULL is not passed to printf/fprintf Dec 21, 2022

kv2019i force-pushed the 202212-soflogger-uidraw-fail branch from adb3466 to fa81f62 Compare December 21, 2022 10:58

kv2019i requested a review from paulstelian97 December 21, 2022 10:58

kv2019i force-pushed the 202212-soflogger-uidraw-fail branch from fa81f62 to fce89c9 Compare December 21, 2022 11:00

kv2019i commented Dec 21, 2022

View reviewed changes

lgirdwood approved these changes Dec 21, 2022

View reviewed changes

lgirdwood merged commit 1a7a36a into thesofproject:main Dec 21, 2022

kv2019i mentioned this pull request Dec 21, 2022

[SOF2.4] Backport fixes PR6848, PR6858 and PR6862 #6871

Merged

sof-logger: ensure NULL is not passed to printf/fprintf #6848

sof-logger: ensure NULL is not passed to printf/fprintf #6848

Uh oh!

Conversation

kv2019i commented Dec 19, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

kv2019i commented Dec 19, 2022

Uh oh!

marc-hb left a comment • 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!

marc-hb commented Dec 19, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

marc-hb commented Dec 20, 2022

Uh oh!

kv2019i commented Dec 20, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

kv2019i commented Dec 20, 2022

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

kv2019i commented Dec 20, 2022

Uh oh!

Uh oh!

kv2019i commented Dec 20, 2022

Uh oh!

marc-hb commented Dec 20, 2022

Uh oh!

marc-hb commented Dec 21, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

kv2019i commented Dec 21, 2022

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

kv2019i Dec 21, 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!

jsarha left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

lgirdwood left a comment

Choose a reason for hiding this comment

Uh oh!

kv2019i commented Dec 21, 2022

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

7 participants

kv2019i commented Dec 19, 2022 •

edited

Loading

marc-hb left a comment •

edited

Loading

marc-hb commented Dec 19, 2022 •

edited

Loading

kv2019i commented Dec 20, 2022 •

edited

Loading

marc-hb commented Dec 21, 2022 •

edited

Loading

kv2019i Dec 21, 2022 •

edited

Loading