platform/chrome: sensorhub: Add trace events for sample
authorGwendal Grignou <gwendal@chromium.org>
Fri, 14 May 2021 00:57:33 +0000 (17:57 -0700)
committerGreg Kroah-Hartman <gregkh@linuxfoundation.org>
Sun, 26 Sep 2021 12:08:58 +0000 (14:08 +0200)
[ Upstream commit d453ceb6549af8798913de6a20444cb7200fdb69 ]

Add trace event to report samples and their timestamp coming from the
EC. It allows to check if the timestamps are correct and the filter is
working correctly without introducing too much latency.

To enable these events:

cd /sys/kernel/debug/tracing/
echo 1 > events/cros_ec/enable
echo 0 > events/cros_ec/cros_ec_request_start/enable
echo 0 > events/cros_ec/cros_ec_request_done/enable
echo 1 > tracing_on
cat trace_pipe
Observe event flowing:
irq/105-chromeo-95      [000] ....   613.659758: cros_ec_sensorhub_timestamp: ...
irq/105-chromeo-95      [000] ....   613.665219: cros_ec_sensorhub_filter: dx: ...

Signed-off-by: Gwendal Grignou <gwendal@chromium.org>
Signed-off-by: Enric Balletbo i Serra <enric.balletbo@collabora.com>
Signed-off-by: Sasha Levin <sashal@kernel.org>
drivers/platform/chrome/Makefile
drivers/platform/chrome/cros_ec_sensorhub_ring.c
drivers/platform/chrome/cros_ec_trace.h

index 41baccba033f732efa26b1bd46099b1c8076e57a..f901d2e43166c339971aed719f8d749026dd4ad1 100644 (file)
@@ -20,7 +20,7 @@ obj-$(CONFIG_CROS_EC_CHARDEV)         += cros_ec_chardev.o
 obj-$(CONFIG_CROS_EC_LIGHTBAR)         += cros_ec_lightbar.o
 obj-$(CONFIG_CROS_EC_VBC)              += cros_ec_vbc.o
 obj-$(CONFIG_CROS_EC_DEBUGFS)          += cros_ec_debugfs.o
-cros-ec-sensorhub-objs                 := cros_ec_sensorhub.o cros_ec_sensorhub_ring.o
+cros-ec-sensorhub-objs                 := cros_ec_sensorhub.o cros_ec_sensorhub_ring.o cros_ec_trace.o
 obj-$(CONFIG_CROS_EC_SENSORHUB)                += cros-ec-sensorhub.o
 obj-$(CONFIG_CROS_EC_SYSFS)            += cros_ec_sysfs.o
 obj-$(CONFIG_CROS_USBPD_LOGGER)                += cros_usbpd_logger.o
index 8921f24e83baca469398a25237b40ee9338bceb6..98e37080f760913ecdbeb53f611ce71cfbecbc7f 100644 (file)
@@ -17,6 +17,8 @@
 #include <linux/sort.h>
 #include <linux/slab.h>
 
+#include "cros_ec_trace.h"
+
 /* Precision of fixed point for the m values from the filter */
 #define M_PRECISION BIT(23)
 
@@ -291,6 +293,7 @@ cros_ec_sensor_ring_ts_filter_update(struct cros_ec_sensors_ts_filter_state
                state->median_m = 0;
                state->median_error = 0;
        }
+       trace_cros_ec_sensorhub_filter(state, dx, dy);
 }
 
 /**
@@ -427,6 +430,11 @@ cros_ec_sensor_ring_process_event(struct cros_ec_sensorhub *sensorhub,
                        if (new_timestamp - *current_timestamp > 0)
                                *current_timestamp = new_timestamp;
                }
+               trace_cros_ec_sensorhub_timestamp(in->timestamp,
+                                                 fifo_info->timestamp,
+                                                 fifo_timestamp,
+                                                 *current_timestamp,
+                                                 now);
        }
 
        if (in->flags & MOTIONSENSE_SENSOR_FLAG_ODR) {
@@ -460,6 +468,12 @@ cros_ec_sensor_ring_process_event(struct cros_ec_sensorhub *sensorhub,
 
        /* Regular sample */
        out->sensor_id = in->sensor_num;
+       trace_cros_ec_sensorhub_data(in->sensor_num,
+                                    fifo_info->timestamp,
+                                    fifo_timestamp,
+                                    *current_timestamp,
+                                    now);
+
        if (*current_timestamp - now > 0) {
                /*
                 * This fix is needed to overcome the timestamp filter putting
index f744b21bc655f7e922b1b4cf027e0d31ba52c19f..f50b9f9b861065213a9b21d4d8048f05ceed147e 100644 (file)
@@ -15,6 +15,7 @@
 #include <linux/types.h>
 #include <linux/platform_data/cros_ec_commands.h>
 #include <linux/platform_data/cros_ec_proto.h>
+#include <linux/platform_data/cros_ec_sensorhub.h>
 
 #include <linux/tracepoint.h>
 
@@ -70,6 +71,99 @@ TRACE_EVENT(cros_ec_request_done,
                  __entry->retval)
 );
 
+TRACE_EVENT(cros_ec_sensorhub_timestamp,
+           TP_PROTO(u32 ec_sample_timestamp, u32 ec_fifo_timestamp, s64 fifo_timestamp,
+                    s64 current_timestamp, s64 current_time),
+       TP_ARGS(ec_sample_timestamp, ec_fifo_timestamp, fifo_timestamp, current_timestamp,
+               current_time),
+       TP_STRUCT__entry(
+               __field(u32, ec_sample_timestamp)
+               __field(u32, ec_fifo_timestamp)
+               __field(s64, fifo_timestamp)
+               __field(s64, current_timestamp)
+               __field(s64, current_time)
+               __field(s64, delta)
+       ),
+       TP_fast_assign(
+               __entry->ec_sample_timestamp = ec_sample_timestamp;
+               __entry->ec_fifo_timestamp = ec_fifo_timestamp;
+               __entry->fifo_timestamp = fifo_timestamp;
+               __entry->current_timestamp = current_timestamp;
+               __entry->current_time = current_time;
+               __entry->delta = current_timestamp - current_time;
+       ),
+       TP_printk("ec_ts: %12lld, ec_fifo_ts: %12lld, fifo_ts: %12lld, curr_ts: %12lld, curr_time: %12lld, delta %12lld",
+                 __entry->ec_sample_timestamp,
+               __entry->ec_fifo_timestamp,
+               __entry->fifo_timestamp,
+               __entry->current_timestamp,
+               __entry->current_time,
+               __entry->delta
+       )
+);
+
+TRACE_EVENT(cros_ec_sensorhub_data,
+           TP_PROTO(u32 ec_sensor_num, u32 ec_fifo_timestamp, s64 fifo_timestamp,
+                    s64 current_timestamp, s64 current_time),
+       TP_ARGS(ec_sensor_num, ec_fifo_timestamp, fifo_timestamp, current_timestamp, current_time),
+       TP_STRUCT__entry(
+               __field(u32, ec_sensor_num)
+               __field(u32, ec_fifo_timestamp)
+               __field(s64, fifo_timestamp)
+               __field(s64, current_timestamp)
+               __field(s64, current_time)
+               __field(s64, delta)
+       ),
+       TP_fast_assign(
+               __entry->ec_sensor_num = ec_sensor_num;
+               __entry->ec_fifo_timestamp = ec_fifo_timestamp;
+               __entry->fifo_timestamp = fifo_timestamp;
+               __entry->current_timestamp = current_timestamp;
+               __entry->current_time = current_time;
+               __entry->delta = current_timestamp - current_time;
+       ),
+       TP_printk("ec_num: %4d, ec_fifo_ts: %12lld, fifo_ts: %12lld, curr_ts: %12lld, curr_time: %12lld, delta %12lld",
+                 __entry->ec_sensor_num,
+               __entry->ec_fifo_timestamp,
+               __entry->fifo_timestamp,
+               __entry->current_timestamp,
+               __entry->current_time,
+               __entry->delta
+       )
+);
+
+TRACE_EVENT(cros_ec_sensorhub_filter,
+           TP_PROTO(struct cros_ec_sensors_ts_filter_state *state, s64 dx, s64 dy),
+       TP_ARGS(state, dx, dy),
+       TP_STRUCT__entry(
+               __field(s64, dx)
+               __field(s64, dy)
+               __field(s64, median_m)
+               __field(s64, median_error)
+               __field(s64, history_len)
+               __field(s64, x)
+               __field(s64, y)
+       ),
+       TP_fast_assign(
+               __entry->dx = dx;
+               __entry->dy = dy;
+               __entry->median_m = state->median_m;
+               __entry->median_error = state->median_error;
+               __entry->history_len = state->history_len;
+               __entry->x = state->x_offset;
+               __entry->y = state->y_offset;
+       ),
+       TP_printk("dx: %12lld. dy: %12lld median_m: %12lld median_error: %12lld len: %d x: %12lld y: %12lld",
+                 __entry->dx,
+               __entry->dy,
+               __entry->median_m,
+               __entry->median_error,
+               __entry->history_len,
+               __entry->x,
+               __entry->y
+       )
+);
+
 
 #endif /* _CROS_EC_TRACE_H_ */