[PATCH][v2] timekeeping: Fix memory overwrite of sleep_time_bin array

[PATCH][v2] timekeeping: Fix memory overwrite of sleep_time_bin array

[Chen Yu]

It is reported the hibernation fails at 2nd attempt, which
hangs at hibernate() -> syscore_resume() -> i8237A_resume()
-> claim_dma_lock(), because the lock has already been taken.
However there is actually no other process would like to grab
this lock on that problematic platform.

Further investigation shows that, the problem is caused by setting
/sys/power/pm_trace to 1 before the 1st hibernation, since once
pm_trace is enabled, the rtc becomes an unmeaningful value after resumed,
which might bring a significant long sleep time in timekeeping_resume,
thus in tk_debug_account_sleep_time, if the bit31 happened to be set to 1,
the fls might return 32 and then we add 1 to sleep_time_bin[32], which
caused a memory overwritten. As System.map shows:

ffffffff81c9d080 b sleep_time_bin
ffffffff81c9d100 B dma_spin_lock

Thus set the dma_spin_lock.val to 1, which caused this problem.

To fix this problem, we ignore those abnormal sleep time,
since no one would like to sleep that long.

Cc: Stable <stable@vger.kernel.org> # 3.17+
Suggested-by: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
Reported-and-tested-by: Janek Kozicki <cosurgi@gmail.com>
Signed-off-by: Chen Yu <yu.c.chen@intel.com>
---
 kernel/time/timekeeping_debug.c | 4 +++-
 1 file changed, 3 insertions(+), 1 deletion(-)

diff --git a/kernel/time/timekeeping_debug.c b/kernel/time/timekeeping_debug.c
index f6bd652..b164bb9 100644
--- a/kernel/time/timekeeping_debug.c
+++ b/kernel/time/timekeeping_debug.c
@@ -24,6 +24,7 @@
 #include "timekeeping_internal.h"
 
 static unsigned int sleep_time_bin[32] = {0};
+#define MAX_SLEEP_TIME 0x7fffffff
 
 static int tk_debug_show_sleep_time(struct seq_file *s, void *data)
 {
@@ -69,6 +70,7 @@ late_initcall(tk_debug_sleep_time_init);
 
 void tk_debug_account_sleep_time(struct timespec64 *t)
 {
-	sleep_time_bin[fls(t->tv_sec)]++;
+	if ((t->tv_sec >= 0) && (t->tv_sec <= MAX_SLEEP_TIME))
+		sleep_time_bin[fls(t->tv_sec)]++;
 }
 
-- 
2.7.4

Re: [PATCH][v2] timekeeping: Fix memory overwrite of sleep_time_bin array

[Thomas Gleixner]

On Tue, 19 Jul 2016, Chen Yu wrote:

> It is reported the hibernation fails at 2nd attempt, which
> hangs at hibernate() -> syscore_resume() -> i8237A_resume()
> -> claim_dma_lock(), because the lock has already been taken.
> However there is actually no other process would like to grab
> this lock on that problematic platform.
> 
> Further investigation shows that, the problem is caused by setting
> /sys/power/pm_trace to 1 before the 1st hibernation, since once
> pm_trace is enabled, the rtc becomes an unmeaningful value after resumed,

So why is the RTC value useless if pm_trace is enabled? I really have a hard
time to understand why pm_trace would affect the sleep time readout from RTC.

Thanks,

	tglx

Re: [PATCH][v2] timekeeping: Fix memory overwrite of sleep_time_bin array

[Chen Yu]

Hi Thomas,

On 2016年07月19日 16:36, Thomas Gleixner wrote:
> On Tue, 19 Jul 2016, Chen Yu wrote:
>
>> It is reported the hibernation fails at 2nd attempt, which
>> hangs at hibernate() -> syscore_resume() -> i8237A_resume()
>> -> claim_dma_lock(), because the lock has already been taken.
>> However there is actually no other process would like to grab
>> this lock on that problematic platform.
>>
>> Further investigation shows that, the problem is caused by setting
>> /sys/power/pm_trace to 1 before the 1st hibernation, since once
>> pm_trace is enabled, the rtc becomes an unmeaningful value after resumed,
> So why is the RTC value useless if pm_trace is enabled? I really have a hard
> time to understand why pm_trace would affect the sleep time readout from RTC.
>
> Thanks,
>
> 	tglx
After pm_trace is enabled, during system suspend/hibernate, the hash name of
each devices will be written to rtc, so  the rtc value depends on what 
we write in last suspend
round, thus pm_trace can be  used for diagnose which device failed to 
suspend(eg, the suspending
on this device hang the system, we reboot the system , and check rtc 
hash value).

  In our case, after first hibernate/resume round,  we found our current 
system time
is  at  2117, so syscore_resume -> timekeeping_resume :
__timekeeping_inject_sleeptime(tk, &ts_delta)
would inject a quite large delta :  2117 - 2017 year, thus the 
sleep_time_bin is overflow.

thanks,
Yu

Re: [PATCH][v2] timekeeping: Fix memory overwrite of sleep_time_bin array

[Thomas Gleixner]

[-- Attachment #1: Type: TEXT/PLAIN, Size: 1513 bytes --]

On Tue, 19 Jul 2016, Chen Yu wrote:
> On 2016年07月19日 16:36, Thomas Gleixner wrote:
> > On Tue, 19 Jul 2016, Chen Yu wrote:
> > > Further investigation shows that, the problem is caused by setting
> > > /sys/power/pm_trace to 1 before the 1st hibernation, since once
> > > pm_trace is enabled, the rtc becomes an unmeaningful value after resumed,
> >
> > So why is the RTC value useless if pm_trace is enabled? I really have a hard
> > time to understand why pm_trace would affect the sleep time readout from
> > RTC.
>
> After pm_trace is enabled, during system suspend/hibernate, the hash name of
> each devices will be written to rtc, so the rtc value depends on what we
> write in last suspend round, thus pm_trace can be used for diagnose which
> device failed to suspend(eg, the suspending on this device hang the system,
> we reboot the system , and check rtc hash value).
> 
> In our case, after first hibernate/resume round, we found our current system
> time is at 2117, so syscore_resume -> timekeeping_resume :
> __timekeeping_inject_sleeptime(tk, &ts_delta) would inject a quite large
> delta : 2117 - 2017 year, thus the sleep_time_bin is overflow.

While the range check is certainly correct and a good thing to have it's wrong
in the first place to call __timekeeping_inject_sleeptime() in case that
pm_trace is enabled simply because that "hash" time value will also wreckage
timekeeping. Your patch is just curing the symptom in the debug code but not
fixing the root cause.

Thanks,

	tglx