touch/sec: add more logs after touch suspend.android-s-v2-beta-3_r0.6android-12.1.0_r0.6android-12.1.0_r0.22android-12.1.0_r0.16android-gs-raviole-5.10-s-v2-beta-3android-gs-raviole-5.10-android12L

Example:
dump: #0: 11.824(0.99) D(184, 621).
dump: #0: 11.532(0.83) D(169, -560).
dump: #0: 11.266(0.58) D(88, 365).
dump: #0: 11.24(0.70) D(152, -546).
dump: i/o 0, comm 0, reset 0, longest 10.5.
dump: cnt 8, active 0, wet 0, palm 0.

Doc: go/no_touch_debug_1p
Test:
lshal debug android.hardware.dumpstate@1.0::IDumpstateDevice/default touch
Test: check logs after suspend and resume.
Bug: 203298201
Signed-off-by: Super Liu <supercjliu@google.com>
Change-Id: Idb914d17b91dd818a7d6131a8b46aef9188dee62

3 files changed, 165 insertions, 47 deletions

diff --git a/sec_ts.c b/sec_ts.c
index f1aaed8..98d2e9a 100644
--- a/sec_ts.c
+++ b/sec_ts.c
@@ -15,6 +15,11 @@ struct sec_ts_data *tsp_info;
 #include "sec_ts.h"
 #include <samsung/exynos_drm_connector.h>
 
+/* init the kfifo for debug used. */
+#define SEC_TS_DEBUG_KFIFO_LEN 4 /* must be power of 2. */
+DEFINE_KFIFO(debug_fifo, struct sec_ts_coordinate, SEC_TS_DEBUG_KFIFO_LEN);
+static struct sec_ts_coordinate last_coord[SEC_TS_DEBUG_KFIFO_LEN];
+
 /* Switch GPIO values */
 #define SEC_SWITCH_GPIO_VALUE_SLPI_MASTER	1
 #define SEC_SWITCH_GPIO_VALUE_AP_MASTER		0
@@ -442,8 +447,8 @@ static int sec_ts_read_internal(struct sec_ts_data *ts, u8 reg,
 					input_err(true, &ts->client->dev,
 						"%s: retry %d for 0x%02X size(%d) delay_us(%d)\n",
 						__func__, retry + 1, reg, len, spi_delay_us);
+						ts->comm_err_count++;
 				}
-				ts->comm_err_count++;
 
 				usleep_range(1 * 1000, 1 * 1000);
 				if (ts->power_status ==
@@ -703,6 +708,7 @@ skip_spi_read:
 	 */
 	if (ts->io_err_count >= SEC_TS_IO_RESET_CNT &&
 	    (ts->bus_refmask & SEC_TS_BUS_REF_FW_UPDATE) == 0) {
+		ts->hw_reset_count++;
 		ts->io_err_count = 0;
 		sec_ts_system_reset(ts, RESET_MODE_HW, false, true);
 	}
@@ -1850,6 +1856,100 @@ static void sec_ts_handle_lib_status_event(struct sec_ts_data *ts,
 }
 #endif
 
+#ifdef SEC_TS_DEBUG_KFIFO_LEN
+inline void sec_ts_kfifo_push_coord(struct sec_ts_data *ts, u8 slot)
+{
+	if (slot < MAX_SUPPORT_TOUCH_COUNT) {
+		/*
+		 * Use kfifo as circular buffer by skipping one element
+		 * when fifo is full.
+		 */
+		if (kfifo_is_full(&debug_fifo))
+			kfifo_skip(&debug_fifo);
+		kfifo_in(&debug_fifo, &ts->coord[slot], 1);
+	}
+}
+
+inline void sec_ts_kfifo_pop_all_coords(struct sec_ts_data *ts)
+{
+	/*
+	 * Keep coords without pop-out to support different timing
+	 * print-out by each caller.
+	 */
+	kfifo_out_peek(&debug_fifo, last_coord, kfifo_size(&debug_fifo));
+}
+
+inline void sec_ts_debug_dump(struct sec_ts_data *ts)
+{
+	int i;
+	s64 delta;
+	s64 sec_longest_duration;
+	u32 ms_longest_duration;
+	s64 sec_delta_down;
+	u32 ms_delta_down;
+	s64 sec_delta_duration;
+	u32 ms_delta_duration;
+	s32 px_delta_x, px_delta_y;
+	ktime_t current_time = ktime_get();
+
+	sec_longest_duration = div_u64_rem(ts->longest_duration,
+				MSEC_PER_SEC, &ms_longest_duration);
+
+	sec_ts_kfifo_pop_all_coords(ts);
+	for (i = 0 ; i < ARRAY_SIZE(last_coord) ; i++) {
+		if (last_coord[i].action == SEC_TS_COORDINATE_ACTION_NONE) {
+			input_dbg(true, &ts->client->dev,
+				"dump: #%d: N/A!\n", last_coord[i].id);
+			continue;
+		}
+		sec_delta_down = -1;
+		ms_delta_down = 0;
+		/* calculate the delta of finger down from current time. */
+		delta = ktime_ms_delta(current_time, last_coord[i].ktime_pressed);
+		if (delta > 0)
+			sec_delta_down = div_u64_rem(delta, MSEC_PER_SEC, &ms_delta_down);
+
+		/* calculate the delta of finger duration between finger up and down. */
+		sec_delta_duration = -1;
+		ms_delta_duration = 0;
+		px_delta_x = 0;
+		px_delta_y = 0;
+		if (last_coord[i].action == SEC_TS_COORDINATE_ACTION_RELEASE) {
+			delta = ktime_ms_delta(last_coord[i].ktime_released,
+					last_coord[i].ktime_pressed);
+			if (delta > 0) {
+				sec_delta_duration = div_u64_rem(delta, MSEC_PER_SEC,
+									&ms_delta_duration);
+				px_delta_x = last_coord[i].x - last_coord[i].x_pressed;
+				px_delta_y = last_coord[i].y - last_coord[i].y_pressed;
+			}
+		}
+		input_info(true, &ts->client->dev,
+			"dump: #%d: %lld.%u(%lld.%u) D(%d, %d).\n",
+			last_coord[i].id,
+			sec_delta_down, ms_delta_down,
+			sec_delta_duration, ms_delta_duration,
+			px_delta_x, px_delta_y);
+		input_dbg(true, &ts->client->dev,
+			"dump-dbg: #%d: (%d, %d) (%d, %d).\n",
+			last_coord[i].id,
+			last_coord[i].x_pressed, last_coord[i].y_pressed,
+			last_coord[i].x, last_coord[i].y);
+	}
+	input_info(true, &ts->client->dev,
+		"dump: i/o %u, comm %u, reset %u, longest %lld.%u.\n",
+		ts->io_err_count, ts->comm_err_count, ts->hw_reset_count,
+		sec_longest_duration, ms_longest_duration);
+	input_info(true, &ts->client->dev,
+		"dump: cnt %u, active %u, wet %u, palm %u.\n",
+		ts->pressed_count, ts->touch_count, ts->wet_count, ts->palm_count);
+}
+#else
+#define sec_ts_kfifo_push_coord(ts, slot) do {} while (0)
+#define sec_ts_kfifo_pop_all_coords(ts) do {} while (0)
+#define sec_ts_debug_dump(ts) do {} while (0)
+#endif /* #ifdef SEC_TS_DEBUG_KFIFO_LEN */
+
 static void sec_ts_handle_coord_event(struct sec_ts_data *ts,
 				struct sec_ts_event_coordinate *p_event_coord)
 {
@@ -1879,10 +1979,9 @@ static void sec_ts_handle_coord_event(struct sec_ts_data *ts,
 		ts->coord[t_id].minor = p_event_coord->minor *
 						ts->plat_data->mm2px;
 
-
 		if (!ts->coord[t_id].palm &&
 			(ts->coord[t_id].ttype == SEC_TS_TOUCHTYPE_PALM))
-			ts->coord[t_id].palm_count++;
+			ts->palm_count++;
 
 		ts->coord[t_id].palm =
 			(ts->coord[t_id].ttype == SEC_TS_TOUCHTYPE_PALM);
@@ -1914,17 +2013,14 @@ static void sec_ts_handle_coord_event(struct sec_ts_data *ts,
 		    (ts->coord[t_id].ttype ==
 		     SEC_TS_TOUCHTYPE_GLOVE)) {
 
-			if (ts->coord[t_id].action ==
-				SEC_TS_COORDINATE_ACTION_RELEASE) {
-
-				ktime_get_real_ts64(&ts->time_released[t_id]);
+			if (ts->coord[t_id].action == SEC_TS_COORDINATE_ACTION_RELEASE) {
+				s64 ms_delta;
 
-				if (ts->time_longest <
-					(ts->time_released[t_id].tv_sec -
-						ts->time_pressed[t_id].tv_sec))
-					ts->time_longest =
-					(ts->time_released[t_id].tv_sec
-					  - ts->time_pressed[t_id].tv_sec);
+				ts->coord[t_id].ktime_released = ktime_get();
+				ms_delta = ktime_ms_delta(ts->coord[t_id].ktime_released,
+							ts->coord[t_id].ktime_pressed);
+				if (ts->longest_duration < ms_delta)
+					ts->longest_duration = ms_delta;
 
 				if (ts->touch_count > 0)
 					ts->touch_count--;
@@ -1960,8 +2056,8 @@ static void sec_ts_handle_coord_event(struct sec_ts_data *ts,
 #endif
 			} else if (ts->coord[t_id].action ==
 					SEC_TS_COORDINATE_ACTION_PRESS) {
-				ktime_get_real_ts64(&ts->time_pressed[t_id]);
-
+				ts->coord[t_id].ktime_pressed = ktime_get();
+				ts->pressed_count++;
 				ts->touch_count++;
 				if ((ts->touch_count > 4) &&
 					(ts->check_multi == 0)) {
@@ -1970,6 +2066,8 @@ static void sec_ts_handle_coord_event(struct sec_ts_data *ts,
 				}
 				ts->all_finger_count++;
 
+				ts->coord[t_id].x_pressed = ts->coord[t_id].x;
+				ts->coord[t_id].y_pressed = ts->coord[t_id].y;
 				ts->max_z_value = max_t(unsigned int,
 							ts->coord[t_id].z,
 							ts->max_z_value);
@@ -2138,9 +2236,10 @@ static void sec_ts_handle_coord_event(struct sec_ts_data *ts,
 				__func__, t_id);
 
 	if (t_id < MAX_SUPPORT_TOUCH_COUNT + MAX_SUPPORT_HOVER_COUNT) {
+
 		if (ts->coord[t_id].action == SEC_TS_COORDINATE_ACTION_PRESS) {
 			input_dbg(false, &ts->client->dev,
-				"%s[P] tID: %d x: %d y: %d z: %d major: %d minor: %d tc: %d type: %X\n",
+				"%s[P] tID: %d x: %d y: %d z: %d major: %d minor: %d tc: %u type: %X\n",
 				ts->dex_name,
 				t_id, ts->coord[t_id].x,
 				ts->coord[t_id].y, ts->coord[t_id].z,
@@ -2151,8 +2250,9 @@ static void sec_ts_handle_coord_event(struct sec_ts_data *ts,
 
 		} else if (ts->coord[t_id].action ==
 			   SEC_TS_COORDINATE_ACTION_RELEASE) {
+			sec_ts_kfifo_push_coord(ts, t_id);
 			input_dbg(false, &ts->client->dev,
-				"%s[R] tID: %d mc: %d tc: %d lx: %d ly: %d v: %02X%02X cal: %02X(%02X) id(%d,%d) p: %d\n",
+				"%s[R] tID: %d mc: %d tc: %u lx: %d ly: %d v: %02X%02X cal: %02X(%02X) id(%d,%d)\n",
 				ts->dex_name,
 				t_id, ts->coord[t_id].mcount,
 				ts->touch_count,
@@ -2160,11 +2260,9 @@ static void sec_ts_handle_coord_event(struct sec_ts_data *ts,
 				ts->plat_data->img_version_of_ic[2],
 				ts->plat_data->img_version_of_ic[3],
 				ts->cal_status, ts->nv, ts->tspid_val,
-				ts->tspicid_val,
-				ts->coord[t_id].palm_count);
+				ts->tspicid_val);
 
 			ts->coord[t_id].mcount = 0;
-			ts->coord[t_id].palm_count = 0;
 		}
 	}
 }
@@ -2825,6 +2923,8 @@ static void sec_ts_read_vendor_event(struct sec_ts_data *ts,
 			input_info(true, &ts->client->dev,
 				"STATUS: palm: %d.\n",
 				status_data_1);
+				if (status_data_1)
+					ts->palm_count++;
 			break;
 
 		case SEC_TS_EVENT_STATUS_ID_FOD:
@@ -4760,6 +4860,7 @@ error_allocate_pdata:
 void sec_ts_unlocked_release_all_finger(struct sec_ts_data *ts)
 {
 	int i;
+	s64 ms_delta;
 
 	for (i = 0; i < MAX_SUPPORT_TOUCH_COUNT; i++) {
 		input_mt_slot(ts->input_dev, i);
@@ -4773,22 +4874,22 @@ void sec_ts_unlocked_release_all_finger(struct sec_ts_data *ts)
 			 SEC_TS_COORDINATE_ACTION_MOVE)) {
 
 			input_info(true, &ts->client->dev,
-				"%s: [RA] tID: %d mc: %d tc: %d v: %02X%02X cal: %02X(%02X) id(%d,%d) p: %d\n",
+				"%s: [RA] tID: %d mc: %d tc: %u v: %02X%02X cal: %02X(%02X) id(%d,%d)\n",
 				__func__, i,
 				ts->coord[i].mcount, ts->touch_count,
 				ts->plat_data->img_version_of_ic[2],
 				ts->plat_data->img_version_of_ic[3],
 				ts->cal_status, ts->nv, ts->tspid_val,
-				ts->tspicid_val, ts->coord[i].palm_count);
+				ts->tspicid_val);
 
-			ktime_get_real_ts64(&ts->time_released[i]);
+			ts->coord[i].ktime_released = ktime_get();
+			ms_delta = ktime_ms_delta(ts->coord[i].ktime_released,
+						ts->coord[i].ktime_pressed);
+			if (ts->longest_duration < ms_delta)
+				ts->longest_duration = ms_delta;
 
-			if (ts->time_longest <
-				(ts->time_released[i].tv_sec -
-				 ts->time_pressed[i].tv_sec))
-				ts->time_longest =
-					(ts->time_released[i].tv_sec -
-					 ts->time_pressed[i].tv_sec);
+			/* special case to push into kfifo during release all fingers. */
+			sec_ts_kfifo_push_coord(ts, i);
 		}
 
 #if IS_ENABLED(CONFIG_TOUCHSCREEN_OFFLOAD)
@@ -4799,8 +4900,6 @@ void sec_ts_unlocked_release_all_finger(struct sec_ts_data *ts)
 #endif
 		ts->coord[i].action = SEC_TS_COORDINATE_ACTION_RELEASE;
 		ts->coord[i].mcount = 0;
-		ts->coord[i].palm_count = 0;
-
 	}
 
 	input_mt_slot(ts->input_dev, 0);
@@ -5520,6 +5619,8 @@ static void sec_ts_suspend_work(struct work_struct *work)
 		tbn_release_bus(ts->tbn_register_mask);
 #endif
 	mutex_unlock(&ts->device_mutex);
+
+	sec_ts_debug_dump(ts);
 }
 
 static void sec_ts_resume_work(struct work_struct *work)
@@ -5530,6 +5631,12 @@ static void sec_ts_resume_work(struct work_struct *work)
 	int ret = 0;
 
 	input_info(true, &ts->client->dev, "%s\n", __func__);
+	ts->comm_err_count = 0;
+	ts->hw_reset_count = 0;
+	ts->longest_duration = 0;
+	ts->pressed_count = 0;
+	ts->palm_count = 0;
+	ts->wet_count = 0;
 
 	mutex_lock(&ts->device_mutex);
 
diff --git a/sec_ts.h b/sec_ts.h
index fbcdafd..f4ef114 100644
--- a/sec_ts.h
+++ b/sec_ts.h
@@ -35,6 +35,7 @@
 #include <linux/io.h>
 #include <linux/irq.h>
 #include <linux/kernel.h>
+#include <linux/kfifo.h>
 #include <linux/module.h>
 #include <drm/drm_bridge.h>
 #include <drm/drm_device.h>
@@ -873,9 +874,13 @@ struct sec_ts_coordinate {
 	u16 major;
 	u16 minor;
 	bool palm;
-	int palm_count;
 	u8 left_event;
 	bool grip;
+	/* for debug purpose. */
+	u16 x_pressed;	/* x coord on first down timing. */
+	u16 y_pressed;	/* y coord on first down timing. */
+	ktime_t ktime_pressed;
+	ktime_t ktime_released;
 };
 
 struct sec_ts_data {
@@ -905,11 +910,7 @@ struct sec_ts_data {
 			    * in CLOCK_MONOTONIC
 			    **/
 
-	struct timespec64 time_pressed[MAX_SUPPORT_TOUCH_COUNT +
-					MAX_SUPPORT_HOVER_COUNT];
-	struct timespec64 time_released[MAX_SUPPORT_TOUCH_COUNT +
-					MAX_SUPPORT_HOVER_COUNT];
-	long time_longest;
+	s64 longest_duration; /* ms unit */
 
 	u8 lowpower_mode;
 	u8 lowpower_status;
@@ -924,7 +925,7 @@ struct sec_ts_data {
 	struct completion bus_resumed;
 	struct completion boot_completed;
 
-	int touch_count;
+	unsigned int touch_count;	/* active touch slot(s). */
 	int tx_count;
 	int rx_count;
 	int io_burstmax;
@@ -1054,11 +1055,18 @@ struct sec_ts_data {
 	unsigned char ito_test[4];		/* ito panel tx/rx chanel */
 	unsigned char check_multi;
 	unsigned int multi_count;		/* multi touch count */
+	unsigned int palm_count;
 	unsigned int wet_count;			/* wet mode count */
 	unsigned int dive_count;		/* dive mode count */
-	unsigned int comm_err_count;	/* comm error count */
-	unsigned int io_err_count;	/* io error count */
-	unsigned int checksum_result;	/* checksum result */
+	unsigned int comm_err_count;		/* comm error count */
+	unsigned int io_err_count;		/* io error count */
+	unsigned int hw_reset_count;
+	/*
+	 * accumulated count of pressed
+	 * touch from resume to suspend.
+	 */
+	unsigned int pressed_count;
+	unsigned int checksum_result;		/* checksum result */
 	unsigned char module_id[4];
 	unsigned int all_finger_count;
 	unsigned int all_force_count;
@@ -1214,6 +1222,7 @@ struct sec_ts_plat_data {
 	u8 mm2px;
 };
 
+void sec_ts_debug_dump(struct sec_ts_data *ts);
 int sec_ts_stop_device(struct sec_ts_data *ts);
 int sec_ts_start_device(struct sec_ts_data *ts);
 int sec_ts_hw_reset(struct sec_ts_data *ts, bool wait_for_done);
diff --git a/sec_ts_fn.c b/sec_ts_fn.c
index 47200ea..1a07174 100644
--- a/sec_ts_fn.c
+++ b/sec_ts_fn.c
@@ -730,7 +730,7 @@ static ssize_t holding_time_store(struct device *dev,
 	struct sec_cmd_data *sec = dev_get_drvdata(dev);
 	struct sec_ts_data *ts = container_of(sec, struct sec_ts_data, sec);
 
-	ts->time_longest = 0;
+	ts->longest_duration = 0;
 
 	input_info(true, &ts->client->dev, "%s: clear\n", __func__);
 
@@ -743,10 +743,10 @@ static ssize_t holding_time_show(struct device *dev,
 	struct sec_cmd_data *sec = dev_get_drvdata(dev);
 	struct sec_ts_data *ts = container_of(sec, struct sec_ts_data, sec);
 
-	input_info(true, &ts->client->dev, "%s: %ld\n", __func__,
-		ts->time_longest);
+	input_info(true, &ts->client->dev, "%s: %lld ms\n",
+		__func__, ts->longest_duration);
 
-	return snprintf(buf, SEC_CMD_BUF_SIZE, "%ld", ts->time_longest);
+	return snprintf(buf, SEC_CMD_BUF_SIZE, "%lld ms", ts->longest_duration);
 }
 
 static ssize_t all_touch_count_show(struct device *dev,
@@ -8108,10 +8108,12 @@ static void force_touch_active(void *device_data)
 	if (sec->cmd_param[0] == 2) {
 		bus_ref = SEC_TS_BUS_REF_BUGREPORT;
 		active = (sec->cmd_param[1]) ? true : false;
-		if (active)
+		if (active) {
+			sec_ts_debug_dump(ts);
 			ts->bugreport_ktime_start = ktime_get();
-		else
+		} else {
 			ts->bugreport_ktime_start = 0;
+		}
 	} else {
 		active = sec->cmd_param[0];
 	}