[TEST]audio: component: don't inline functions that have logging

[aiChaoSONG]

Two reasons:

• If a function contains logging code, normally it means
  there are a lot of operations, so, better not to inline it.

• It is not possible for us to define a clear logging
  context for these functions when using zephyr logging utilities,
  because the header file contains these functions are included
  by other modules, and each has a logging context defined.

Signed-off-by: Chao Song [email protected]

[lgirdwood]

Can you give a size delta for some platforms before and after this change.

[marc-hb]

The technical problem here is not "inlining". Every recent compiler I recently tested for this ignores the inline keyword when generating code. The logging problem here is duplicating the same function across different .c files. This PR is a de-duplication PR. It will indeed block the compiler from inlining (unless LTO) but maybe the compiler wasn't inlining in the first place and it is unrelated to the logging context issue anyway.

I'm not sure all this de-duplication is required because:

1. The Zephyr logging API supports "shadowing" file-level contextes in specific functions:
   https://docs.zephyrproject.org/latest/reference/logging/index.html#logging-in-a-module

You have actually used that yourself in d0642b8#diff-eefa8737b3d4d1630d03548eb7e8185baf5c180cba1d5c27e689390c4a42ba53

2. If 1. does not work in some cases (why not?) or you really don't want to duplicate logging calls in a .h file, then you can de-duplicate only the logging calls, no need to de-duplicate the entire functions. For instance you can create a new, extern comp_err_invalid_version() function. So if the compiler wants to inline comp_cmd it still can and you're not affecting performance or size in any way.

If a function contains logging code, normally it means there are a lot of operations, so, better not to inline it.

You can have few operations and one error message.

[aiChaoSONG]

Can you give a size delta for some platforms before and after this change.

Size Delta for most of the platforms keeps unchanged except CNL, I think this is because our smarter compiler knows what to inline and what not to inline.

For CNL, the size decreased by 1k bytes.
firmware_binary_diff.txt

[aiChaoSONG]

@marc-hb I read the logging part zephyr doc, and I tried "shadowing" file-level contexts in specific functions, but finally I get something like this:

modules/sof/libmodules_sof.a(kpb.c.obj): In function `z_log_printf_arg_checker':
(.bss.__log_current_dynamic_data$24338+0x0): multiple definition of `__log_current_dynamic_data$24338'
modules/sof/libmodules_sof.a(pipeline-stream.c.obj):(.bss.__log_current_dynamic_data$24338+0x0): first defined here
modules/sof/libmodules_sof.a(idc.c.obj): In function `z_log_printf_arg_checker':
(.bss.__log_current_dynamic_data$24036+0x0): multiple definition of `__log_current_dynamic_data$24036'
modules/sof/libmodules_sof.a(pipeline-params.c.obj):(.bss.__log_current_dynamic_data$24036+0x0): first defined here
modules/sof/libmodules_sof.a(idc.c.obj):(.bss.__log_current_dynamic_data$24338+0x0): multiple definition of `__log_current_dynamic_data$24338'
modules/sof/libmodules_sof.a(pipeline-stream.c.obj):(.bss.__log_current_dynamic_data$24338+0x0): first defined here

and the changes are straitforward:

changes for logging

--- a/src/audio/component.c
+++ b/src/audio/component.c
@@ -21,6 +21,8 @@
 #include <stddef.h>
 #include <stdint.h>
 
+LOG_MODULE_REGISTER(component, LOG_LEVEL_INF);
+
 static SHARED_DATA struct comp_driver_list cd;

--- a/src/include/sof/audio/component_ext.h
+++ b/src/include/sof/audio/component_ext.h
@@ -74,6 +74,8 @@ static inline int comp_params_remote(struct comp_dev *dev,
 static inline int comp_params(struct comp_dev *dev,
                              struct sof_ipc_stream_params *params)
 {
+       LOG_MODULE_DECLARE(component, LOG_LEVEL_INF);
+
        int ret = 0;
 
        if (dev->is_shared && !cpu_is_me(dev->ipc_config.core)) {
@@ -107,6 +109,8 @@ static inline int comp_dai_get_hw_params(struct comp_dev *dev,
 static inline int comp_cmd(struct comp_dev *dev, int cmd, void *data,
                           int max_data_size)
 {
+       LOG_MODULE_DECLARE(component, LOG_LEVEL_INF);
+
        struct sof_ipc_ctrl_data *cdata = ASSUME_ALIGNED(data, 4);
 
        if (cmd == COMP_CMD_SET_DATA &&
@@ -166,6 +170,8 @@ static inline int comp_prepare(struct comp_dev *dev)
 /** See comp_ops::copy */
 static inline int comp_copy(struct comp_dev *dev)
 {
+       LOG_MODULE_DECLARE(component, LOG_LEVEL_INF);
+
        int ret = 0;
 
        assert(dev->drv->ops.copy);

diff --git a/src/include/sof/audio/component.h b/src/include/sof/audio/component.h
index aa87f2f38..cee72ca1b 100644
--- a/src/include/sof/audio/component.h
+++ b/src/include/sof/audio/component.h
@@ -152,6 +152,26 @@ enum {
 /** \brief Retrieves subid (comp id) from the component device */
 #define trace_comp_get_subid(comp_p) ((comp_p)->ipc_config.id)
 
+#ifdef __ZEPHYR__
+/* class (driver) level (no device object) tracing */
+#define comp_cl_err(drv_p, __e, ...) LOG_ERR(__e, ##__VA_ARGS__)
+
+#define comp_cl_warn(drv_p, __e, ...) LOG_WRN(__e, ##__VA_ARGS__)
+
+#define comp_cl_info(drv_p, __e, ...) LOG_INF(__e, ##__VA_ARGS__)
+
+#define comp_cl_dbg(drv_p, __e, ...) LOG_DBG(__e, ##__VA_ARGS__)
+
+/* device level tracing */
+#define comp_err(comp_p, __e, ...) LOG_ERR(__e, ##__VA_ARGS__)
+
+#define comp_warn(comp_p, __e, ...) LOG_WRN(__e, ##__VA_ARGS__)
+
+#define comp_info(comp_p, __e, ...) LOG_INF(__e, ##__VA_ARGS__)
+
+#define comp_dbg(comp_p, __e, ...) LOG_DBG(__e, ##__VA_ARGS__)
+
+#else
 /* class (driver) level (no device object) tracing */
 
 /** \brief Trace error message from component driver (no comp instance) */
@@ -208,6 +228,8 @@ enum {
 	trace_dev_dbg(trace_comp_get_tr_ctx, trace_comp_get_id,		\
 		      trace_comp_get_subid, comp_p, __e, ##__VA_ARGS__)
 
+#endif
+
 #define comp_perf_info(pcd, comp_p)					\
 	comp_info(comp_p, "perf comp_copy peak plat %d cpu %d",		\
 		  (uint32_t)((pcd)->plat_delta_peak),			\
@@ -739,6 +761,8 @@ static inline void comp_underrun(struct comp_dev *dev,
 				 struct comp_buffer *source,
 				 uint32_t copy_bytes)
 {
+	LOG_MODULE_DECLARE(component, LOG_LEVEL_INF);
+
 	int32_t bytes = (int32_t)audio_stream_get_avail_bytes(&source->stream) -
 			copy_bytes;
 
@@ -759,6 +783,7 @@ static inline void comp_underrun(struct comp_dev *dev,
 static inline void comp_overrun(struct comp_dev *dev, struct comp_buffer *sink,
 				uint32_t copy_bytes)
 {
+	LOG_MODULE_DECLARE(component, LOG_LEVEL_INF);
 	int32_t bytes = (int32_t)copy_bytes -
 			audio_stream_get_free_bytes(&sink->stream);
 

[marc-hb]

and the changes are straitforward:

I applied this patch, added the missing LOG_MODULE_DECLARE(component, LOG_LEVEL_INF); in .c files and everything builds and runs fine. This is with the current Zephyr commit feffe639a3f8 and SOF commit ae7e8da

[aiChaoSONG]

@marc-hb Did you try to build APL and CNL?

I re-clone a new zephyr with -c, firmware compiled. Seems my zephyr is too old.

[aiChaoSONG]

Look like This PR is a mistake, with a newer zephyr, issue resolved