From: Joel Fernandes <joel@joelfernandes.org>
To: Frankie Chang <Frankie.Chang@mediatek.com>
Cc: "Todd Kjos" <tkjos@android.com>,
wsd_upstream@mediatek.com,
"Greg Kroah-Hartman" <gregkh@linuxfoundation.org>,
linux-kernel@vger.kernel.org, "Arve Hjønnevåg" <arve@android.com>,
Jian-Min.Liu@mediatek.com, linux-mediatek@lists.infradead.org,
"Martijn Coenen" <maco@android.com>,
"Christian Brauner" <christian@brauner.io>
Subject: Re: [PATCH v1 1/1] binder: transaction latency tracking for user build
Date: Thu, 6 Feb 2020 22:17:59 -0500 [thread overview]
Message-ID: <20200207031759.GA121785@google.com> (raw)
In-Reply-To: <1581045023.22229.46.camel@mtkswgap22>
On Fri, Feb 07, 2020 at 11:10:23AM +0800, Frankie Chang wrote:
> On Wed, 2020-02-05 at 10:49 -0500, Joel Fernandes wrote:
> > On Wed, Feb 05, 2020 at 09:36:12AM +0000, Greg Kroah-Hartman wrote:
> > > On Wed, Feb 05, 2020 at 02:52:52PM +0800, Frankie Chang wrote:
> > > > 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));
> > > > +}
> > >
> > > Ick, why not use a tracepoint for this instead?
> > >
> > > And what is userspace supposed to do with this if they see it?
> >
> > Or another option is to implement this separately outside of binder.c using
> > register_trace_* on the existing binder tracepoints, similar to what say the
> > block tracer or preempt-off tracers do. Call it, say, "binder-latency tracer".
> >
> > That way all of this tracing code is in-kernel but outside of binder.c.
> >
> > thanks,
> >
> > - Joel
> >
> Time limitation of recording is the reason why we don't use tracepoint.
> In some situations, the exception is caused by a series of transactions
> interaction.
> Some abnormal transactions may be pending for a long time ago, they
> could not be recorded due to buffer limited.
register_trace_* does not use the trace buffer so I am not sure what you
mean. I am asking you to use tracepoints, not ftrace events.
thanks,
- Joel
_______________________________________________
Linux-mediatek mailing list
Linux-mediatek@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-mediatek
next prev parent reply other threads:[~2020-02-07 3:18 UTC|newest]
Thread overview: 72+ messages / expand[flat|nested] mbox.gz Atom feed top
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 [this message]
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
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=20200207031759.GA121785@google.com \
--to=joel@joelfernandes.org \
--cc=Frankie.Chang@mediatek.com \
--cc=Jian-Min.Liu@mediatek.com \
--cc=arve@android.com \
--cc=christian@brauner.io \
--cc=gregkh@linuxfoundation.org \
--cc=linux-kernel@vger.kernel.org \
--cc=linux-mediatek@lists.infradead.org \
--cc=maco@android.com \
--cc=tkjos@android.com \
--cc=wsd_upstream@mediatek.com \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
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).