audio: comp_ext: workaround XCC compatibility with zephyr logging

[aiChaoSONG]

Multiple use of static inline functions across different C
files will result in same symbol names defined in all of the
corresponding object files, because XCC compiler emits the
same symbol names based on the source file for those static
variables inside functions.

If Zephyr logging is used in SOF, we will have log context
redefinition issue with XCC due to above reason.

This patch workarounds the issue by removing the log calls
in static inline functions that are used across multiple C
files.

BugLink: zephyrproject-rtos/zephyr#43786

Signed-off-by: Chao Song chao.song@linux.intel.com

[kv2019i]

The first one we might just drop, but the perf_cnt might be more problematic. Maybe it's safer to ifdef both out just for Zephyr builds.

[aiChaoSONG]

Failure unrelated, @lgirdwood @kv2019i Ping?

[kv2019i]

Thanks @aiChaoSONG , looks good.

[lgirdwood]

@aiChaoSONG ping - can we get the comments added so this can be merged and tracked. Thanks

[aiChaoSONG]

@aiChaoSONG ping - can we get the comments added so this can be merged and tracked. Thanks

You mean add the comment in code, right?

The integration of zephyr log api into SOF now works well， please check the test result of #5411.
https://sof-ci.01.org/sofpr/PR5411/build12574/devicetest/, (failures are due to an empty logger trace, it is respected)

I am thinking to merge the commit in this PR to PR#5411, and close this one. So PR#5411 should be ready to review.

[aiChaoSONG]

@lgirdwood I added some comments in the code, and test failures are not related to this PR.

PR #5411 makes a lot of changes to the code, so we can merge this first, and I will rebase #5411

[gkbldcig]

Can one of the admins verify this patch?

[lyakh]

@aiChaoSONG could you please point out to the code that is causing zephyrproject-rtos/zephyr#43786 - i.e. how are you adding LOG_MODULE_REGISTER and LOG_MODULE_DECLARE?

[lgirdwood]

SOFCI TEST

[aiChaoSONG]

@lyakh This is the buggy commit, c3cfc52.
It is quite simple, I add LOG_MODULE_REGISTER(component, LOG_LEVEL_INF); to component.c, and add LOG_MODULE_DECLARE(component, LOG_LEVEL_INF); into the the function comp_params and comp_copy.

[lgirdwood]

@kkarask looks like CI got stuck, can you take a look. Thanks ! EDIT - ignore. I see the queue today, will check back later.

[aiChaoSONG]

The test on TGLU_UP_HDA_ZEPHYR is actually testing with IPC4, that's why we have errors. This because ipc-version.conf is left in /etc/modprobe.d by mistake.

Retested.

[lyakh]

@lyakh This is the buggy commit, c3cfc52. It is quite simple, I add LOG_MODULE_REGISTER(component, LOG_LEVEL_INF); to component.c, and add LOG_MODULE_DECLARE(component, LOG_LEVEL_INF); into the the function comp_params and comp_copy.

Thanks! So you add logging to component.h, component_ext.h and wait.h, but only component_ext.h is causing problems. Do we know why? wait.h is ok presumably because it only has one LOG_MODULE_DECLARE() in it, but component.h has two. Interesting, that that header isn't causing problems. I'm wondering if something like

#define comp_copy(dev, log) ({ \
	LOG_MODULE_DECLARE(log, LOG_LEVEL_INF); \
	__comp_copy(dev); \
})

would work with calling comp_comp(dev, copier) in copier.c etc. And renaming comp_copy to __comp_copy in component_ext.h of course

[aiChaoSONG]

Do we know why?

@lyakh Please check this issue zephyrproject-rtos/zephyr#43786, it is because a restriction of XCC, GCC is good. XCC cannot emit correct symbol if an inline function are called by multiple modules, for example, comp_params are called in idc.c, handler.c and pipeline-graph.c. With GCC only a single log context will be defined, but with XCC, three log contexts will be defined, and we will have log context redefinition issue in linking.

With this code, we are actually adding log context in functions(caller of comp_copy) in C file, actually this is not going to work, because we have a file level log context, they are going to collapse.

#define comp_copy(dev, log) ({ \
	LOG_MODULE_DECLARE(log, LOG_LEVEL_INF); \
	__comp_copy(dev); \
})

[lyakh]

With this code, we are actually adding log context in functions(caller of comp_copy) in C file, actually this is not going to work, because we have a file level log context, they are going to collapse.

@aiChaoSONG Are you sure? When LOG_MODULE_DECLARE() is added to inline functions in a header, that is included into that .c file, we get the same result - LOG_MODULE_DECLARE() in a function context, as long as e.g. comp_copy() isn't called more than once from the same function. But even then - is it really function context that matters or any block context? You can define static variables in internal code blocks in functions too.

[aiChaoSONG]

@lyakh I tested the code, I defined the comp_copy and comp_params macros, and pass log context to them at the caller. I got errors. For functions defined in header files, Zephyr requires LOG_MODULE_DECLARE being called explicitly, but with the macro, above condition is not satisfied, because we call LOG_MODULE_DECLARE in the caller.

Error Message

/home/chao/Music/sof/zephyrproject/zephyr/include/logging/log_core.h:258:13: error: '__log_level' undeclared (first use in this function)
  258 |  (_level <= __log_level) &&         \
      |             ^~~~~~~~~~~
/home/chao/Music/sof/zephyrproject/zephyr/include/logging/log_core.h:322:7: note: in expansion of macro 'Z_LOG_CONST_LEVEL_CHECK'
  322 |  if (!Z_LOG_CONST_LEVEL_CHECK(_level)) { \
      |       ^~~~~~~~~~~~~~~~~~~~~~~
/home/chao/Music/sof/zephyrproject/zephyr/include/logging/log_core.h:363:2: note: in expansion of macro 'Z_LOG2'
  363 |  Z_LOG2(_level, 0, __log_current_const_data, __log_current_dynamic_data, __VA_ARGS__)
      |  ^~~~~~
/home/chao/Music/sof/zephyrproject/zephyr/include/logging/log.h:40:25: note: in expansion of macro 'Z_LOG'
   40 | #define LOG_ERR(...)    Z_LOG(LOG_LEVEL_ERR, __VA_ARGS__)
      |                         ^~~~~
/home/chao/Music/sof/zephyr/../src/include/sof/audio/component.h:166:36: note: in expansion of macro 'LOG_ERR'
  166 | #define comp_err(comp_p, __e, ...) LOG_ERR(__e, ##__VA_ARGS__)
      |                                    ^~~~~~~
/home/chao/Music/sof/zephyr/../src/include/sof/audio/component_ext.h:98:5: note: in expansion of macro 'comp_err'
   98 |     comp_err(dev, "pcm params verification failed");
      |     ^~~~~~~~

[lyakh]

@lyakh I tested the code, I defined the comp_copy and comp_params macros, and pass log context to them at the caller. I got errors. For functions defined in header files, Zephyr requires LOG_MODULE_DECLARE being called explicitly, but with the macro, above condition is not satisfied, because we call LOG_MODULE_DECLARE in the caller.

Aah, right. The reason is, that with that code static variables are defined within caller functions, not at the file scope, so other functions cannot access them. Sorry for a non-working proposal. I guess I don't have a better idea for now then than what this PR is proposing!

[aiChaoSONG]

@lgirdwood are we good to merge this now? so I can continue the work of #5411