linux-mediatek.lists.infradead.org archive mirror
 help / color / mirror / Atom feed
* [PATCH v1 1/1] binder: transaction latency tracking for user build
@ 2020-02-05  6:52 Frankie Chang
  2020-02-05  9:36 ` Greg Kroah-Hartman
  0 siblings, 1 reply; 72+ messages in thread
From: Frankie Chang @ 2020-02-05  6:52 UTC (permalink / raw)
  To: Greg Kroah-Hartman, Todd Kjos, Martijn Coenen,
	Arve Hjønnevåg, Joel Fernandes, Christian Brauner
  Cc: Frankie Chang, Jian-Min.Liu, linux-mediatek, linux-kernel, wsd_upstream

Record start/end timestamp to binder transaction.
When transaction is completed or transaction is free,
it would be checked if transaction latency over threshold (2 sec),
if yes, printing related information for tracing.

Signed-off-by: Frankie Chang <Frankie.Chang@mediatek.com>
---
 drivers/android/Kconfig           |    8 +++
 drivers/android/binder.c          |  107 +++++++++++++++++++++++++++++++++++++
 drivers/android/binder_internal.h |    4 ++
 3 files changed, 119 insertions(+)

diff --git a/drivers/android/Kconfig b/drivers/android/Kconfig
index 6fdf2ab..7ba80eb 100644
--- a/drivers/android/Kconfig
+++ b/drivers/android/Kconfig
@@ -54,6 +54,14 @@ config ANDROID_BINDER_IPC_SELFTEST
 	  exhaustively with combinations of various buffer sizes and
 	  alignments.
 
+config BINDER_USER_TRACKING
+	bool "Android Binder transaction tracking"
+	help
+	  Used for track abnormal binder transaction which is over 2 seconds,
+	  when the transaction is done or be free, this transaction would be
+	  checked whether it executed overtime.
+	  If yes, printing out the detail info about it.
+
 endif # if ANDROID
 
 endmenu
diff --git a/drivers/android/binder.c b/drivers/android/binder.c
index e9bc9fc..5a352ee 100644
--- a/drivers/android/binder.c
+++ b/drivers/android/binder.c
@@ -76,6 +76,11 @@
 #include "binder_internal.h"
 #include "binder_trace.h"
 
+#ifdef CONFIG_BINDER_USER_TRACKING
+#include <linux/rtc.h>
+#include <linux/time.h>
+#endif
+
 static HLIST_HEAD(binder_deferred_list);
 static DEFINE_MUTEX(binder_deferred_lock);
 
@@ -591,8 +596,104 @@ struct binder_transaction {
 	 * during thread teardown
 	 */
 	spinlock_t lock;
+#ifdef CONFIG_BINDER_USER_TRACKING
+	struct timespec timestamp;
+	struct timeval tv;
+#endif
 };
 
+#ifdef CONFIG_BINDER_USER_TRACKING
+
+/*
+ * binder_print_delay - Output info of a delay transaction
+ * @t:          pointer to the over-time transaction
+ */
+static void binder_print_delay(struct binder_transaction *t)
+{
+	struct rtc_time tm;
+	struct timespec *startime;
+	struct timespec cur, sub_t;
+
+	ktime_get_ts(&cur);
+	startime = &t->timestamp;
+	sub_t = timespec_sub(cur, *startime);
+
+	/* if transaction time is over than 2 sec,
+	 * show timeout warning log.
+	 */
+	if (sub_t.tv_sec < 2)
+		return;
+
+	rtc_time_to_tm(t->tv.tv_sec, &tm);
+
+	spin_lock(&t->lock);
+	pr_info_ratelimited("%d: from %d:%d to %d:%d",
+			    t->debug_id,
+			    t->from ? t->from->proc->pid : 0,
+			    t->from ? t->from->pid : 0,
+			    t->to_proc ? t->to_proc->pid : 0,
+			    t->to_thread ? t->to_thread->pid : 0);
+	spin_unlock(&t->lock);
+
+	pr_info_ratelimited(" total %u.%03ld s code %u start %lu.%03ld android %d-%02d-%02d %02d:%02d:%02d.%03lu\n",
+			    (unsigned int)sub_t.tv_sec,
+			    (sub_t.tv_nsec / NSEC_PER_MSEC),
+			    t->code,
+			    (unsigned long)startime->tv_sec,
+			    (startime->tv_nsec / NSEC_PER_MSEC),
+			    (tm.tm_year + 1900), (tm.tm_mon + 1), tm.tm_mday,
+			    tm.tm_hour, tm.tm_min, tm.tm_sec,
+			    (unsigned long)(t->tv.tv_usec / USEC_PER_MSEC));
+}
+
+static void binder_log_entry_setup(struct binder_transaction_log_entry *e)
+{
+	ktime_get_ts(&e->timestamp);
+	do_gettimeofday(&e->tv);
+	e->tv.tv_sec -= (sys_tz.tz_minuteswest * 60);
+}
+
+static void timestamp_copy(struct binder_transaction *t,
+			   struct binder_transaction_log_entry *e)
+{
+	memcpy(&t->timestamp, &e->timestamp, sizeof(struct timespec));
+	memcpy(&t->tv, &e->tv, sizeof(struct timeval));
+}
+
+static void print_binder_transaction_ext(struct seq_file *m,
+					 struct binder_transaction *t)
+{
+	struct rtc_time tm;
+
+	rtc_time_to_tm(t->tv.tv_sec, &tm);
+	seq_printf(m,
+		   " start %lu.%06lu android %d-%02d-%02d %02d:%02d:%02d.%03lu",
+		   (unsigned long)t->timestamp.tv_sec,
+		   (t->timestamp.tv_nsec / NSEC_PER_USEC),
+		   (tm.tm_year + 1900), (tm.tm_mon + 1), tm.tm_mday,
+		   tm.tm_hour, tm.tm_min, tm.tm_sec,
+		   (unsigned long)(t->tv.tv_usec / USEC_PER_MSEC));
+}
+#else
+static void binder_print_delay(struct binder_transaction *t)
+{
+}
+
+static void binder_log_entry_setup(struct binder_transaction_log_entry *e)
+{
+}
+
+static void timestamp_copy(struct binder_transaction *t,
+			   struct binder_transaction_log_entry *e)
+{
+}
+
+static void print_binder_transaction_ext(struct seq_file *m,
+					 struct binder_transaction *t)
+{
+}
+#endif
+
 /**
  * struct binder_object - union of flat binder object types
  * @hdr:   generic object header
@@ -1927,6 +2028,7 @@ static void binder_free_transaction(struct binder_transaction *t)
 	 * If the transaction has no target_proc, then
 	 * t->buffer->transaction has already been cleared.
 	 */
+	binder_print_delay(t);
 	binder_free_txn_fixups(t);
 	kfree(t);
 	binder_stats_deleted(BINDER_STAT_TRANSACTION);
@@ -2872,6 +2974,8 @@ static void binder_transaction(struct binder_proc *proc,
 	e->offsets_size = tr->offsets_size;
 	strscpy(e->context_name, proc->context->name, BINDERFS_MAX_NAME);
 
+	binder_log_entry_setup(e);
+
 	if (reply) {
 		binder_inner_proc_lock(proc);
 		in_reply_to = thread->transaction_stack;
@@ -3058,6 +3162,7 @@ static void binder_transaction(struct binder_proc *proc,
 		return_error_line = __LINE__;
 		goto err_alloc_t_failed;
 	}
+	timestamp_copy(t, e);
 	INIT_LIST_HEAD(&t->fd_fixups);
 	binder_stats_created(BINDER_STAT_TRANSACTION);
 	spin_lock_init(&t->lock);
@@ -3496,6 +3601,7 @@ static void binder_transaction(struct binder_proc *proc,
 	kfree(tcomplete);
 	binder_stats_deleted(BINDER_STAT_TRANSACTION_COMPLETE);
 err_alloc_tcomplete_failed:
+	binder_print_delay(t);
 	kfree(t);
 	binder_stats_deleted(BINDER_STAT_TRANSACTION);
 err_alloc_t_failed:
@@ -5544,6 +5650,7 @@ static void print_binder_transaction_ilocked(struct seq_file *m,
 		   t->to_thread ? t->to_thread->pid : 0,
 		   t->code, t->flags, t->priority, t->need_reply);
 	spin_unlock(&t->lock);
+	print_binder_transaction_ext(m, t);
 
 	if (proc != to_proc) {
 		/*
diff --git a/drivers/android/binder_internal.h b/drivers/android/binder_internal.h
index ae99109..ea52c5d 100644
--- a/drivers/android/binder_internal.h
+++ b/drivers/android/binder_internal.h
@@ -131,6 +131,10 @@ struct binder_transaction_log_entry {
 	uint32_t return_error;
 	uint32_t return_error_param;
 	char context_name[BINDERFS_MAX_NAME + 1];
+#ifdef CONFIG_BINDER_USER_TRACKING
+	struct timespec timestamp;
+	struct timeval tv;
+#endif
 };
 
 struct binder_transaction_log {
-- 
1.7.9.5
_______________________________________________
Linux-mediatek mailing list
Linux-mediatek@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-mediatek

^ permalink raw reply related	[flat|nested] 72+ messages in thread

end of thread, other threads:[~2020-10-15 17:03 UTC | newest]

Thread overview: 72+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2020-02-05  6:52 [PATCH v1 1/1] binder: transaction latency tracking for user build Frankie Chang
2020-02-05  9:36 ` Greg Kroah-Hartman
2020-02-05 15:49   ` Joel Fernandes
2020-02-07  3:10     ` Frankie Chang
2020-02-07  3:17       ` Joel Fernandes
2020-02-07  6:28         ` Frankie Chang
2020-02-07 13:26           ` Joel Fernandes
2020-04-13  6:24             ` Frankie Chang
2020-04-15  5:37               ` [PATCH v2] " Frankie Chang
2020-04-15  5:37                 ` [PATCH v2 1/1] " Frankie Chang
2020-04-15 22:25                   ` Todd Kjos
2020-04-29  8:32                     ` Frankie Chang
2020-04-30  8:13                   ` Frankie Chang
2020-04-30  8:13                     ` [PATCH v3 1/1] " Frankie Chang
2020-04-30  8:50                       ` Greg Kroah-Hartman
2020-04-30  8:51                       ` Greg Kroah-Hartman
2020-05-07  8:10                         ` Frankie Chang
2020-05-07  8:10                           ` [PATCH v4 1/3] binder: move structs from core file to header file Frankie Chang
2020-05-07  8:10                           ` [PATCH v4 2/3] binder: add trace at free transaction Frankie Chang
2020-05-07  8:10                           ` [PATCH v4 3/3] binder: add transaction latency tracer Frankie Chang
2020-05-07  8:55                             ` Greg Kroah-Hartman
2020-05-11 12:32                               ` Frankie Chang
2020-06-10 12:23                               ` [PATCH v5] binder: transaction latency tracking for user build Frankie Chang
2020-06-10 12:23                                 ` [PATCH v5 1/3] binder: move structs from core file to header file Frankie Chang
2020-06-10 12:23                                 ` [PATCH v5 2/3] binder: add trace at free transaction Frankie Chang
2020-07-20 18:23                                   ` Todd Kjos
2020-07-23  2:47                                     ` Frankie Chang
2020-06-10 12:23                                 ` [PATCH v5 3/3] binder: add transaction latency tracer Frankie Chang
2020-07-20 18:56                                   ` Todd Kjos
2020-07-23  3:01                                     ` Frankie Chang
2020-07-02 13:25                                 ` [PATCH v5] binder: transaction latency tracking for user build Frankie Chang
2020-07-20 13:40                                   ` Frankie Chang
2020-07-28  3:19                                     ` [PATCH v6] " Frankie Chang
2020-07-28  3:19                                       ` [PATCH v6 1/3] binder: move structs from core file to header file Frankie Chang
2020-07-28  3:20                                       ` [PATCH v6 2/3] binder: add trace at free transaction Frankie Chang
2020-07-31 18:50                                         ` Todd Kjos
2020-08-03  3:11                                           ` Frankie Chang
2020-08-03 15:12                                             ` Todd Kjos
2020-08-04  2:45                                               ` Frankie Chang
2020-08-04 13:59                                                 ` [PATCH v7] binder: transaction latency tracking for user build Frankie Chang
2020-08-04 13:59                                                   ` [PATCH v7 1/3] binder: move structs from core file to header file Frankie Chang
2020-08-04 15:24                                                     ` Todd Kjos
2020-08-04 13:59                                                   ` [PATCH v7 2/3] binder: add trace at free transaction Frankie Chang
2020-08-04 15:26                                                     ` Todd Kjos
2020-08-04 13:59                                                   ` [PATCH v7 3/3] binder: add transaction latency tracer Frankie Chang
2020-08-04 15:28                                                     ` Todd Kjos
2020-09-07 14:41                                                     ` peter enderborg
2020-09-03 16:21                                                   ` [PATCH v7] binder: transaction latency tracking for user build Greg Kroah-Hartman
2020-09-07  6:49                                                     ` Frankie Chang
2020-09-07  7:00                                                       ` Greg Kroah-Hartman
2020-09-07 12:00                                                         ` [PATCH v8] " Frankie Chang
2020-09-07 12:00                                                           ` [PATCH v8 1/3] binder: move structs from core file to header file Frankie Chang
2020-09-07 12:00                                                           ` [PATCH v8 2/3] binder: add trace at free transaction Frankie Chang
2020-09-07 12:00                                                           ` [PATCH v8 3/3] binder: add transaction latency tracer Frankie Chang
2020-09-07 12:25                                                             ` Greg Kroah-Hartman
2020-09-07 13:51                                                               ` Frankie Chang
2020-09-07 14:09                                                                 ` Greg Kroah-Hartman
2020-09-08  5:38                                                                   ` Frankie Chang
2020-09-08 14:06                                                                     ` [PATCH v9] binder: transaction latency tracking for user build Frankie Chang
2020-09-08 14:06                                                                       ` [PATCH v9 1/3] binder: move structs from core file to header file Frankie Chang
2020-09-08 14:06                                                                       ` [PATCH v9 2/3] binder: add trace at free transaction Frankie Chang
2020-09-08 14:06                                                                       ` [PATCH v9 3/3] binder: add transaction latency tracer Frankie Chang
2020-09-16 17:38                                                                         ` Greg Kroah-Hartman
2020-10-15 17:02                                                                           ` [PATCH v10 " Frankie Chang
2020-10-15 17:02                                                                             ` [PATCH v10 1/3] binder: move structs from core file to header file Frankie Chang
2020-10-15 17:02                                                                             ` [PATCH v10 2/3] binder: add trace at free transaction Frankie Chang
2020-10-15 17:02                                                                             ` [PATCH v10 3/3] binder: add transaction latency tracer Frankie Chang
2020-09-16 15:29                                                                       ` [PATCH v9] binder: transaction latency tracking for user build Greg Kroah-Hartman
2020-09-07 12:24                                                           ` [PATCH v8] " Greg Kroah-Hartman
2020-07-28  3:20                                       ` [PATCH v6 3/3] binder: add transaction latency tracer Frankie Chang
2020-05-07 18:21                             ` [PATCH v4 " Todd Kjos
2020-05-11 12:35                               ` Frankie Chang

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).