Re: [PATCH 4/8] time: Condense timekeeper.xtime into xtime_sec

Re: [PATCH 4/8] time: Condense timekeeper.xtime into xtime_sec

[Andreas Schwab]

John Stultz <john.stultz@linaro.org> writes:

> The timekeeper struct has a xtime_nsec, which keeps the
> sub-nanosecond remainder.  This ends up being somewhat
> duplicative of the timekeeper.xtime.tv_nsec value, and we
> have to do extra work to keep them apart, copying the full
> nsec portion out and back in over and over.
>
> This patch simplifies some of the logic by taking the timekeeper
> xtime value and splitting it into timekeeper.xtime_sec and
> reuses the timekeeper.xtime_nsec for the sub-second portion
> (stored in higher res shifted nanoseconds).
>
> This simplifies some of the accumulation logic. And will
> allow for more accurate timekeeping once the vsyscall code
> is updated to use the shifted nanosecond remainder.

This (together with b44d50d "time: Fix casting issue in tk_set_xtime and
tk_xtime_add") is causing resume to hang on the iBook (PowerBook6,7).
The fact that the add-on commit is needed to uncover the bug might give
a hint, but I'm unable to decipher it.

Andreas.

-- 
Andreas Schwab, schwab@linux-m68k.org
GPG Key fingerprint = 58CA 54C7 6D53 942B 1756  01D3 44D5 214B 8276 4ED5
"And now for something completely different."

Re: [PATCH 4/8] time: Condense timekeeper.xtime into xtime_sec

[John Stultz]

On 08/19/2012 02:02 PM, Andreas Schwab wrote:
> John Stultz <john.stultz@linaro.org> writes:
>
>> The timekeeper struct has a xtime_nsec, which keeps the
>> sub-nanosecond remainder.  This ends up being somewhat
>> duplicative of the timekeeper.xtime.tv_nsec value, and we
>> have to do extra work to keep them apart, copying the full
>> nsec portion out and back in over and over.
>>
>> This patch simplifies some of the logic by taking the timekeeper
>> xtime value and splitting it into timekeeper.xtime_sec and
>> reuses the timekeeper.xtime_nsec for the sub-second portion
>> (stored in higher res shifted nanoseconds).
>>
>> This simplifies some of the accumulation logic. And will
>> allow for more accurate timekeeping once the vsyscall code
>> is updated to use the shifted nanosecond remainder.
> This (together with b44d50d "time: Fix casting issue in tk_set_xtime and
> tk_xtime_add") is causing resume to hang on the iBook (PowerBook6,7).
> The fact that the add-on commit is needed to uncover the bug might give
> a hint, but I'm unable to decipher it.

Thanks for the bug report and narrowing this down.

I'm not very familiar w/ the iBook hardware, but does it use a 
clocksource, or does it use arch_gettimeoffset()?

I suspect that the casting has avoided clipping some strange values from 
the persistent clock.

Could you try with the following patch against Linus' HEAD? I suspect it 
will let the box resume (although it will seem as though no time was 
spent in resume) and then let me know what the JDB lines print out?

thanks
-john

diff --git a/kernel/time/timekeeping.c b/kernel/time/timekeeping.c
index e16af19..03f5a82 100644
--- a/kernel/time/timekeeping.c
+++ b/kernel/time/timekeeping.c
@@ -753,10 +753,14 @@ static void timekeeping_resume(void)
  	clocksource_resume();
  
  	write_seqlock_irqsave(&tk->lock, flags);
+	printk("JDB: suspend_time: %ld:%ld  resume_time: %ld:%ld\n",
+		timekeeping_suspend_time.tv_sec, timekeeping_suspend_time.tv_nsec,
+		ts.tv_sec, ts.tv_nsec);
  
  	if (timespec_compare(&ts, &timekeeping_suspend_time) > 0) {
  		ts = timespec_sub(ts, timekeeping_suspend_time);
-		__timekeeping_inject_sleeptime(tk, &ts);
+		printk("JDB: Trying to add: %ld:%ld\n", ts.tv_sec, ts.tv_nsec);
+		//__timekeeping_inject_sleeptime(tk, &ts);
  	}
  	/* re-base the last cycle value */
  	tk->clock->cycle_last = tk->clock->read(tk->clock);

Re: [PATCH 4/8] time: Condense timekeeper.xtime into xtime_sec

[Andreas Schwab]

John Stultz <john.stultz@linaro.org> writes:

> I'm not very familiar w/ the iBook hardware, but does it use a 
> clocksource, or does it use arch_gettimeoffset()?

clocksource: timebase mult[3640e38e] shift[24] registered

> I suspect that the casting has avoided clipping some strange values from 
> the persistent clock.

That's my guess as well.

> Could you try with the following patch against Linus' HEAD? I suspect it 
> will let the box resume (although it will seem as though no time was 
> spent in resume) and then let me know what the JDB lines print out?

JDB: suspend_time: 1345491706:0  resume_time: 1345491737:0
JDB: Trying to add: 31:0

(Looks reasonable.)

Andreas.

-- 
Andreas Schwab, schwab@linux-m68k.org
GPG Key fingerprint = 58CA 54C7 6D53 942B 1756  01D3 44D5 214B 8276 4ED5
"And now for something completely different."

Re: [PATCH 4/8] time: Condense timekeeper.xtime into xtime_sec

[John Stultz]

On 08/20/2012 12:45 PM, Andreas Schwab wrote:
> John Stultz <john.stultz@linaro.org> writes:
>
>> I'm not very familiar w/ the iBook hardware, but does it use a
>> clocksource, or does it use arch_gettimeoffset()?
> clocksource: timebase mult[3640e38e] shift[24] registered
>
>> I suspect that the casting has avoided clipping some strange values from
>> the persistent clock.
> That's my guess as well.
>
>> Could you try with the following patch against Linus' HEAD? I suspect it
>> will let the box resume (although it will seem as though no time was
>> spent in resume) and then let me know what the JDB lines print out?
> JDB: suspend_time: 1345491706:0  resume_time: 1345491737:0
> JDB: Trying to add: 31:0
>
> (Looks reasonable.)
Huh.  Yea, that looks fine.  And without the 
__timekeeping_inject_sleeptime() call, the system resumed ok?

Thanks for the testing!  I'll keep looking here.
-john

Re: [PATCH 4/8] time: Condense timekeeper.xtime into xtime_sec

[Andreas Schwab]

John Stultz <john.stultz@linaro.org> writes:

> Huh.  Yea, that looks fine.  And without the
> __timekeeping_inject_sleeptime() call, the system resumed ok?

Yes, it does.

Andreas.

-- 
Andreas Schwab, schwab@linux-m68k.org
GPG Key fingerprint = 58CA 54C7 6D53 942B 1756  01D3 44D5 214B 8276 4ED5
"And now for something completely different."

Re: [PATCH 4/8] time: Condense timekeeper.xtime into xtime_sec

[John Stultz]

On 08/20/2012 01:04 PM, Andreas Schwab wrote:
> John Stultz <john.stultz@linaro.org> writes:
>
>> Huh.  Yea, that looks fine.  And without the
>> __timekeeping_inject_sleeptime() call, the system resumed ok?
> Yes, it does.

So I'm mostly still stumped on this. But I did find one possible related 
bugfix that maybe you can try?

Let me know if the patch below dodges the problem, and if not, please 
send me the JDB printk output.
(if the resume hangs without any output, add a "return;" before the 
tk_xtime_add() call between the JDB printks).

thanks
-john



diff --git a/kernel/time/timekeeping.c b/kernel/time/timekeeping.c
index e16af19..1a9b9c5 100644
--- a/kernel/time/timekeeping.c
+++ b/kernel/time/timekeeping.c
@@ -115,6 +115,7 @@ static void tk_xtime_add(struct timekeeper *tk, const struct timespec *ts)
  {
  	tk->xtime_sec += ts->tv_sec;
  	tk->xtime_nsec += (u64)ts->tv_nsec << tk->shift;
+	tk_normalize_xtime(tk);
  }
  
  static void tk_set_wall_to_mono(struct timekeeper *tk, struct timespec wtm)
@@ -695,9 +696,22 @@ static void __timekeeping_inject_sleeptime(struct timekeeper *tk,
  					"sleep delta value!\n");
  		return;
  	}
+
+	printk("JDB: pre xt %ld:%ld  wtm: %ld:%ld st: %ld:%ld\n",
+		tk_xtime(tk).tv_sec, tk_xtime(tk).tv_nsec,
+		tk->wall_to_monotonic.tv_sec,tk->wall_to_monotonic.tv_nsec,
+		tk->total_sleep_time.tv_sec, tk->total_sleep_time.tv_nsec);
+	printk("JDB: Adding %ld:%ld\n", delta->tv_sec, delta->tv_nsec);
+
  	tk_xtime_add(tk, delta);
  	tk_set_wall_to_mono(tk, timespec_sub(tk->wall_to_monotonic, *delta));
  	tk_set_sleep_time(tk, timespec_add(tk->total_sleep_time, *delta));
+
+	printk("JDB: post xt %ld:%ld  wtm: %ld:%ld st: %ld:%ld\n",
+		tk_xtime(tk).tv_sec, tk_xtime(tk).tv_nsec,
+		tk->wall_to_monotonic.tv_sec,tk->wall_to_monotonic.tv_nsec,
+		tk->total_sleep_time.tv_sec, tk->total_sleep_time.tv_nsec);
+
  }
  
  /**

Re: [PATCH 4/8] time: Condense timekeeper.xtime into xtime_sec

[Andreas Schwab]

John Stultz <john.stultz@linaro.org> writes:

> @@ -115,6 +115,7 @@ static void tk_xtime_add(struct timekeeper *tk, const struct timespec *ts)
>  {
>  	tk->xtime_sec += ts->tv_sec;
>  	tk->xtime_nsec += (u64)ts->tv_nsec << tk->shift;
> +	tk_normalize_xtime(tk);
>  }

Yes, that does it.  Failure to normalize is always bad.

Andreas.

-- 
Andreas Schwab, schwab@linux-m68k.org
GPG Key fingerprint = 58CA 54C7 6D53 942B 1756  01D3 44D5 214B 8276 4ED5
"And now for something completely different."

Re: [PATCH 4/8] time: Condense timekeeper.xtime into xtime_sec

[John Stultz]

On 08/21/2012 12:14 AM, Andreas Schwab wrote:
> John Stultz <john.stultz@linaro.org> writes:
>
>> @@ -115,6 +115,7 @@ static void tk_xtime_add(struct timekeeper *tk, const struct timespec *ts)
>>   {
>>   	tk->xtime_sec += ts->tv_sec;
>>   	tk->xtime_nsec += (u64)ts->tv_nsec << tk->shift;
>> +	tk_normalize_xtime(tk);
>>   }
> Yes, that does it.  Failure to normalize is always bad.

Great. Thanks for the testing and the bug report! I'll be sending out 
the patch to -tip later today.

thanks
-john