From: Baolin Wang <baolin.wang@linaro.org>
To: Thomas Gleixner <tglx@linutronix.de>
Cc: John Stultz <john.stultz@linaro.org>,
lkml <linux-kernel@vger.kernel.org>,
Richard Cochran <richardcochran@gmail.com>,
Prarit Bhargava <prarit@redhat.com>,
Ingo Molnar <mingo@kernel.org>,
Steven Rostedt <rostedt@goodmis.org>
Subject: Re: [PATCH 4/7] time: alarmtimer: Add the tracepoints for alarmtimer
Date: Wed, 30 Nov 2016 19:43:18 +0800 [thread overview]
Message-ID: <CAMz4kuJDWrJ7hb5Y-FAK5ioGy0CmjpC9pnp3NY7zi4mnVmMc1A@mail.gmail.com> (raw)
In-Reply-To: <alpine.DEB.2.20.1611291129130.4358@nanos>
On 29 November 2016 at 20:06, Thomas Gleixner <tglx@linutronix.de> wrote:
> On Mon, 28 Nov 2016, John Stultz wrote:
>
>> From: Baolin Wang <baolin.wang@linaro.org>
>>
>> For system debugging, we sometimes want to know who sets one
>> alarm timer, the time of the timer, when the timer started and
>> fired and so on. Thus adding tracepoints can help us trace the
>> alarmtimer information.
>>
>> For example, when we debug the system supend/resume, if the
>> system is always resumed by RTC alarm, we can find out which
>> process set the alarm timer to resume system by below trace log:
>>
>> ......
>>
>> Binder:3292_2-3304 [000] d..2 149.981123: alarmtimer_cancel:
>> alarmtimer:ffffffc1319a7800 type:REALTIME
>> expires:1325463120000000000 now:1325376810370370245
>>
>> Binder:3292_2-3304 [000] d..2 149.981136: alarmtimer_start:
>> alarmtimer:ffffffc1319a7800 type:REALTIME
>> expires:1325376840000000000 now:1325376810370384591
>>
>> Binder:3292_9-3953 [000] d..2 150.212991: alarmtimer_cancel:
>> alarmtimer:ffffffc1319a5a00 type:BOOTTIME
>> expires:179552000000 now:150154008122
>>
>> Binder:3292_9-3953 [000] d..2 150.213006: alarmtimer_start:
>> alarmtimer:ffffffc1319a5a00 type:BOOTTIME
>> expires:179551000000 now:150154025622
>>
>> ......
>>
>> system_server-3000 [002] ...1 162.701940: alarmtimer_suspend:
>> alarmtimer type:REALTIME expires:1325376839802714584
>> ......
>>
>> >From the trace log, we can find out the 'Binder:3292_2' process
>> set one alarm timer which resumes the system.
>
> To be honest. I have a hard time to figure out that Binder:3292_2 armed the
> timer.
>
> suspend: expires:1325376839802714584
> Binder start: expires:1325376840000000000
>
> That does not make any sense at all. And this is a result of how that
> suspend tracepoint got glued into alarmtimer_suspend():
>
>> @@ -222,7 +226,7 @@ static int alarmtimer_suspend(struct device *dev)
>> ktime_t min, now;
>> unsigned long flags;
>> struct rtc_device *rtc;
>> - int i;
>> + int i, min_type = -1;
>> int ret;
>>
>> spin_lock_irqsave(&freezer_delta_lock, flags);
>> @@ -247,8 +251,10 @@ static int alarmtimer_suspend(struct device *dev)
>> if (!next)
>> continue;
>> delta = ktime_sub(next->expires, base->gettime());
>> - if (!min.tv64 || (delta.tv64 < min.tv64))
>> + if (!min.tv64 || (delta.tv64 < min.tv64)) {
>> min = delta;
>> + min_type = i;
>> + }
>> }
>> if (min.tv64 == 0)
>> return 0;
>> @@ -264,6 +270,8 @@ static int alarmtimer_suspend(struct device *dev)
>> now = rtc_tm_to_ktime(tm);
>> now = ktime_add(now, min);
>>
>> + trace_alarmtimer_suspend(now, min_type);
>
> So first we calculate the relative expiry time from now, add it to the RTC
> and then print out the sum. That's utter crap especially if the first
> expiring timer is based on CLOCK_BOOTTIME. Even with CLOCK_REALTIME you do
> not get matching expiry time as you can see above.
>
> Now looking at the other possibility to arm the resume time: freezer_delta.
> That's even more undebuggable because the freezer time is stored as
> relative timeout without any type information. How is one supposed to map
> that back to an alarm timer start?
>
> Find below a revamped version (untested) of this including a proper written
> changelog.
Make sense. Thanks for your patch and I will help to test it.
--
Baolin.wang
Best Regards
next prev parent reply other threads:[~2016-11-30 11:43 UTC|newest]
Thread overview: 29+ messages / expand[flat|nested] mbox.gz Atom feed top
2016-11-28 22:35 [GIT PULL][PATCH 0/7] Timekeeping changes for 4.10 (take 2) John Stultz
2016-11-28 22:35 ` [PATCH 1/7] selftests/timers: Fix spelling mistake "Asyncrhonous" -> "Asynchronous" John Stultz
2016-11-29 17:10 ` [tip:timers/core] " tip-bot for Colin Ian King
2016-11-28 22:35 ` [PATCH 2/7] timekeeping: Ignore the bogus sleep time if pm_trace is enabled John Stultz
2016-11-29 7:19 ` Ingo Molnar
2016-11-29 9:38 ` Chen Yu
2016-11-29 17:10 ` [tip:timers/core] " tip-bot for Chen Yu
2016-11-28 22:35 ` [PATCH 3/7] timekeeping: clocksource_cyc2ns: Document intended range limitation John Stultz
2016-11-29 17:11 ` [tip:timers/core] timekeeping/clocksource_cyc2ns: " tip-bot for Chris Metcalf
2016-11-28 22:35 ` [PATCH 4/7] time: alarmtimer: Add the tracepoints for alarmtimer John Stultz
2016-11-29 7:23 ` Ingo Molnar
2016-11-29 8:23 ` Baolin Wang
2016-11-29 9:12 ` Ingo Molnar
2016-11-29 11:52 ` Baolin Wang
2016-11-29 12:06 ` Thomas Gleixner
2016-11-30 11:43 ` Baolin Wang [this message]
2016-12-01 2:34 ` Baolin Wang
2016-12-01 13:52 ` [tip:timers/core] alarmtimer: Add tracepoints for alarm timers tip-bot for Baolin Wang
2016-11-28 22:35 ` [PATCH 5/7] timekeeping: Add a fast and NMI safe boot clock John Stultz
2016-11-29 17:11 ` [tip:timers/core] " tip-bot for Joel Fernandes
2016-11-28 22:35 ` [PATCH 6/7] trace: Add an option for boot clock as trace clock John Stultz
2016-11-28 23:05 ` Steven Rostedt
2016-11-29 17:12 ` [tip:timers/core] " tip-bot for Joel Fernandes
2016-11-28 22:35 ` [PATCH 7/7] trace: Update documentation for mono, mono_raw and boot clock John Stultz
2016-11-28 23:07 ` Steven Rostedt
2016-11-29 7:26 ` Ingo Molnar
2016-11-29 16:10 ` Joel Fernandes
2016-11-29 16:11 ` Thomas Gleixner
2016-11-29 17:13 ` [tip:timers/core] " tip-bot for Joel Fernandes
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=CAMz4kuJDWrJ7hb5Y-FAK5ioGy0CmjpC9pnp3NY7zi4mnVmMc1A@mail.gmail.com \
--to=baolin.wang@linaro.org \
--cc=john.stultz@linaro.org \
--cc=linux-kernel@vger.kernel.org \
--cc=mingo@kernel.org \
--cc=prarit@redhat.com \
--cc=richardcochran@gmail.com \
--cc=rostedt@goodmis.org \
--cc=tglx@linutronix.de \
/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).