tracing: trace timer calls

Add tracing support for timer expiry and stop function callbacks,
enabling measurement of callback execution duration and facilitating
debugging of cases where callbacks take longer than expected.

Signed-off-by: Vijay Sharma <[email protected]>

Author: VijsharQC

include/zephyr/tracing/tracing.h

@@ -1911,6 +1911,30 @@
  */
 #define sys_port_trace_k_timer_status_sync_exit(timer, result)
 
+/**
+ * @brief Trace Timer expiry entry
+ * @param timer Timer object
+ */
+#define sys_port_trace_k_timer_expiry_enter(timer)
+
+/**
+ * @brief Trace Timer expiry exit
+ * @param timer Timer object
+ */
+#define sys_port_trace_k_timer_expiry_exit(timer)
+
+/**
+ * @brief Trace Timer stop function expiry entry
+ * @param timer Timer object
+ */
+#define sys_port_trace_k_timer_stop_fn_expiry_enter(timer)
+
+/**
+ * @brief Trace Timer stop function expiry exit
+ * @param timer Timer object
+ */
+#define sys_port_trace_k_timer_stop_fn_expiry_exit(timer)
+
 /** @} */ /* end of subsys_tracing_apis_timer */
 
 /**

kernel/timer.c

@@ -84,7 +84,13 @@ void z_timer_expiration_handler(struct _timeout *t)
 	if (timer->expiry_fn != NULL) {
 		/* Unlock for user handler. */
 		k_spin_unlock(&lock, key);
+
+		SYS_PORT_TRACING_OBJ_FUNC_ENTER(k_timer, expiry, timer);
+
 		timer->expiry_fn(timer);
+
+		SYS_PORT_TRACING_OBJ_FUNC_EXIT(k_timer, expiry, timer);
+
 		key = k_spin_lock(&lock);
 	}
 
@@ -207,7 +213,11 @@ void z_impl_k_timer_stop(struct k_timer *timer)
 	}
 
 	if (timer->stop_fn != NULL) {
+		SYS_PORT_TRACING_OBJ_FUNC_ENTER(k_timer, stop_fn_expiry, timer);
+
 		timer->stop_fn(timer);
+
+		SYS_PORT_TRACING_OBJ_FUNC_EXIT(k_timer, stop_fn_expiry, timer);
 	}
 
 	if (IS_ENABLED(CONFIG_MULTITHREADING)) {

subsys/tracing/ctf/tracing_ctf.h

@@ -180,6 +180,10 @@ extern "C" {
 	sys_trace_k_timer_status_sync_blocking(timer, timeout)
 #define sys_port_trace_k_timer_status_sync_exit(timer, result)			\
 	sys_trace_k_timer_status_sync_exit(timer, result)
+#define sys_port_trace_k_timer_expiry_enter(timer)
+#define sys_port_trace_k_timer_expiry_exit(timer)
+#define sys_port_trace_k_timer_stop_fn_expiry_enter(timer)
+#define sys_port_trace_k_timer_stop_fn_expiry_exit(timer)
 
 #define sys_port_trace_k_condvar_init(condvar, ret)
 #define sys_port_trace_k_condvar_signal_enter(condvar)

subsys/tracing/sysview/tracing_sysview.h

@@ -636,6 +636,11 @@ void sys_trace_thread_info(struct k_thread *thread);
 #define sys_port_trace_k_timer_status_sync_exit(timer, result)                                     \
 	SEGGER_SYSVIEW_RecordEndCallU32(TID_TIMER_STATUS_SYNC, (uint32_t)result)
 
+#define sys_port_trace_k_timer_expiry_enter(timer)
+#define sys_port_trace_k_timer_expiry_exit(timer)
+#define sys_port_trace_k_timer_stop_fn_expiry_enter(timer)
+#define sys_port_trace_k_timer_stop_fn_expiry_exit(timer)
+
 #define sys_port_trace_syscall_enter(id, name, ...)	\
 	SEGGER_SYSVIEW_RecordString(TID_SYSCALL, (const char *)#name)
 

subsys/tracing/test/tracing_string_format_test.c

@@ -349,6 +349,25 @@ void sys_trace_k_timer_status_sync_exit(struct k_timer *timer, uint32_t result)
 	TRACING_STRING("%s: %p\n", __func__, timer);
 }
 
+void sys_trace_k_timer_expiry_enter(struct k_timer *timer)
+{
+	TRACING_STRING("%s: %p\n", __func__, timer);
+}
+
+void sys_trace_k_timer_expiry_exit(struct k_timer *timer)
+{
+	TRACING_STRING("%s: %p\n", __func__, timer);
+}
+
+void sys_trace_k_timer_stop_fn_expiry_enter(struct k_timer *timer)
+{
+	TRACING_STRING("%s: %p\n", __func__, timer);
+}
+
+void sys_trace_k_timer_stop_fn_expiry_exit(struct k_timer *timer)
+{
+	TRACING_STRING("%s: %p\n", __func__, timer);
+}
 
 void sys_trace_k_heap_init(struct k_heap *h, void *mem, size_t bytes)
 {

subsys/tracing/test/tracing_test.h

@@ -429,6 +429,14 @@
 	sys_trace_k_timer_status_sync_blocking(timer)
 #define sys_port_trace_k_timer_status_sync_exit(timer, result)                                     \
 	sys_trace_k_timer_status_sync_exit(timer, result)
+#define sys_port_trace_k_timer_expiry_enter(timer)                                                 \
+	sys_trace_k_timer_expiry_enter(timer)
+#define sys_port_trace_k_timer_expiry_exit(timer)                                                  \
+	sys_trace_k_timer_expiry_exit(timer)
+#define sys_port_trace_k_timer_stop_fn_expiry_enter(timer)					   \
+	sys_trace_k_timer_stop_fn_expiry_enter(timer)
+#define sys_port_trace_k_timer_stop_fn_expiry_exit(timer)					   \
+	sys_trace_k_timer_stop_fn_expiry_exit(timer)
 
 #define sys_port_trace_k_event_init(event) sys_trace_k_event_init(event)
 #define sys_port_trace_k_event_post_enter(event, events, events_mask)   \
@@ -696,6 +704,10 @@ void sys_trace_k_timer_start(struct k_timer *timer, k_timeout_t duration, k_time
 void sys_trace_k_timer_stop(struct k_timer *timer);
 void sys_trace_k_timer_status_sync_blocking(struct k_timer *timer);
 void sys_trace_k_timer_status_sync_exit(struct k_timer *timer, uint32_t result);
+void sys_trace_k_timer_expiry_enter(struct k_timer *timer);
+void sys_trace_k_timer_expiry_exit(struct k_timer *timer);
+void sys_trace_k_timer_stop_fn_expiry_enter(struct k_timer *timer);
+void sys_trace_k_timer_stop_fn_expiry_exit(struct k_timer *timer);
 
 void sys_trace_k_event_init(struct k_event *event);
 void sys_trace_k_event_post_enter(struct k_event *event, uint32_t events, uint32_t events_mask);

subsys/tracing/user/tracing_user.c

@@ -75,6 +75,18 @@ void __weak sys_trace_gpio_fire_callbacks_enter_user(sys_slist_t *list, const st
 						     gpio_pin_t pins) {}
 void __weak sys_trace_gpio_fire_callback_user(const struct device *port,
 					      struct gpio_callback *callback) {}
+void __weak sys_trace_timer_init_user(struct k_timer *timer) {}
+void __weak sys_trace_timer_start_user(struct k_timer *timer, k_timeout_t duration,
+							    k_timeout_t period) {}
+void __weak sys_trace_timer_stop_user(struct k_timer *timer) {}
+void __weak sys_trace_timer_status_sync_enter_user(struct k_timer *timer) {}
+void __weak sys_trace_timer_status_sync_blocking_user(struct k_timer *timer,
+							    k_timeout_t timeout) {}
+void __weak sys_trace_timer_status_sync_exit_user(struct k_timer *timer, uint32_t result) {}
+void __weak sys_trace_timer_expiry_enter_user(struct k_timer *timer) {}
+void __weak sys_trace_timer_expiry_exit_user(struct k_timer *timer) {}
+void __weak sys_trace_timer_stop_fn_expiry_enter_user(struct k_timer *timer) {}
+void __weak sys_trace_timer_stop_fn_expiry_exit_user(struct k_timer *timer) {}
 
 void sys_trace_thread_create(struct k_thread *thread)
 {
@@ -314,3 +326,53 @@ void sys_trace_gpio_fire_callback(const struct device *port, struct gpio_callbac
 {
 	sys_trace_gpio_fire_callback_user(port, callback);
 }
+
+void sys_trace_timer_init(struct k_timer *timer)
+{
+	sys_trace_timer_init_user(timer);
+}
+
+void sys_trace_timer_start(struct k_timer *timer, k_timeout_t duration, k_timeout_t period)
+{
+	sys_trace_timer_start_user(timer, duration, period);
+}
+
+void sys_trace_timer_stop(struct k_timer *timer)
+{
+	sys_trace_timer_stop_user(timer);
+}
+
+void sys_trace_timer_status_sync_enter(struct k_timer *timer)
+{
+	sys_trace_timer_status_sync_enter_user(timer);
+}
+
+void sys_trace_timer_status_sync_blocking(struct k_timer *timer, k_timeout_t timeout)
+{
+	sys_trace_timer_status_sync_blocking_user(timer, timeout);
+}
+
+void sys_trace_timer_status_sync_exit(struct k_timer *timer, uint32_t result)
+{
+	sys_trace_timer_status_sync_exit_user(timer, result);
+}
+
+void sys_trace_timer_expiry_enter(struct k_timer *timer)
+{
+	sys_trace_timer_expiry_enter_user(timer);
+}
+
+void sys_trace_timer_expiry_exit(struct k_timer *timer)
+{
+	sys_trace_timer_expiry_exit_user(timer);
+}
+
+void sys_trace_timer_stop_fn_expiry_enter(struct k_timer *timer)
+{
+	sys_trace_timer_stop_fn_expiry_enter_user(timer);
+}
+
+void sys_trace_timer_stop_fn_expiry_exit(struct k_timer *timer)
+{
+	sys_trace_timer_stop_fn_expiry_exit_user(timer);
+}

subsys/tracing/user/tracing_user.h

@@ -49,6 +49,16 @@ void sys_trace_idle(void);
 void sys_trace_idle_exit(void);
 void sys_trace_sys_init_enter(const struct init_entry *entry, int level);
 void sys_trace_sys_init_exit(const struct init_entry *entry, int level, int result);
+void sys_trace_timer_init(struct k_timer *timer);
+void sys_trace_timer_start(struct k_timer *timer, k_timeout_t duration, k_timeout_t period);
+void sys_trace_timer_stop(struct k_timer *timer);
+void sys_trace_timer_status_sync_enter(struct k_timer *timer);
+void sys_trace_timer_status_sync_blocking(struct k_timer *timer, k_timeout_t timeout);
+void sys_trace_timer_status_sync_exit(struct k_timer *timer, uint32_t result);
+void sys_trace_timer_expiry_enter(struct k_timer *timer);
+void sys_trace_timer_expiry_exit(struct k_timer *timer);
+void sys_trace_timer_stop_fn_expiry_enter(struct k_timer *timer);
+void sys_trace_timer_stop_fn_expiry_exit(struct k_timer *timer);
 
 struct gpio_callback;
 typedef uint8_t gpio_pin_t;
@@ -367,12 +377,26 @@ void sys_trace_gpio_fire_callback_user(const struct device *port, struct gpio_ca
 #define sys_port_trace_k_mem_slab_free_enter(slab)
 #define sys_port_trace_k_mem_slab_free_exit(slab)
 
-#define sys_port_trace_k_timer_init(timer)
-#define sys_port_trace_k_timer_start(timer, duration, period)
-#define sys_port_trace_k_timer_stop(timer)
-#define sys_port_trace_k_timer_status_sync_enter(timer)
-#define sys_port_trace_k_timer_status_sync_blocking(timer, timeout)
-#define sys_port_trace_k_timer_status_sync_exit(timer, result)
+#define sys_port_trace_k_timer_init(timer)					\
+					sys_trace_timer_init(timer)
+#define sys_port_trace_k_timer_start(timer, duration, period)			\
+					sys_trace_timer_start(timer, duration, period)
+#define sys_port_trace_k_timer_stop(timer)					\
+					sys_trace_timer_stop(timer)
+#define sys_port_trace_k_timer_status_sync_enter(timer)				\
+					sys_trace_timer_status_sync_enter(timer)
+#define sys_port_trace_k_timer_status_sync_blocking(timer, timeout)		\
+					sys_trace_timer_status_sync_blocking(timer, timeout)
+#define sys_port_trace_k_timer_status_sync_exit(timer, result)			\
+					sys_trace_timer_status_sync_exit(timer, result)
+#define sys_port_trace_k_timer_expiry_enter(timer)				\
+					sys_trace_timer_expiry_enter(timer)
+#define sys_port_trace_k_timer_expiry_exit(timer)				\
+					sys_trace_timer_expiry_exit(timer)
+#define sys_port_trace_k_timer_stop_fn_expiry_enter(timer)			\
+					sys_trace_timer_stop_fn_expiry_enter(timer)
+#define sys_port_trace_k_timer_stop_fn_expiry_exit(timer)			\
+					sys_trace_timer_stop_fn_expiry_exit(timer)
 
 #define sys_port_trace_k_event_init(event)
 #define sys_port_trace_k_event_post_enter(event, events, events_mask)