[RFC] trace: verify argument size

src/audio/host.c

@@ -238,7 +238,7 @@ static void host_dma_cb(void *arg, enum notify_id type, void *data)
 	struct host_data *hd = comp_get_drvdata(dev);
 	uint32_t bytes = next->elem.size;
 
-	comp_cl_dbg(&comp_host, "host_dma_cb() %p", (uintptr_t)&comp_host);
+	comp_cl_dbg(&comp_host, "host_dma_cb() %p", &comp_host);
 
 	/* update position */
 	host_update_position(dev, bytes);

src/audio/kpb.c

@@ -40,6 +40,7 @@
 #include <user/kpb.h>
 #include <user/trace.h>
 #include <errno.h>
+#include <limits.h>
 #include <stdbool.h>
 #include <stddef.h>
 #include <stdint.h>
@@ -59,7 +60,7 @@ DECLARE_SOF_UUID("kpb-task", kpb_task_uuid, 0xe50057a5, 0x8b27, 0x4db4,
 /* KPB private data, runtime data */
 struct comp_data {
 	enum kpb_state state; /**< current state of KPB component */
-	uint64_t state_log; /**< keeps record of KPB recent states */
+	uint32_t state_log; /**< keeps record of KPB recent states */
 	spinlock_t lock; /**< locking mechanism for read pointer calculations */
 	struct sof_kpb_config config;   /**< component configuration data */
 	struct history_data hd; /** data related to history buffer */
@@ -835,9 +836,16 @@ static int kpb_buffer_data(struct comp_dev *dev,
 		/* Are we stuck in buffering? */
 		current_time = platform_timer_get(timer);
 		if (timeout < current_time) {
-			comp_err(dev, "kpb_buffer_data(): timeout of %d [ms] (current state %d, state log %x)",
-				 current_time - timeout, kpb->state,
-				 kpb->state_log);
+			if (current_time - timeout <= UINT_MAX)
+				comp_err(dev,
+					 "kpb_buffer_data(): timeout of %u [ms] (current state %d, state log %x)",
+					 (unsigned int)(current_time - timeout), kpb->state,
+					 kpb->state_log);
+			else
+				comp_err(dev,
+					 "kpb_buffer_data(): timeout > %u [ms] (current state %d, state log %x)",
+					 UINT_MAX, kpb->state,
+					 kpb->state_log);
 			return -ETIME;
 		}
 
@@ -1153,17 +1161,18 @@ static enum task_state kpb_draining_task(void *arg)
 	size_t size_to_copy;
 	bool move_buffer = false;
 	uint32_t drained = 0;
-	uint64_t draining_time_start = 0;
-	uint64_t draining_time_end = 0;
+	uint64_t draining_time_start;
+	uint64_t draining_time_end;
+	uint64_t draining_time_ms;
 	enum comp_copy_type copy_type = COMP_COPY_NORMAL;
 	uint64_t drain_interval = draining_data->drain_interval;
 	uint64_t next_copy_time = 0;
-	uint64_t current_time = 0;
+	uint64_t current_time;
 	size_t period_bytes = 0;
 	size_t period_bytes_limit = draining_data->pb_limit;
 	struct timer *timer = timer_get();
 	size_t period_copy_start = platform_timer_get(timer);
-	size_t time_taken = 0;
+	size_t time_taken;
 	size_t *rt_stream_update = &draining_data->buffered_while_draining;
 	struct comp_data *kpb = comp_get_drvdata(draining_data->dev);
 	bool sync_mode_on = &draining_data->sync_mode_on;
@@ -1276,15 +1285,14 @@ static enum task_state kpb_draining_task(void *arg)
 	/* Reset host-sink copy mode back to unblocking */
 	comp_set_attribute(sink->sink, COMP_ATTR_COPY_TYPE, &copy_type);
 
-	comp_cl_info(&comp_kpb, "KPB: kpb_draining_task(), done. %u drained in %d ms",
-		     drained,
-		     (draining_time_end - draining_time_start)
-		     / clock_ms_to_ticks(PLATFORM_DEFAULT_CLOCK, 1));
-
-	/* If traces are disabled, prevent compile error from unused
-	 * variables.
-	 */
-	(void)(draining_time_end - draining_time_start);
+	draining_time_ms = (draining_time_end - draining_time_start)
+		/ clock_ms_to_ticks(PLATFORM_DEFAULT_CLOCK, 1);
+	if (draining_time_ms <= UINT_MAX)
+		comp_cl_info(&comp_kpb, "KPB: kpb_draining_task(), done. %u drained in %u ms",
+			     drained, (unsigned int)draining_time_ms);
+	else
+		comp_cl_info(&comp_kpb, "KPB: kpb_draining_task(), done. %u drained in > %u ms",
+			     drained, UINT_MAX);
 
 	pm_runtime_enable(PM_RUNTIME_DSP, PLATFORM_MASTER_CORE_ID);
 

src/audio/smart_amp/smart_amp.c

@@ -156,7 +156,7 @@ static inline int smart_amp_alloc_memory(struct smart_amp_data *sad,
 	mem_sz += size;
 
 	comp_dbg(dev, "[DSM] module:%p (%d bytes used)",
-		 (uintptr_t)hspk, mem_sz);
+		 hspk, mem_sz);
 
 	return 0;
 err:

src/audio/smart_amp/smart_amp_maxim_dsm.c

@@ -229,7 +229,7 @@ int smart_amp_flush(struct smart_amp_mod_struct_t *hspk, struct comp_dev *dev)
 	hspk->buf.ff_out.avail = 0;
 	hspk->buf.fb.avail = 0;
 
-	comp_dbg(dev, "[DSM] Reset (handle:%p)", (uintptr_t)hspk);
+	comp_dbg(dev, "[DSM] Reset (handle:%p)", hspk);
 
 	return 0;
 }

src/drivers/imx/interrupt.c

@@ -347,9 +347,8 @@ static inline void irq_handler(void *data, uint32_t line_index)
 
 		if (!--tries) {
 			tries = IRQ_MAX_TRIES;
-			tr_err(&irq_i_tr, "irq_handler(): IRQ storm, status "
-			       PRIx64,
-			       get_irqsteer_interrupts(line_index));
+			tr_err(&irq_i_tr, "irq_handler(): IRQ storm, status 0x%08x%08x",
+			       (uint32_t)(status >> 32), (uint32_t)status);
 		}
 	}
 

src/include/sof/trace/trace.h

@@ -170,18 +170,47 @@ void trace_log(bool send_atomic, const void *log_entry,
 unsupported_amount_of_params_in_trace_event\
 _thrown_from_macro_BASE_LOG_in_trace_h
 
+#define trace_check_size_uint32_0() do { } while (0)
+
+#define trace_check_size_uint32_1(a) do {				\
+	STATIC_ASSERT(sizeof(a) <= sizeof(uint32_t),			\
+	trace_parameter_too_large);					\
+} while (0)
+
+#define trace_check_size_uint32_2(a, b) do {				\
+	  trace_check_size_uint32_1(a);					\
+	  trace_check_size_uint32_1(b);					\
+} while (0)
+
+#define trace_check_size_uint32_3(a, b, c) do {				\
+	  trace_check_size_uint32_1(a);					\
+	  trace_check_size_uint32_1(b);					\
+	  trace_check_size_uint32_1(c);					\
+} while (0)
+
+#define trace_check_size_uint32_4(a, b, c, d) do {			\
+	  trace_check_size_uint32_1(a);					\
+	  trace_check_size_uint32_1(b);					\
+	  trace_check_size_uint32_1(c);					\
+	  trace_check_size_uint32_1(d);					\
+} while (0)
+
+#define trace_check_args(...) META_CONCAT(trace_check_size_uint32_,	\
+	META_COUNT_VARAGS_BEFORE_COMPILE(__VA_ARGS__))(__VA_ARGS__)
+
 #define _log_message(atomic, lvl, comp_class, ctx, id_1, id_2,		\
 		     format, ...)					\
 do {									\
 	_DECLARE_LOG_ENTRY(lvl, format, comp_class,			\
-			   PP_NARG(__VA_ARGS__));			\
-	STATIC_ASSERT(							\
-		_TRACE_EVENT_MAX_ARGUMENT_COUNT >=			\
+			META_COUNT_VARAGS_BEFORE_COMPILE(__VA_ARGS__));	\
+	STATIC_ASSERT(_TRACE_EVENT_MAX_ARGUMENT_COUNT >=		\
 			META_COUNT_VARAGS_BEFORE_COMPILE(__VA_ARGS__),	\
 		BASE_LOG_ASSERT_FAIL_MSG				\
 	);								\
+	trace_check_args(__VA_ARGS__);					\
 	trace_log(atomic, &log_entry, ctx, lvl, id_1, id_2,		\
-		  PP_NARG(__VA_ARGS__), ##__VA_ARGS__);			\
+		  META_COUNT_VARAGS_BEFORE_COMPILE(__VA_ARGS__),	\
+		  ##__VA_ARGS__);					\
 } while (0)
 
 #else /* CONFIG_LIBRARY */

src/lib/agent.c

@@ -29,6 +29,7 @@
 #include <ipc/topology.h>
 #include <ipc/trace.h>
 #include <user/trace.h>
+#include <limits.h>
 #include <stdbool.h>
 #include <stddef.h>
 #include <stdint.h>
@@ -66,9 +67,13 @@ static enum task_state validate(void *data)
 #endif
 
 	/* warning timeout */
-	if (delta > sa->warn_timeout)
-		tr_warn(&sa_tr, "validate(), ll drift detected, delta = %u",
-			delta);
+	if (delta > sa->warn_timeout) {
+		if (delta > UINT_MAX)
+			tr_warn(&sa_tr, "validate(), ll drift detected, delta > %u", UINT_MAX);
+		else
+			tr_warn(&sa_tr, "validate(), ll drift detected, delta = %u",
+				(unsigned int)delta);
+	}
 
 	/* update last_check to current */
 	sa->last_check = current;
@@ -82,7 +87,10 @@ void sa_init(struct sof *sof, uint64_t timeout)
 {
 	uint64_t ticks;
 
-	tr_info(&sa_tr, "sa_init(), timeout = %u", timeout);
+	if (timeout > UINT_MAX)
+		tr_warn(&sa_tr, "sa_init(), timeout > %u", UINT_MAX);
+	else
+		tr_info(&sa_tr, "sa_init(), timeout = %u", (unsigned int)timeout);
 
 	sof->sa = rzalloc(SOF_MEM_ZONE_SYS, SOF_MEM_FLAG_SHARED,
 			  SOF_MEM_CAPS_RAM, sizeof(*sof->sa));
@@ -97,8 +105,15 @@ void sa_init(struct sof *sof, uint64_t timeout)
 	atomic_init(&sof->sa->panic_cnt, 0);
 	sof->sa->panic_on_delay = true;
 
-	tr_info(&sa_tr, "sa_init(), ticks = %u, sof->sa->warn_timeout = %u, sof->sa->panic_timeout = %u",
-		ticks, sof->sa->warn_timeout, sof->sa->panic_timeout);
+	if (ticks > UINT_MAX || sof->sa->warn_timeout > UINT_MAX ||
+	    sof->sa->panic_timeout > UINT_MAX)
+		tr_info(&sa_tr,
+			"sa_init(), some of the values are > %u", UINT_MAX);
+	else
+		tr_info(&sa_tr,
+			"sa_init(), ticks = %u, sof->sa->warn_timeout = %u, sof->sa->panic_timeout = %u",
+			(unsigned int)ticks, (unsigned int)sof->sa->warn_timeout,
+			(unsigned int)sof->sa->panic_timeout);
 
 	schedule_task_init_ll(&sof->sa->work, SOF_UUID(agent_work_task_uuid),
 			      SOF_SCHEDULE_LL_TIMER,

src/lib/alloc.c

@@ -64,10 +64,10 @@ static void validate_memory(void *ptr, size_t size)
 
 	if (not_matching) {
 		tr_info(&mem_tr, "validate_memory() pointer: %p freed pattern not detected",
-			(uintptr_t)ptr);
+			ptr);
 	} else {
 		tr_err(&mem_tr, "validate_memory() freeing pointer: %p double free detected",
-		       (uintptr_t)ptr);
+		       ptr);
 	}
 }
 #endif
@@ -449,7 +449,7 @@ static void free_block(void *ptr)
 	heap = get_heap_from_ptr(ptr);
 	if (!heap) {
 		tr_err(&mem_tr, "free_block(): invalid heap = %p, cpu = %d",
-		       (uintptr_t)ptr, cpu_get_id());
+		       ptr, cpu_get_id());
 		return;
 	}
 
@@ -470,7 +470,7 @@ static void free_block(void *ptr)
 
 		/* not found */
 		tr_err(&mem_tr, "free_block(): invalid ptr = %p cpu = %d",
-		       (uintptr_t)ptr, cpu_get_id());
+		       ptr, cpu_get_id());
 		return;
 	}
 
@@ -890,7 +890,7 @@ static void _rfree_unlocked(void *ptr)
 	if (ptr >= (void *)cpu_heap->heap &&
 	    (char *)ptr < (char *)cpu_heap->heap + cpu_heap->size) {
 		tr_err(&mem_tr, "rfree(): attempt to free system heap = %p, cpu = %d",
-		       (uintptr_t)ptr, cpu_get_id());
+		       ptr, cpu_get_id());
 		panic(SOF_IPC_PANIC_MEM);
 	}
 

src/lib/dma.c

@@ -144,7 +144,7 @@ void dma_put(struct dma *dma)
 		}
 	}
 	tr_info(&dma_tr, "dma_put(), dma = %p, sref = %d",
-		(uintptr_t)dma, dma->sref);
+		dma, dma->sref);
 	platform_shared_commit(dma, sizeof(*dma));
 	spin_unlock(&dma->lock);
 }

src/schedule/dma_single_chan_domain.c

@@ -20,6 +20,7 @@
 #include <sof/schedule/task.h>
 #include <ipc/topology.h>
 #include <errno.h>
+#include <limits.h>
 #include <stdbool.h>
 #include <stddef.h>
 #include <stdint.h>
@@ -224,8 +225,14 @@ static int dma_single_chan_domain_register(struct ll_schedule_domain *domain,
 		register_needed = false;
 	}
 
-	tr_info(&ll_tr, "dma_single_chan_domain_register(): registering on channel with period %u",
-		channel->period);
+	if (channel->period <= UINT_MAX)
+		tr_info(&ll_tr,
+			"dma_single_chan_domain_register(): registering on channel with period %u",
+			(unsigned int)channel->period);
+	else
+		tr_info(&ll_tr,
+			"dma_single_chan_domain_register(): registering on channel with period > %u",
+			UINT_MAX);
 
 	/* register for interrupt */
 	ret = dma_single_chan_domain_irq_register(channel, data, handler, arg);

src/schedule/ll_schedule.c

@@ -27,6 +27,7 @@
 #include <ipc/topology.h>
 
 #include <errno.h>
+#include <limits.h>
 #include <stdbool.h>
 #include <stddef.h>
 #include <stdint.h>
@@ -120,8 +121,7 @@ static void schedule_ll_tasks_execute(struct ll_schedule_data *sch,
 			count = atomic_sub(&sch->num_tasks, 1);
 			if (count == 1)
 				sch->domain->registered[cpu] = false;
-			tr_info(&ll_tr, "task complete %p %pU", (uintptr_t)task,
-				task->uid);
+			tr_info(&ll_tr, "task complete %p %pU", task, task->uid);
 			tr_info(&ll_tr, "num_tasks %d total_num_tasks %d",
 				atomic_read(&sch->num_tasks),
 				atomic_read(&sch->domain->total_num_tasks));
@@ -342,9 +342,14 @@ static int schedule_ll_task(void *data, struct task *task, uint64_t start,
 
 	pdata = ll_sch_get_pdata(task);
 
-	tr_info(&ll_tr, "task add %p %pU", (uintptr_t)task, task->uid);
-	tr_info(&ll_tr, "task params pri %d flags %d start %u period %u",
-		task->priority, task->flags, start, period);
+	tr_info(&ll_tr, "task add %p %pU", task, task->uid);
+	if (start <= UINT_MAX && period <= UINT_MAX)
+		tr_info(&ll_tr, "task params pri %d flags %d start %u period %u",
+			task->priority, task->flags,
+			(unsigned int)start, (unsigned int)period);
+	else
+		tr_info(&ll_tr, "task params pri %d flags %d start or period > %u",
+			task->priority, task->flags, UINT_MAX);
 
 	pdata->period = period;
 
@@ -429,7 +434,7 @@ static int schedule_ll_task_cancel(void *data, struct task *task)
 
 	irq_local_disable(flags);
 
-	tr_info(&ll_tr, "task cancel %p %pU", (uintptr_t)task, task->uid);
+	tr_info(&ll_tr, "task cancel %p %pU", task, task->uid);
 
 	/* check to see if we are scheduled */
 	list_for_item(tlist, &sch->tasks) {

src/schedule/timer_domain.c

@@ -14,6 +14,7 @@
 #include <sof/schedule/schedule.h>
 #include <sof/schedule/task.h>
 #include <ipc/topology.h>
+#include <limits.h>
 #include <stdbool.h>
 #include <stddef.h>
 #include <stdint.h>
@@ -85,8 +86,12 @@ static inline void timer_report_delay(int id, uint64_t delay)
 		return;
 #endif
 
-	tr_err(&ll_tr, "timer_report_delay(): timer %d delayed by %d uS %d ticks",
-	       id, ll_delay_us, delay);
+	if (delay <= UINT_MAX)
+		tr_err(&ll_tr, "timer_report_delay(): timer %d delayed by %d uS %d ticks",
+		       id, ll_delay_us, (unsigned int)delay);
+	else
+		tr_err(&ll_tr, "timer_report_delay(): timer %d delayed by %d uS, ticks > %u",
+		       id, ll_delay_us, UINT_MAX);
 
 	/* Fix compile error when traces are disabled */
 	(void)ll_delay_us;
@@ -280,7 +285,11 @@ struct ll_schedule_domain *timer_domain_init(struct timer *timer, int clk,
 	struct ll_schedule_domain *domain;
 	struct timer_domain *timer_domain;
 
-	tr_info(&ll_tr, "timer_domain_init clk %d timeout %u", clk, timeout);
+	if (timeout <= UINT_MAX)
+		tr_info(&ll_tr, "timer_domain_init clk %d timeout %u", clk,
+			(unsigned int)timeout);
+	else
+		tr_info(&ll_tr, "timer_domain_init clk %d timeout > %u", clk, UINT_MAX);
 
 	domain = domain_init(SOF_SCHEDULE_LL_TIMER, clk, false,
 			     &timer_domain_ops);