* Re: Suspend resume problem (WAS Re: [ANNOUNCE] 3.8.10-rt6)
2013-04-30 17:09 ` Suspend resume problem (WAS Re: [ANNOUNCE] 3.8.10-rt6) Sebastian Andrzej Siewior
@ 2013-04-30 18:08 ` Steven Rostedt
2013-05-03 9:59 ` Sebastian Andrzej Siewior
2013-04-30 19:18 ` Clark Williams
` (3 subsequent siblings)
4 siblings, 1 reply; 19+ messages in thread
From: Steven Rostedt @ 2013-04-30 18:08 UTC (permalink / raw)
To: Sebastian Andrzej Siewior
Cc: Clark Williams, linux-rt-users, Thomas Gleixner, LKML
On Tue, 2013-04-30 at 19:09 +0200, Sebastian Andrzej Siewior wrote:
> The next thing that happens is that RCU assumes nobody is doing any
> progress (for almost 28secs) and triggers NMIs & printks to get some
> attention. I have a trace where
> - CPU0: arch_trigger_all_cpu_backtrace_handler() => printk()
> has "lock" and is spinning for logbuf_lock
>
> - CPU1: print_cpu_stall() => printk() (spinning for the lock) => NMI =>
> arch_trigger_all_cpu_backtrace_handler()
> it may have logbuf_lock and is spinning for "lock"
>
> I can't tell if CPU1 got the logbuf_lock at this time but it seemed that
> it made no progress until I ended it.
> This NMI releated deadlock is a problem which should also trigger
> mainline, right?
Well, yeah, as sending out a NMI stack dump is sorta the last resort,
and is dangerous to do printks from NMI context.
>
> Now, the time jump on the other hand is the real issue here and is
> RT-only. It looks like we get a big number of timer updates via
> tick_do_update_jiffies64() because according to ktime_get() that much
> time really passed by.
As the NMI dump only happens because of the time jump, which as you
said, is -rt only, I wouldn't say that the NMI deadlock is a mainline
bug.
-- Steve
^ permalink raw reply [flat|nested] 19+ messages in thread* Re: Suspend resume problem (WAS Re: [ANNOUNCE] 3.8.10-rt6)
2013-04-30 18:08 ` Steven Rostedt
@ 2013-05-03 9:59 ` Sebastian Andrzej Siewior
2013-05-03 15:31 ` Steven Rostedt
0 siblings, 1 reply; 19+ messages in thread
From: Sebastian Andrzej Siewior @ 2013-05-03 9:59 UTC (permalink / raw)
To: Steven Rostedt; +Cc: Clark Williams, linux-rt-users, Thomas Gleixner, LKML
On 04/30/2013 08:08 PM, Steven Rostedt wrote:
>> This NMI releated deadlock is a problem which should also trigger
>> mainline, right?
>
> Well, yeah, as sending out a NMI stack dump is sorta the last resort,
> and is dangerous to do printks from NMI context.
So we did bad and we upgrade to bad and dangerous.
>>
>> Now, the time jump on the other hand is the real issue here and is
>> RT-only. It looks like we get a big number of timer updates via
>> tick_do_update_jiffies64() because according to ktime_get() that much
>> time really passed by.
>
> As the NMI dump only happens because of the time jump, which as you
> said, is -rt only, I wouldn't say that the NMI deadlock is a mainline
> bug.
The reason for the NMI was a bug in the -RT tree but if something else
triggers that NMI we have a good chance to deadlock.
What about a try_lock() and leave after 50 usecs of trying and not
getting it in the in_nmi() case?
> -- Steve
Sebastian
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Suspend resume problem (WAS Re: [ANNOUNCE] 3.8.10-rt6)
2013-05-03 9:59 ` Sebastian Andrzej Siewior
@ 2013-05-03 15:31 ` Steven Rostedt
0 siblings, 0 replies; 19+ messages in thread
From: Steven Rostedt @ 2013-05-03 15:31 UTC (permalink / raw)
To: Sebastian Andrzej Siewior
Cc: Clark Williams, linux-rt-users, Thomas Gleixner, LKML
On Fri, 2013-05-03 at 11:59 +0200, Sebastian Andrzej Siewior wrote:
>
> > As the NMI dump only happens because of the time jump, which as you
> > said, is -rt only, I wouldn't say that the NMI deadlock is a mainline
> > bug.
>
> The reason for the NMI was a bug in the -RT tree but if something else
> triggers that NMI we have a good chance to deadlock.
But only if the NMI does a printk(). The only reason NMIs do printks is
when a bug is detected. But usually oops_in_progress() is called and
also zap_locks() is suppose to help prevent these problems. But that
doesn't always work.
>
> What about a try_lock() and leave after 50 usecs of trying and not
> getting it in the in_nmi() case?
I wouldn't try too hard to fix printks for NMIs. There's many things
that can go wrong with NMIs doing a printk while another printk is
active.
-- Steve
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Suspend resume problem (WAS Re: [ANNOUNCE] 3.8.10-rt6)
2013-04-30 17:09 ` Suspend resume problem (WAS Re: [ANNOUNCE] 3.8.10-rt6) Sebastian Andrzej Siewior
2013-04-30 18:08 ` Steven Rostedt
@ 2013-04-30 19:18 ` Clark Williams
2013-04-30 21:54 ` Clark Williams
2013-04-30 22:31 ` Borislav Petkov
` (2 subsequent siblings)
4 siblings, 1 reply; 19+ messages in thread
From: Clark Williams @ 2013-04-30 19:18 UTC (permalink / raw)
To: Sebastian Andrzej Siewior; +Cc: linux-rt-users, Thomas Gleixner, LKML, rostedt
[-- Attachment #1: Type: text/plain, Size: 3881 bytes --]
On Tue, 30 Apr 2013 19:09:48 +0200
Sebastian Andrzej Siewior <bigeasy@linutronix.de> wrote:
> * Clark Williams | 2013-04-29 16:19:25 [-0500]:
>
> >On Mon, 29 Apr 2013 22:12:02 +0200
> >Sebastian Andrzej Siewior <bigeasy@linutronix.de> wrote:
> >> - suspend / resume seems to program program the timer wrong and wait
> >> ages until it continues.
> >
> >It has to be something we're doing when we apply RT to v3.8.x, since
> >v3.8.x suspends/resumes with no issues and I was able to suspend and
> >resume fine with the 3.6-rt series.
>
> I think I figured out what is going on or atleast I think I did.
>
> This log snippet is from the resume path (from suspend to mem):
>
> [ 15.052115] Enabling non-boot CPUs ...
> [ 15.052115] smpboot: Booting Node 0 Processor 1 APIC 0x1
> [ 14.841378] Initializing CPU#1
> [ 42.840017] [sched_delayed] sched: RT throttling activated
> [ 42.842144] CPU1 is up
> [ 42.842536] smpboot: Booting Node 0 Processor 2 APIC 0x2
>
> Two things happen here:
> - the time goes backwards from 15.X to 14.X. This is okay because the
> 14.X is the timestamp from the secondary CPU not - yet synchronized
> with the bootcpu
> - the printk with "CPU1 is up" is comming from the boot CPU and
> according to the timestamp about 28secs passed by. But this did not
> really happen as the whole procedure took less time.
>
> The next thing that happens is that RCU assumes nobody is doing any
> progress (for almost 28secs) and triggers NMIs & printks to get some
> attention. I have a trace where
> - CPU0: arch_trigger_all_cpu_backtrace_handler() => printk()
> has "lock" and is spinning for logbuf_lock
>
> - CPU1: print_cpu_stall() => printk() (spinning for the lock) => NMI =>
> arch_trigger_all_cpu_backtrace_handler()
> it may have logbuf_lock and is spinning for "lock"
>
> I can't tell if CPU1 got the logbuf_lock at this time but it seemed that
> it made no progress until I ended it.
> This NMI releated deadlock is a problem which should also trigger
> mainline, right?
>
> Now, the time jump on the other hand is the real issue here and is
> RT-only. It looks like we get a big number of timer updates via
> tick_do_update_jiffies64() because according to ktime_get() that much
> time really passed by.
>
> The sollution seems as simple as
>
> From c27eb2e0ab0b5acd96a4b62288976f1b72789b3e Mon Sep 17 00:00:00 2001
> From: Sebastian Andrzej Siewior <bigeasy@linutronix.de>
> Date: Tue, 30 Apr 2013 18:53:55 +0200
> Subject: [PATCH] time/timekeeping: shadow tk->cycle_last together with
> clock->cycle_last
>
> Commit ("timekeeping: Store cycle_last value in timekeeper struct as
> well") introduced a tk-> based cycle_last values which needs to be reset
> on resume path as well or else ktime_get() will think that time
> increased a lot.
>
> Signed-off-by: Sebastian Andrzej Siewior <bigeasy@linutronix.de>
> ---
> kernel/time/timekeeping.c | 1 +
> 1 file changed, 1 insertion(+)
>
> diff --git a/kernel/time/timekeeping.c b/kernel/time/timekeeping.c
> index 99f943b..688817f 100644
> --- a/kernel/time/timekeeping.c
> +++ b/kernel/time/timekeeping.c
> @@ -777,6 +777,7 @@ static void timekeeping_resume(void)
> }
> /* re-base the last cycle value */
> tk->clock->cycle_last = tk->clock->read(tk->clock);
> + tk->cycle_last = tk->clock->cycle_last;
> tk->ntp_error = 0;
> timekeeping_suspended = 0;
> timekeeping_update(tk, false, true);
> --
> 1.7.10.4
>
> So Clark, does this patch fix your problem?
>
It does seem to! I've got both patches applied right now (your patch to
vprintk_emit() and the above patch) and it fixes the long delay on my
lab box. When I get done today (or have a break in the action) I'll try
it on my laptop to verify.
Thanks Sebastian,
Clark
[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 198 bytes --]
^ permalink raw reply [flat|nested] 19+ messages in thread* Re: Suspend resume problem (WAS Re: [ANNOUNCE] 3.8.10-rt6)
2013-04-30 19:18 ` Clark Williams
@ 2013-04-30 21:54 ` Clark Williams
0 siblings, 0 replies; 19+ messages in thread
From: Clark Williams @ 2013-04-30 21:54 UTC (permalink / raw)
To: Sebastian Andrzej Siewior; +Cc: linux-rt-users, Thomas Gleixner, LKML, rostedt
[-- Attachment #1: Type: text/plain, Size: 4224 bytes --]
On Tue, 30 Apr 2013 14:18:24 -0500
Clark Williams <williams@redhat.com> wrote:
> On Tue, 30 Apr 2013 19:09:48 +0200
> Sebastian Andrzej Siewior <bigeasy@linutronix.de> wrote:
>
> > * Clark Williams | 2013-04-29 16:19:25 [-0500]:
> >
> > >On Mon, 29 Apr 2013 22:12:02 +0200
> > >Sebastian Andrzej Siewior <bigeasy@linutronix.de> wrote:
> > >> - suspend / resume seems to program program the timer wrong and wait
> > >> ages until it continues.
> > >
> > >It has to be something we're doing when we apply RT to v3.8.x, since
> > >v3.8.x suspends/resumes with no issues and I was able to suspend and
> > >resume fine with the 3.6-rt series.
> >
> > I think I figured out what is going on or atleast I think I did.
> >
> > This log snippet is from the resume path (from suspend to mem):
> >
> > [ 15.052115] Enabling non-boot CPUs ...
> > [ 15.052115] smpboot: Booting Node 0 Processor 1 APIC 0x1
> > [ 14.841378] Initializing CPU#1
> > [ 42.840017] [sched_delayed] sched: RT throttling activated
> > [ 42.842144] CPU1 is up
> > [ 42.842536] smpboot: Booting Node 0 Processor 2 APIC 0x2
> >
> > Two things happen here:
> > - the time goes backwards from 15.X to 14.X. This is okay because the
> > 14.X is the timestamp from the secondary CPU not - yet synchronized
> > with the bootcpu
> > - the printk with "CPU1 is up" is comming from the boot CPU and
> > according to the timestamp about 28secs passed by. But this did not
> > really happen as the whole procedure took less time.
> >
> > The next thing that happens is that RCU assumes nobody is doing any
> > progress (for almost 28secs) and triggers NMIs & printks to get some
> > attention. I have a trace where
> > - CPU0: arch_trigger_all_cpu_backtrace_handler() => printk()
> > has "lock" and is spinning for logbuf_lock
> >
> > - CPU1: print_cpu_stall() => printk() (spinning for the lock) => NMI =>
> > arch_trigger_all_cpu_backtrace_handler()
> > it may have logbuf_lock and is spinning for "lock"
> >
> > I can't tell if CPU1 got the logbuf_lock at this time but it seemed that
> > it made no progress until I ended it.
> > This NMI releated deadlock is a problem which should also trigger
> > mainline, right?
> >
> > Now, the time jump on the other hand is the real issue here and is
> > RT-only. It looks like we get a big number of timer updates via
> > tick_do_update_jiffies64() because according to ktime_get() that much
> > time really passed by.
> >
> > The sollution seems as simple as
> >
> > From c27eb2e0ab0b5acd96a4b62288976f1b72789b3e Mon Sep 17 00:00:00 2001
> > From: Sebastian Andrzej Siewior <bigeasy@linutronix.de>
> > Date: Tue, 30 Apr 2013 18:53:55 +0200
> > Subject: [PATCH] time/timekeeping: shadow tk->cycle_last together with
> > clock->cycle_last
> >
> > Commit ("timekeeping: Store cycle_last value in timekeeper struct as
> > well") introduced a tk-> based cycle_last values which needs to be reset
> > on resume path as well or else ktime_get() will think that time
> > increased a lot.
> >
> > Signed-off-by: Sebastian Andrzej Siewior <bigeasy@linutronix.de>
> > ---
> > kernel/time/timekeeping.c | 1 +
> > 1 file changed, 1 insertion(+)
> >
> > diff --git a/kernel/time/timekeeping.c b/kernel/time/timekeeping.c
> > index 99f943b..688817f 100644
> > --- a/kernel/time/timekeeping.c
> > +++ b/kernel/time/timekeeping.c
> > @@ -777,6 +777,7 @@ static void timekeeping_resume(void)
> > }
> > /* re-base the last cycle value */
> > tk->clock->cycle_last = tk->clock->read(tk->clock);
> > + tk->cycle_last = tk->clock->cycle_last;
> > tk->ntp_error = 0;
> > timekeeping_suspended = 0;
> > timekeeping_update(tk, false, true);
> > --
> > 1.7.10.4
> >
> > So Clark, does this patch fix your problem?
> >
>
> It does seem to! I've got both patches applied right now (your patch to
> vprintk_emit() and the above patch) and it fixes the long delay on my
> lab box. When I get done today (or have a break in the action) I'll try
> it on my laptop to verify.
>
> Thanks Sebastian,
> Clark
Tested on my laptop which now resumes.
Many thanks.
Clark
[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 198 bytes --]
^ permalink raw reply [flat|nested] 19+ messages in thread
* Re: Suspend resume problem (WAS Re: [ANNOUNCE] 3.8.10-rt6)
2013-04-30 17:09 ` Suspend resume problem (WAS Re: [ANNOUNCE] 3.8.10-rt6) Sebastian Andrzej Siewior
2013-04-30 18:08 ` Steven Rostedt
2013-04-30 19:18 ` Clark Williams
@ 2013-04-30 22:31 ` Borislav Petkov
2013-05-02 7:59 ` Sebastian Andrzej Siewior
2013-05-01 8:30 ` Bernhard Schiffner
2013-05-01 8:32 ` Bernhard Schiffner
4 siblings, 1 reply; 19+ messages in thread
From: Borislav Petkov @ 2013-04-30 22:31 UTC (permalink / raw)
To: Sebastian Andrzej Siewior
Cc: Clark Williams, linux-rt-users, Thomas Gleixner, LKML, rostedt
On Tue, Apr 30, 2013 at 07:09:48PM +0200, Sebastian Andrzej Siewior wrote:
> Now, the time jump on the other hand is the real issue here and is
> RT-only. It looks like we get a big number of timer updates via
> tick_do_update_jiffies64() because according to ktime_get() that much
> time really passed by.
>
> The sollution seems as simple as
>
> From c27eb2e0ab0b5acd96a4b62288976f1b72789b3e Mon Sep 17 00:00:00 2001
> From: Sebastian Andrzej Siewior <bigeasy@linutronix.de>
> Date: Tue, 30 Apr 2013 18:53:55 +0200
> Subject: [PATCH] time/timekeeping: shadow tk->cycle_last together with
> clock->cycle_last
>
> Commit ("timekeeping: Store cycle_last value in timekeeper struct as
> well") introduced a tk-> based cycle_last values which needs to be reset
> on resume path as well or else ktime_get() will think that time
> increased a lot.
>
> Signed-off-by: Sebastian Andrzej Siewior <bigeasy@linutronix.de>
> ---
> kernel/time/timekeeping.c | 1 +
> 1 file changed, 1 insertion(+)
>
> diff --git a/kernel/time/timekeeping.c b/kernel/time/timekeeping.c
> index 99f943b..688817f 100644
> --- a/kernel/time/timekeeping.c
> +++ b/kernel/time/timekeeping.c
> @@ -777,6 +777,7 @@ static void timekeeping_resume(void)
> }
> /* re-base the last cycle value */
> tk->clock->cycle_last = tk->clock->read(tk->clock);
> + tk->cycle_last = tk->clock->cycle_last;
> tk->ntp_error = 0;
> timekeeping_suspended = 0;
> timekeeping_update(tk, false, true);
Didn't tlgx fix a similar issue upstream already?
77c675ba18836.
--
Regards/Gruss,
Boris.
Sent from a fat crate under my desk. Formatting is fine.
--
^ permalink raw reply [flat|nested] 19+ messages in thread* Re: Suspend resume problem (WAS Re: [ANNOUNCE] 3.8.10-rt6)
2013-04-30 17:09 ` Suspend resume problem (WAS Re: [ANNOUNCE] 3.8.10-rt6) Sebastian Andrzej Siewior
` (2 preceding siblings ...)
2013-04-30 22:31 ` Borislav Petkov
@ 2013-05-01 8:30 ` Bernhard Schiffner
2013-05-01 8:32 ` Bernhard Schiffner
4 siblings, 0 replies; 19+ messages in thread
From: Bernhard Schiffner @ 2013-05-01 8:30 UTC (permalink / raw)
To: linux-rt-users
Am Dienstag, 30. April 2013, 19:09:48 schrieb Sebastian Andrzej Siewior:
> * Clark Williams | 2013-04-29 16:19:25 [-0500]:
> >On Mon, 29 Apr 2013 22:12:02 +0200
> >
> >Sebastian Andrzej Siewior <bigeasy@linutronix.de> wrote:
> >> - suspend / resume seems to program program the timer wrong and wait
> >>
> >> ages until it continues.
> >
> >It has to be something we're doing when we apply RT to v3.8.x, since
> >v3.8.x suspends/resumes with no issues and I was able to suspend and
> >resume fine with the 3.6-rt series.
>
> I think I figured out what is going on or atleast I think I did.
>
> This log snippet is from the resume path (from suspend to mem):
>
> [ 15.052115] Enabling non-boot CPUs ...
> [ 15.052115] smpboot: Booting Node 0 Processor 1 APIC 0x1
> [ 14.841378] Initializing CPU#1
> [ 42.840017] [sched_delayed] sched: RT throttling activated
> [ 42.842144] CPU1 is up
> [ 42.842536] smpboot: Booting Node 0 Processor 2 APIC 0x2
>
> Two things happen here:
> - the time goes backwards from 15.X to 14.X. This is okay because the
> 14.X is the timestamp from the secondary CPU not - yet synchronized
> with the bootcpu
> - the printk with "CPU1 is up" is comming from the boot CPU and
> according to the timestamp about 28secs passed by. But this did not
> really happen as the whole procedure took less time.
>
> The next thing that happens is that RCU assumes nobody is doing any
> progress (for almost 28secs) and triggers NMIs & printks to get some
> attention. I have a trace where
> - CPU0: arch_trigger_all_cpu_backtrace_handler() => printk()
> has "lock" and is spinning for logbuf_lock
>
> - CPU1: print_cpu_stall() => printk() (spinning for the lock) => NMI =>
> arch_trigger_all_cpu_backtrace_handler()
> it may have logbuf_lock and is spinning for "lock"
>
> I can't tell if CPU1 got the logbuf_lock at this time but it seemed that
> it made no progress until I ended it.
> This NMI releated deadlock is a problem which should also trigger
> mainline, right?
>
> Now, the time jump on the other hand is the real issue here and is
> RT-only. It looks like we get a big number of timer updates via
> tick_do_update_jiffies64() because according to ktime_get() that much
> time really passed by.
>
> The sollution seems as simple as
>
> From c27eb2e0ab0b5acd96a4b62288976f1b72789b3e Mon Sep 17 00:00:00 2001
> From: Sebastian Andrzej Siewior <bigeasy@linutronix.de>
> Date: Tue, 30 Apr 2013 18:53:55 +0200
> Subject: [PATCH] time/timekeeping: shadow tk->cycle_last together with
> clock->cycle_last
>
> Commit ("timekeeping: Store cycle_last value in timekeeper struct as
> well") introduced a tk-> based cycle_last values which needs to be reset
> on resume path as well or else ktime_get() will think that time
> increased a lot.
>
> Signed-off-by: Sebastian Andrzej Siewior <bigeasy@linutronix.de>
> ---
> kernel/time/timekeeping.c | 1 +
> 1 file changed, 1 insertion(+)
>
> diff --git a/kernel/time/timekeeping.c b/kernel/time/timekeeping.c
> index 99f943b..688817f 100644
> --- a/kernel/time/timekeeping.c
> +++ b/kernel/time/timekeeping.c
> @@ -777,6 +777,7 @@ static void timekeeping_resume(void)
> }
> /* re-base the last cycle value */
> tk->clock->cycle_last = tk->clock->read(tk->clock);
> + tk->cycle_last = tk->clock->cycle_last;
> tk->ntp_error = 0;
> timekeeping_suspended = 0;
> timekeeping_update(tk, false, true);
>
> >Clark
>
> Sebastian
> --
This patch together with the in_nmi() patch solves the resume problem for me.
Architecture X64, patched against 3.8.10-rt6.
THANKS!
Bernhard
^ permalink raw reply [flat|nested] 19+ messages in thread* Re: Suspend resume problem (WAS Re: [ANNOUNCE] 3.8.10-rt6)
2013-04-30 17:09 ` Suspend resume problem (WAS Re: [ANNOUNCE] 3.8.10-rt6) Sebastian Andrzej Siewior
` (3 preceding siblings ...)
2013-05-01 8:30 ` Bernhard Schiffner
@ 2013-05-01 8:32 ` Bernhard Schiffner
2013-05-03 10:27 ` Sebastian Andrzej Siewior
4 siblings, 1 reply; 19+ messages in thread
From: Bernhard Schiffner @ 2013-05-01 8:32 UTC (permalink / raw)
To: linux-rt-users
Am Dienstag, 30. April 2013, 19:09:48 schrieb Sebastian Andrzej Siewior:
> * Clark Williams | 2013-04-29 16:19:25 [-0500]:
> >On Mon, 29 Apr 2013 22:12:02 +0200
> >
> >Sebastian Andrzej Siewior <bigeasy@linutronix.de> wrote:
> >> - suspend / resume seems to program program the timer wrong and wait
> >>
> >> ages until it continues.
> >
> >It has to be something we're doing when we apply RT to v3.8.x, since
> >v3.8.x suspends/resumes with no issues and I was able to suspend and
> >resume fine with the 3.6-rt series.
>
> I think I figured out what is going on or atleast I think I did.
>
> This log snippet is from the resume path (from suspend to mem):
>
> [ 15.052115] Enabling non-boot CPUs ...
> [ 15.052115] smpboot: Booting Node 0 Processor 1 APIC 0x1
> [ 14.841378] Initializing CPU#1
> [ 42.840017] [sched_delayed] sched: RT throttling activated
> [ 42.842144] CPU1 is up
> [ 42.842536] smpboot: Booting Node 0 Processor 2 APIC 0x2
>
> Two things happen here:
> - the time goes backwards from 15.X to 14.X. This is okay because the
> 14.X is the timestamp from the secondary CPU not - yet synchronized
> with the bootcpu
> - the printk with "CPU1 is up" is comming from the boot CPU and
> according to the timestamp about 28secs passed by. But this did not
> really happen as the whole procedure took less time.
>
> The next thing that happens is that RCU assumes nobody is doing any
> progress (for almost 28secs) and triggers NMIs & printks to get some
> attention. I have a trace where
> - CPU0: arch_trigger_all_cpu_backtrace_handler() => printk()
> has "lock" and is spinning for logbuf_lock
>
> - CPU1: print_cpu_stall() => printk() (spinning for the lock) => NMI =>
> arch_trigger_all_cpu_backtrace_handler()
> it may have logbuf_lock and is spinning for "lock"
>
> I can't tell if CPU1 got the logbuf_lock at this time but it seemed that
> it made no progress until I ended it.
> This NMI releated deadlock is a problem which should also trigger
> mainline, right?
>
> Now, the time jump on the other hand is the real issue here and is
> RT-only. It looks like we get a big number of timer updates via
> tick_do_update_jiffies64() because according to ktime_get() that much
> time really passed by.
>
> The sollution seems as simple as
>
> From c27eb2e0ab0b5acd96a4b62288976f1b72789b3e Mon Sep 17 00:00:00 2001
> From: Sebastian Andrzej Siewior <bigeasy@linutronix.de>
> Date: Tue, 30 Apr 2013 18:53:55 +0200
> Subject: [PATCH] time/timekeeping: shadow tk->cycle_last together with
> clock->cycle_last
>
> Commit ("timekeeping: Store cycle_last value in timekeeper struct as
> well") introduced a tk-> based cycle_last values which needs to be reset
> on resume path as well or else ktime_get() will think that time
> increased a lot.
>
> Signed-off-by: Sebastian Andrzej Siewior <bigeasy@linutronix.de>
> ---
> kernel/time/timekeeping.c | 1 +
> 1 file changed, 1 insertion(+)
>
> diff --git a/kernel/time/timekeeping.c b/kernel/time/timekeeping.c
> index 99f943b..688817f 100644
> --- a/kernel/time/timekeeping.c
> +++ b/kernel/time/timekeeping.c
> @@ -777,6 +777,7 @@ static void timekeeping_resume(void)
> }
> /* re-base the last cycle value */
> tk->clock->cycle_last = tk->clock->read(tk->clock);
> + tk->cycle_last = tk->clock->cycle_last;
> tk->ntp_error = 0;
> timekeeping_suspended = 0;
> timekeeping_update(tk, false, true);
>
> >Clark
>
> Sebastian
> --
This patch together with the in_nmi() patch solves the resume problem for me.
Architecture X64, patched against 3.8.10-rt6.
THANKS!
Bernhard
^ permalink raw reply [flat|nested] 19+ messages in thread