binder: add trace at free transaction.
authorFrankie.Chang <Frankie.Chang@mediatek.com>
Wed, 11 Nov 2020 03:02:43 +0000 (11:02 +0800)
committerGreg Kroah-Hartman <gregkh@linuxfoundation.org>
Wed, 11 Nov 2020 07:20:44 +0000 (08:20 +0100)
Since the original trace_binder_transaction_received cannot
precisely present the real finished time of transaction, adding a
trace_binder_txn_latency_free at the point of free transaction
may be more close to it.

Signed-off-by: Frankie.Chang <Frankie.Chang@mediatek.com>
Acked-by: Todd Kjos <tkjos@google.com>
Link: https://lore.kernel.org/r/1605063764-12930-3-git-send-email-Frankie.Chang@mediatek.com
Signed-off-by: Greg Kroah-Hartman <gregkh@linuxfoundation.org>
drivers/android/binder.c
drivers/android/binder_trace.h

index abf47734f185bd68574a7f1b5f04089e80e8a6b7..20b08f52e788f6128090be854b7eaed2e92bdc68 100644 (file)
@@ -1486,6 +1486,20 @@ static void binder_free_txn_fixups(struct binder_transaction *t)
        }
 }
 
+static void binder_txn_latency_free(struct binder_transaction *t)
+{
+       int from_proc, from_thread, to_proc, to_thread;
+
+       spin_lock(&t->lock);
+       from_proc = t->from ? t->from->proc->pid : 0;
+       from_thread = t->from ? t->from->pid : 0;
+       to_proc = t->to_proc ? t->to_proc->pid : 0;
+       to_thread = t->to_thread ? t->to_thread->pid : 0;
+       spin_unlock(&t->lock);
+
+       trace_binder_txn_latency_free(t, from_proc, from_thread, to_proc, to_thread);
+}
+
 static void binder_free_transaction(struct binder_transaction *t)
 {
        struct binder_proc *target_proc = t->to_proc;
@@ -1496,6 +1510,8 @@ static void binder_free_transaction(struct binder_transaction *t)
                        t->buffer->transaction = NULL;
                binder_inner_proc_unlock(target_proc);
        }
+       if (trace_binder_txn_latency_free_enabled())
+               binder_txn_latency_free(t);
        /*
         * If the transaction has no target_proc, then
         * t->buffer->transaction has already been cleared.
@@ -3073,6 +3089,8 @@ err_get_secctx_failed:
        kfree(tcomplete);
        binder_stats_deleted(BINDER_STAT_TRANSACTION_COMPLETE);
 err_alloc_tcomplete_failed:
+       if (trace_binder_txn_latency_free_enabled())
+               binder_txn_latency_free(t);
        kfree(t);
        binder_stats_deleted(BINDER_STAT_TRANSACTION);
 err_alloc_t_failed:
index 6731c3cd814550ae9364e9fc071706baf04df5d4..8eeccdc64724b12b18e63a3ebfff8edf0c733ecb 100644 (file)
@@ -95,6 +95,35 @@ TRACE_EVENT(binder_wait_for_work,
                  __entry->thread_todo)
 );
 
+TRACE_EVENT(binder_txn_latency_free,
+       TP_PROTO(struct binder_transaction *t,
+                int from_proc, int from_thread,
+                int to_proc, int to_thread),
+       TP_ARGS(t, from_proc, from_thread, to_proc, to_thread),
+       TP_STRUCT__entry(
+               __field(int, debug_id)
+               __field(int, from_proc)
+               __field(int, from_thread)
+               __field(int, to_proc)
+               __field(int, to_thread)
+               __field(unsigned int, code)
+               __field(unsigned int, flags)
+       ),
+       TP_fast_assign(
+               __entry->debug_id = t->debug_id;
+               __entry->from_proc = from_proc;
+               __entry->from_thread = from_thread;
+               __entry->to_proc = to_proc;
+               __entry->to_thread = to_thread;
+               __entry->code = t->code;
+               __entry->flags = t->flags;
+       ),
+       TP_printk("transaction=%d from %d:%d to %d:%d flags=0x%x code=0x%x",
+                 __entry->debug_id, __entry->from_proc, __entry->from_thread,
+                 __entry->to_proc, __entry->to_thread, __entry->code,
+                 __entry->flags)
+);
+
 TRACE_EVENT(binder_transaction,
        TP_PROTO(bool reply, struct binder_transaction *t,
                 struct binder_node *target_node),