[PATCH] Binder: Add timestamp and async from pid/tid to transaction record

From: Chuang Zhang
Date: Thu Apr 13 2023 - 06:41:45 EST


From: Chuang Zhang <zhangchuang3@xxxxxxxxxx>

This patch adds a timestamp field to the binder_transaction
structure to track the time consumed during transmission
when reading binder_transaction records.
Additionally, it records the from pid and tid of asynchronous
binder. This information is printed when reading binderfs
related nodes to assist with debugging.

Signed-off-by: Chuang Zhang <zhangchuang3@xxxxxxxxxx>
---
drivers/android/binder.c | 24 ++++++++++++++++++------
drivers/android/binder_internal.h | 3 +++
2 files changed, 21 insertions(+), 6 deletions(-)

diff --git a/drivers/android/binder.c b/drivers/android/binder.c
index fb56bfc45096..e79f548bcbac 100644
--- a/drivers/android/binder.c
+++ b/drivers/android/binder.c
@@ -66,6 +66,7 @@
#include <linux/syscalls.h>
#include <linux/task_work.h>
#include <linux/sizes.h>
+#include <linux/ktime.h>

#include <uapi/linux/android/binder.h>

@@ -3145,6 +3146,7 @@ static void binder_transaction(struct binder_proc *proc,
binder_stats_created(BINDER_STAT_TRANSACTION_COMPLETE);

t->debug_id = t_debug_id;
+ t->start_time = ktime_get();

if (reply)
binder_debug(BINDER_DEBUG_TRANSACTION,
@@ -3165,10 +3167,15 @@ static void binder_transaction(struct binder_proc *proc,
(u64)tr->data_size, (u64)tr->offsets_size,
(u64)extra_buffers_size);

- if (!reply && !(tr->flags & TF_ONE_WAY))
+ if (!reply && !(tr->flags & TF_ONE_WAY)) {
t->from = thread;
- else
+ t->async_from_pid = 0;
+ t->async_from_tid = 0;
+ } else {
t->from = NULL;
+ t->async_from_pid = thread->proc->pid;
+ t->async_from_tid = thread->pid;
+ }
t->sender_euid = task_euid(proc->tsk);
t->to_proc = target_proc;
t->to_thread = target_thread;
@@ -4963,6 +4970,8 @@ static int binder_thread_release(struct binder_proc *proc,
} else if (t->from == thread) {
t->from = NULL;
t = t->from_parent;
+ t->async_from_pid = 0;
+ t->async_from_tid = 0;
} else
BUG();
spin_unlock(&last_t->lock);
@@ -5930,17 +5939,20 @@ static void print_binder_transaction_ilocked(struct seq_file *m,
{
struct binder_proc *to_proc;
struct binder_buffer *buffer = t->buffer;
+ ktime_t current_time = ktime_get();

spin_lock(&t->lock);
to_proc = t->to_proc;
seq_printf(m,
- "%s %d: %pK from %d:%d to %d:%d code %x flags %x pri %ld r%d",
+ "%s %d: %pK from %d:%d to %d:%d code %x elapsed %lldms flags %x pri %ld r%d",
prefix, t->debug_id, t,
- t->from ? t->from->proc->pid : 0,
- t->from ? t->from->pid : 0,
+ t->from ? t->from->proc->pid : t->async_from_pid,
+ t->from ? t->from->pid : t->async_from_tid,
to_proc ? to_proc->pid : 0,
t->to_thread ? t->to_thread->pid : 0,
- t->code, t->flags, t->priority, t->need_reply);
+ t->code,
+ ktime_ms_delta(current_time, t->start_time),
+ t->flags, t->priority, t->need_reply);
spin_unlock(&t->lock);

if (proc != to_proc) {
diff --git a/drivers/android/binder_internal.h b/drivers/android/binder_internal.h
index 28ef5b3704b1..7e60f547abb6 100644
--- a/drivers/android/binder_internal.h
+++ b/drivers/android/binder_internal.h
@@ -528,6 +528,9 @@ struct binder_transaction {
long priority;
long saved_priority;
kuid_t sender_euid;
+ int async_from_pid;
+ int async_from_tid;
+ ktime_t start_time;
struct list_head fd_fixups;
binder_uintptr_t security_ctx;
/**
--
2.34.1