2018-04-22 02:22:11

by Diego Viola

[permalink] [raw]
Subject: Experiencing freezes with kernel 4.16.3 on a desktop with E5500 CPU (bisect included)

Hi,

I'm currently experiencing freezes after resuming from suspend when
using various applications on my desktop.

For example, when using Firefox and switching between tabs the screen
would freeze, allowing me to only move the mouse pointer but focusing
the mouse pointer on a application won't have any effect.

The keyboard would still work and the only way to make the issue go
away would be to switch to a virtual desktop and then switch back,
then I'd be able to use the mouse again until the same problem
re-occurs.

This never happened before upgrading to 4.16.3 and 4.15.18 is unaffected.

The problem only happens *after* resuming from suspend, in normal S0
state it never happens.

My machine is a desktop and has a dual core E5500 CPU with 2GB of RAM,
I run Arch Linux and I use the i3wm.

I don't think it's a problem with user space because I run exactly the
same Arch Linux setup on my T450 and the issue can't be reproduced on
that machine.

I did a bisect and the cause of the bug seems to be this commit:

aa83c45762a242acce9b35020363225a7b59d7c9 is the first bad commit

Here is the bisect log:

git bisect start
# bad: [0adb32858b0bddf4ada5f364a84ed60b196dbcda] Linux 4.16
git bisect bad 0adb32858b0bddf4ada5f364a84ed60b196dbcda
# good: [d8a5b80568a9cb66810e75b182018e9edb68e8ff] Linux 4.15
git bisect good d8a5b80568a9cb66810e75b182018e9edb68e8ff
# bad: [c14376de3a1befa70d9811ca2872d47367b48767] printk: Wake klogd
when passing console_lock owner
git bisect bad c14376de3a1befa70d9811ca2872d47367b48767
# bad: [a103950e0dd2058df5e8a8d4a915707bdcf205f0] Merge branch 'linus'
of git://git.kernel.org/pub/scm/linux/kernel/git/herbert/crypto-2.6
git bisect bad a103950e0dd2058df5e8a8d4a915707bdcf205f0
# bad: [d8b91dde38f4c43bd0bbbf17a90f735b16aaff2c] Merge branch
'perf-core-for-linus' of
git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
git bisect bad d8b91dde38f4c43bd0bbbf17a90f735b16aaff2c
# good: [9697e9da84299d0d715d515dd2cc48f1eceb277d] Merge tag
'edac_for_4.16' of git://git.kernel.org/pub/scm/linux/kernel/git/bp/bp
git bisect good 9697e9da84299d0d715d515dd2cc48f1eceb277d
# good: [d0bd31dc5c0b46b9c778112900cf8f910ac26e1b] Merge tag
'xtensa-20180129' of git://github.com/jcmvbkbc/linux-xtensa
git bisect good d0bd31dc5c0b46b9c778112900cf8f910ac26e1b
# good: [0337cf74ccf2a43437bff2e23b278e4f2dc4c6e2] perf util:
Introduce architecture specific errno/name mapping
git bisect good 0337cf74ccf2a43437bff2e23b278e4f2dc4c6e2
# bad: [6304672b7f0a5c010002e63a075160856dc4f88d] Merge branch
'x86-pti-for-linus' of
git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
git bisect bad 6304672b7f0a5c010002e63a075160856dc4f88d
# good: [a46d3f9b1c9888a244ed1ce8da0eca98c3f378e2] Merge branch
'timers-core-for-linus' of
git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
git bisect good a46d3f9b1c9888a244ed1ce8da0eca98c3f378e2
# good: [669c0f762ed19bd9ec128ebc97ae8641b6e1a4a3] Merge branch
'x86-platform-for-linus' of
git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
git bisect good 669c0f762ed19bd9ec128ebc97ae8641b6e1a4a3
# good: [7a32fc51ca938e67974cbb9db31e1a43f98345a9] x86/nospec: Fix
header guards names
git bisect good 7a32fc51ca938e67974cbb9db31e1a43f98345a9
# bad: [942633523cde99c5bfa0329996dd839ca66a87aa] Merge branch
'x86-mm-for-linus' of
git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
git bisect bad 942633523cde99c5bfa0329996dd839ca66a87aa
# bad: [aa83c45762a242acce9b35020363225a7b59d7c9] x86/tsc: Introduce
early tsc clocksource
git bisect bad aa83c45762a242acce9b35020363225a7b59d7c9
# good: [6d671e1b85c63e7a337ba76c1a154c091545cff8] x86/time:
Unconditionally register legacy timer interrupt
git bisect good 6d671e1b85c63e7a337ba76c1a154c091545cff8
# first bad commit: [aa83c45762a242acce9b35020363225a7b59d7c9]
x86/tsc: Introduce early tsc clocksource

Current git HEAD is also affected.

I already tried HEAD with that commit reverted and the problem can't
be reproduced anymore.

Please let me know if I can include more info, thanks in advance.

Diego


2018-04-22 17:52:53

by Diego Viola

[permalink] [raw]
Subject: Re: Experiencing freezes with kernel 4.16.3 on a desktop with E5500 CPU (bisect included)

On Sat, Apr 21, 2018 at 11:19 PM, Diego Viola <[email protected]> wrote:
> Hi,
>
> I'm currently experiencing freezes after resuming from suspend when
> using various applications on my desktop.
>
> For example, when using Firefox and switching between tabs the screen
> would freeze, allowing me to only move the mouse pointer but focusing
> the mouse pointer on a application won't have any effect.
>
> The keyboard would still work and the only way to make the issue go
> away would be to switch to a virtual desktop and then switch back,
> then I'd be able to use the mouse again until the same problem
> re-occurs.
>
> This never happened before upgrading to 4.16.3 and 4.15.18 is unaffected.
>
> The problem only happens *after* resuming from suspend, in normal S0
> state it never happens.
>
> My machine is a desktop and has a dual core E5500 CPU with 2GB of RAM,
> I run Arch Linux and I use the i3wm.
>
> I don't think it's a problem with user space because I run exactly the
> same Arch Linux setup on my T450 and the issue can't be reproduced on
> that machine.
>
> I did a bisect and the cause of the bug seems to be this commit:
>
> aa83c45762a242acce9b35020363225a7b59d7c9 is the first bad commit
>
> Here is the bisect log:
>
> git bisect start
> # bad: [0adb32858b0bddf4ada5f364a84ed60b196dbcda] Linux 4.16
> git bisect bad 0adb32858b0bddf4ada5f364a84ed60b196dbcda
> # good: [d8a5b80568a9cb66810e75b182018e9edb68e8ff] Linux 4.15
> git bisect good d8a5b80568a9cb66810e75b182018e9edb68e8ff
> # bad: [c14376de3a1befa70d9811ca2872d47367b48767] printk: Wake klogd
> when passing console_lock owner
> git bisect bad c14376de3a1befa70d9811ca2872d47367b48767
> # bad: [a103950e0dd2058df5e8a8d4a915707bdcf205f0] Merge branch 'linus'
> of git://git.kernel.org/pub/scm/linux/kernel/git/herbert/crypto-2.6
> git bisect bad a103950e0dd2058df5e8a8d4a915707bdcf205f0
> # bad: [d8b91dde38f4c43bd0bbbf17a90f735b16aaff2c] Merge branch
> 'perf-core-for-linus' of
> git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
> git bisect bad d8b91dde38f4c43bd0bbbf17a90f735b16aaff2c
> # good: [9697e9da84299d0d715d515dd2cc48f1eceb277d] Merge tag
> 'edac_for_4.16' of git://git.kernel.org/pub/scm/linux/kernel/git/bp/bp
> git bisect good 9697e9da84299d0d715d515dd2cc48f1eceb277d
> # good: [d0bd31dc5c0b46b9c778112900cf8f910ac26e1b] Merge tag
> 'xtensa-20180129' of git://github.com/jcmvbkbc/linux-xtensa
> git bisect good d0bd31dc5c0b46b9c778112900cf8f910ac26e1b
> # good: [0337cf74ccf2a43437bff2e23b278e4f2dc4c6e2] perf util:
> Introduce architecture specific errno/name mapping
> git bisect good 0337cf74ccf2a43437bff2e23b278e4f2dc4c6e2
> # bad: [6304672b7f0a5c010002e63a075160856dc4f88d] Merge branch
> 'x86-pti-for-linus' of
> git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
> git bisect bad 6304672b7f0a5c010002e63a075160856dc4f88d
> # good: [a46d3f9b1c9888a244ed1ce8da0eca98c3f378e2] Merge branch
> 'timers-core-for-linus' of
> git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
> git bisect good a46d3f9b1c9888a244ed1ce8da0eca98c3f378e2
> # good: [669c0f762ed19bd9ec128ebc97ae8641b6e1a4a3] Merge branch
> 'x86-platform-for-linus' of
> git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
> git bisect good 669c0f762ed19bd9ec128ebc97ae8641b6e1a4a3
> # good: [7a32fc51ca938e67974cbb9db31e1a43f98345a9] x86/nospec: Fix
> header guards names
> git bisect good 7a32fc51ca938e67974cbb9db31e1a43f98345a9
> # bad: [942633523cde99c5bfa0329996dd839ca66a87aa] Merge branch
> 'x86-mm-for-linus' of
> git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
> git bisect bad 942633523cde99c5bfa0329996dd839ca66a87aa
> # bad: [aa83c45762a242acce9b35020363225a7b59d7c9] x86/tsc: Introduce
> early tsc clocksource
> git bisect bad aa83c45762a242acce9b35020363225a7b59d7c9
> # good: [6d671e1b85c63e7a337ba76c1a154c091545cff8] x86/time:
> Unconditionally register legacy timer interrupt
> git bisect good 6d671e1b85c63e7a337ba76c1a154c091545cff8
> # first bad commit: [aa83c45762a242acce9b35020363225a7b59d7c9]
> x86/tsc: Introduce early tsc clocksource
>
> Current git HEAD is also affected.
>
> I already tried HEAD with that commit reverted and the problem can't
> be reproduced anymore.
>
> Please let me know if I can include more info, thanks in advance.
>
> Diego

When booting with clocksource=hpet I cannot reproduce the problem.

2018-04-22 18:25:43

by Diego Viola

[permalink] [raw]
Subject: Re: Experiencing freezes with kernel 4.16.3 on a desktop with E5500 CPU (bisect included)

On Sun, Apr 22, 2018 at 2:47 PM, Diego Viola <[email protected]> wrote:
> On Sat, Apr 21, 2018 at 11:19 PM, Diego Viola <[email protected]> wrote:
>> Hi,
>>
>> I'm currently experiencing freezes after resuming from suspend when
>> using various applications on my desktop.
>>
>> For example, when using Firefox and switching between tabs the screen
>> would freeze, allowing me to only move the mouse pointer but focusing
>> the mouse pointer on a application won't have any effect.
>>
>> The keyboard would still work and the only way to make the issue go
>> away would be to switch to a virtual desktop and then switch back,
>> then I'd be able to use the mouse again until the same problem
>> re-occurs.
>>
>> This never happened before upgrading to 4.16.3 and 4.15.18 is unaffected.
>>
>> The problem only happens *after* resuming from suspend, in normal S0
>> state it never happens.
>>
>> My machine is a desktop and has a dual core E5500 CPU with 2GB of RAM,
>> I run Arch Linux and I use the i3wm.
>>
>> I don't think it's a problem with user space because I run exactly the
>> same Arch Linux setup on my T450 and the issue can't be reproduced on
>> that machine.
>>
>> I did a bisect and the cause of the bug seems to be this commit:
>>
>> aa83c45762a242acce9b35020363225a7b59d7c9 is the first bad commit
>>
>> Here is the bisect log:
>>
>> git bisect start
>> # bad: [0adb32858b0bddf4ada5f364a84ed60b196dbcda] Linux 4.16
>> git bisect bad 0adb32858b0bddf4ada5f364a84ed60b196dbcda
>> # good: [d8a5b80568a9cb66810e75b182018e9edb68e8ff] Linux 4.15
>> git bisect good d8a5b80568a9cb66810e75b182018e9edb68e8ff
>> # bad: [c14376de3a1befa70d9811ca2872d47367b48767] printk: Wake klogd
>> when passing console_lock owner
>> git bisect bad c14376de3a1befa70d9811ca2872d47367b48767
>> # bad: [a103950e0dd2058df5e8a8d4a915707bdcf205f0] Merge branch 'linus'
>> of git://git.kernel.org/pub/scm/linux/kernel/git/herbert/crypto-2.6
>> git bisect bad a103950e0dd2058df5e8a8d4a915707bdcf205f0
>> # bad: [d8b91dde38f4c43bd0bbbf17a90f735b16aaff2c] Merge branch
>> 'perf-core-for-linus' of
>> git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
>> git bisect bad d8b91dde38f4c43bd0bbbf17a90f735b16aaff2c
>> # good: [9697e9da84299d0d715d515dd2cc48f1eceb277d] Merge tag
>> 'edac_for_4.16' of git://git.kernel.org/pub/scm/linux/kernel/git/bp/bp
>> git bisect good 9697e9da84299d0d715d515dd2cc48f1eceb277d
>> # good: [d0bd31dc5c0b46b9c778112900cf8f910ac26e1b] Merge tag
>> 'xtensa-20180129' of git://github.com/jcmvbkbc/linux-xtensa
>> git bisect good d0bd31dc5c0b46b9c778112900cf8f910ac26e1b
>> # good: [0337cf74ccf2a43437bff2e23b278e4f2dc4c6e2] perf util:
>> Introduce architecture specific errno/name mapping
>> git bisect good 0337cf74ccf2a43437bff2e23b278e4f2dc4c6e2
>> # bad: [6304672b7f0a5c010002e63a075160856dc4f88d] Merge branch
>> 'x86-pti-for-linus' of
>> git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
>> git bisect bad 6304672b7f0a5c010002e63a075160856dc4f88d
>> # good: [a46d3f9b1c9888a244ed1ce8da0eca98c3f378e2] Merge branch
>> 'timers-core-for-linus' of
>> git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
>> git bisect good a46d3f9b1c9888a244ed1ce8da0eca98c3f378e2
>> # good: [669c0f762ed19bd9ec128ebc97ae8641b6e1a4a3] Merge branch
>> 'x86-platform-for-linus' of
>> git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
>> git bisect good 669c0f762ed19bd9ec128ebc97ae8641b6e1a4a3
>> # good: [7a32fc51ca938e67974cbb9db31e1a43f98345a9] x86/nospec: Fix
>> header guards names
>> git bisect good 7a32fc51ca938e67974cbb9db31e1a43f98345a9
>> # bad: [942633523cde99c5bfa0329996dd839ca66a87aa] Merge branch
>> 'x86-mm-for-linus' of
>> git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
>> git bisect bad 942633523cde99c5bfa0329996dd839ca66a87aa
>> # bad: [aa83c45762a242acce9b35020363225a7b59d7c9] x86/tsc: Introduce
>> early tsc clocksource
>> git bisect bad aa83c45762a242acce9b35020363225a7b59d7c9
>> # good: [6d671e1b85c63e7a337ba76c1a154c091545cff8] x86/time:
>> Unconditionally register legacy timer interrupt
>> git bisect good 6d671e1b85c63e7a337ba76c1a154c091545cff8
>> # first bad commit: [aa83c45762a242acce9b35020363225a7b59d7c9]
>> x86/tsc: Introduce early tsc clocksource
>>
>> Current git HEAD is also affected.
>>
>> I already tried HEAD with that commit reverted and the problem can't
>> be reproduced anymore.
>>
>> Please let me know if I can include more info, thanks in advance.
>>
>> Diego
>
> When booting with clocksource=hpet I cannot reproduce the problem.

I can reproduce the freeze with clocksource=tsc as well.

2018-04-23 09:18:14

by Peter Zijlstra

[permalink] [raw]
Subject: Re: Experiencing freezes with kernel 4.16.3 on a desktop with E5500 CPU (bisect included)

On Sat, Apr 21, 2018 at 11:19:55PM -0300, Diego Viola wrote:

> The problem only happens *after* resuming from suspend, in normal S0
> state it never happens.

What kind of suspend are you doing? s2disk, s2ram ?

> My machine is a desktop and has a dual core E5500 CPU with 2GB of RAM,
> I run Arch Linux and I use the i3wm.

That's a Core2 era chip; does it actually have stable TSC ?

> aa83c45762a242acce9b35020363225a7b59d7c9 is the first bad commit

That is most curious; that was supposed to only affect early boot. I'll
try and figure out of there's some intersection with suspend.

2018-04-23 09:30:38

by Rafael J. Wysocki

[permalink] [raw]
Subject: Re: Experiencing freezes with kernel 4.16.3 on a desktop with E5500 CPU (bisect included)

On Monday, April 23, 2018 11:16:33 AM CEST Peter Zijlstra wrote:
> On Sat, Apr 21, 2018 at 11:19:55PM -0300, Diego Viola wrote:
>
> > The problem only happens *after* resuming from suspend, in normal S0
> > state it never happens.
>
> What kind of suspend are you doing? s2disk, s2ram ?
>
> > My machine is a desktop and has a dual core E5500 CPU with 2GB of RAM,
> > I run Arch Linux and I use the i3wm.
>
> That's a Core2 era chip; does it actually have stable TSC ?
>
> > aa83c45762a242acce9b35020363225a7b59d7c9 is the first bad commit
>
> That is most curious; that was supposed to only affect early boot. I'll
> try and figure out of there's some intersection with suspend.

Well, FWIW, I wonder if the flags that were set in init_tsc_clocksource() for
unstable TSC before the above commit may be involved in this somehow.


2018-04-23 11:25:51

by Diego Viola

[permalink] [raw]
Subject: Re: Experiencing freezes with kernel 4.16.3 on a desktop with E5500 CPU (bisect included)

On Mon, Apr 23, 2018 at 6:16 AM, Peter Zijlstra <[email protected]> wrote:
> On Sat, Apr 21, 2018 at 11:19:55PM -0300, Diego Viola wrote:
>
>> The problem only happens *after* resuming from suspend, in normal S0
>> state it never happens.
>
> What kind of suspend are you doing? s2disk, s2ram ?

Suspend to RAM with systemctl suspend.

>
>> My machine is a desktop and has a dual core E5500 CPU with 2GB of RAM,
>> I run Arch Linux and I use the i3wm.
>
> That's a Core2 era chip; does it actually have stable TSC ?

I'm not sure.

>
>> aa83c45762a242acce9b35020363225a7b59d7c9 is the first bad commit
>
> That is most curious; that was supposed to only affect early boot. I'll
> try and figure out of there's some intersection with suspend.

Thanks.

2018-04-23 11:50:48

by Peter Zijlstra

[permalink] [raw]
Subject: Re: Experiencing freezes with kernel 4.16.3 on a desktop with E5500 CPU (bisect included)

On Mon, Apr 23, 2018 at 08:23:24AM -0300, Diego Viola wrote:
> > That's a Core2 era chip; does it actually have stable TSC ?
>
> I'm not sure.

dmesg | grep -i tsc

should be able to tell you.

2018-04-23 11:51:01

by Diego Viola

[permalink] [raw]
Subject: Re: Experiencing freezes with kernel 4.16.3 on a desktop with E5500 CPU (bisect included)

On Mon, Apr 23, 2018 at 8:48 AM, Peter Zijlstra <[email protected]> wrote:
> On Mon, Apr 23, 2018 at 08:23:24AM -0300, Diego Viola wrote:
>> > That's a Core2 era chip; does it actually have stable TSC ?
>>
>> I'm not sure.
>
> dmesg | grep -i tsc
>
> should be able to tell you.

[diego@dualcore ~]$ dmesg | grep -i tsc
[ 0.000000] tsc: Fast TSC calibration using PIT
[ 0.016666] tsc: Fast TSC calibration using PIT
[ 0.019999] tsc: Detected 2793.087 MHz processor
[ 0.019999] clocksource: tsc-early: mask: 0xffffffffffffffff
max_cycles: 0x2842be30f1f, max_idle_ns: 440795236296 ns
[ 0.162058] clocksource: Switched to clocksource tsc-early
[ 0.300076] tsc: Marking TSC unstable due to TSC halts in idle
[diego@dualcore ~]$

2018-04-23 12:40:31

by Peter Zijlstra

[permalink] [raw]
Subject: Re: Experiencing freezes with kernel 4.16.3 on a desktop with E5500 CPU (bisect included)

On Mon, Apr 23, 2018 at 08:49:25AM -0300, Diego Viola wrote:
> On Mon, Apr 23, 2018 at 8:48 AM, Peter Zijlstra <[email protected]> wrote:
> > On Mon, Apr 23, 2018 at 08:23:24AM -0300, Diego Viola wrote:
> >> > That's a Core2 era chip; does it actually have stable TSC ?
> >>
> >> I'm not sure.
> >
> > dmesg | grep -i tsc
> >
> > should be able to tell you.
>
> [diego@dualcore ~]$ dmesg | grep -i tsc
> [ 0.000000] tsc: Fast TSC calibration using PIT
> [ 0.016666] tsc: Fast TSC calibration using PIT
> [ 0.019999] tsc: Detected 2793.087 MHz processor
> [ 0.019999] clocksource: tsc-early: mask: 0xffffffffffffffff
> max_cycles: 0x2842be30f1f, max_idle_ns: 440795236296 ns
> [ 0.162058] clocksource: Switched to clocksource tsc-early
> [ 0.300076] tsc: Marking TSC unstable due to TSC halts in idle
> [diego@dualcore ~]$

Much thanks.. I suspect there a bunch of fail when marking unstable
before we register clocksource_tsc.

The below patch is a bit ugly, but should cure a number of things; it
compiles but hasn't otherwise been tested, can you give it a spin?

---

- when TSC is unstable and we've already registered tsc-early, don't
forget to unregister it; this then leaves us without a tsc
clocksource entirely -- which is good.

- when we call mark_tsc_unstable() before we've registered
clocksource_tsc things go wobbly because it doesn't know about
clocksource_tsc_early. Fix that by:

- Make clocksource_mark_unstable() work for unregistered
clocksources.

- which means we have to be able to detect this; use cs.list
for this; initialize it empty.
- means we also have to place all cs.list manipulation under
watchdog_lock -- bit ugly.

- Make __clocksource_unstable() de-rate the clocksource.

- Call clocksource_mark_unstable() on both tsc and tsc_early.

This way we should either end up with a derated tsc clocksource marked
UNSTABLE or no tsc clocksource at all, either should result in it not
becoming the active clocksource.

---
arch/x86/kernel/tsc.c | 22 +++++++++++-----------
kernel/time/clocksource.c | 43 +++++++++++++++++++++++++++++++++++--------
2 files changed, 46 insertions(+), 19 deletions(-)

diff --git a/arch/x86/kernel/tsc.c b/arch/x86/kernel/tsc.c
index 91e6da48cbb6..74392d9d51e0 100644
--- a/arch/x86/kernel/tsc.c
+++ b/arch/x86/kernel/tsc.c
@@ -1067,6 +1067,7 @@ static struct clocksource clocksource_tsc_early = {
.resume = tsc_resume,
.mark_unstable = tsc_cs_mark_unstable,
.tick_stable = tsc_cs_tick_stable,
+ .list = LIST_HEAD_INIT(clocksource_tsc_early.list),
};

/*
@@ -1086,6 +1087,7 @@ static struct clocksource clocksource_tsc = {
.resume = tsc_resume,
.mark_unstable = tsc_cs_mark_unstable,
.tick_stable = tsc_cs_tick_stable,
+ .list = LIST_HEAD_INIT(clocksource_tsc.list),
};

void mark_tsc_unstable(char *reason)
@@ -1098,13 +1100,9 @@ void mark_tsc_unstable(char *reason)
clear_sched_clock_stable();
disable_sched_clock_irqtime();
pr_info("Marking TSC unstable due to %s\n", reason);
- /* Change only the rating, when not registered */
- if (clocksource_tsc.mult) {
- clocksource_mark_unstable(&clocksource_tsc);
- } else {
- clocksource_tsc.flags |= CLOCK_SOURCE_UNSTABLE;
- clocksource_tsc.rating = 0;
- }
+
+ clocksource_mark_unstable(&clocksource_tsc_early);
+ clocksource_mark_unstable(&clocksource_tsc);
}

EXPORT_SYMBOL_GPL(mark_tsc_unstable);
@@ -1244,7 +1242,7 @@ static void tsc_refine_calibration_work(struct work_struct *work)

/* Don't bother refining TSC on unstable systems */
if (tsc_unstable)
- return;
+ goto unreg;

/*
* Since the work is started early in boot, we may be
@@ -1297,11 +1295,12 @@ static void tsc_refine_calibration_work(struct work_struct *work)

out:
if (tsc_unstable)
- return;
+ goto unreg;

if (boot_cpu_has(X86_FEATURE_ART))
art_related_clocksource = &clocksource_tsc;
clocksource_register_khz(&clocksource_tsc, tsc_khz);
+unreg:
clocksource_unregister(&clocksource_tsc_early);
}

@@ -1311,8 +1310,8 @@ static int __init init_tsc_clocksource(void)
if (!boot_cpu_has(X86_FEATURE_TSC) || tsc_disabled > 0 || !tsc_khz)
return 0;

- if (check_tsc_unstable())
- return 0;
+ if (tsc_unstable)
+ goto unreg;

if (tsc_clocksource_reliable)
clocksource_tsc.flags &= ~CLOCK_SOURCE_MUST_VERIFY;
@@ -1328,6 +1327,7 @@ static int __init init_tsc_clocksource(void)
if (boot_cpu_has(X86_FEATURE_ART))
art_related_clocksource = &clocksource_tsc;
clocksource_register_khz(&clocksource_tsc, tsc_khz);
+unreg:
clocksource_unregister(&clocksource_tsc_early);
return 0;
}
diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
index 0e974cface0b..f689c9e3ff5e 100644
--- a/kernel/time/clocksource.c
+++ b/kernel/time/clocksource.c
@@ -119,6 +119,16 @@ static DEFINE_SPINLOCK(watchdog_lock);
static int watchdog_running;
static atomic_t watchdog_reset_pending;

+static void inline clocksource_watchdog_lock(unsigned long *flags)
+{
+ spin_lock_irqsave(&watchdog_lock, *flags);
+}
+
+static void inline clocksource_watchdog_unlock(unsigned long *flags)
+{
+ spin_unlock_irqrestore(&watchdog_lock, *flags);
+}
+
static int clocksource_watchdog_kthread(void *data);
static void __clocksource_change_rating(struct clocksource *cs, int rating);

@@ -142,6 +152,13 @@ static void __clocksource_unstable(struct clocksource *cs)
cs->flags &= ~(CLOCK_SOURCE_VALID_FOR_HRES | CLOCK_SOURCE_WATCHDOG);
cs->flags |= CLOCK_SOURCE_UNSTABLE;

+ if (list_empty(&cs->list)) {
+ cs->rating = 0;
+ return;
+ }
+
+ __clocksource_change_rating(cs, 0);
+
if (cs->mark_unstable)
cs->mark_unstable(cs);

@@ -164,7 +181,7 @@ void clocksource_mark_unstable(struct clocksource *cs)

spin_lock_irqsave(&watchdog_lock, flags);
if (!(cs->flags & CLOCK_SOURCE_UNSTABLE)) {
- if (list_empty(&cs->wd_list))
+ if (!list_empty(&cs->list) && list_empty(&cs->wd_list))
list_add(&cs->wd_list, &watchdog_list);
__clocksource_unstable(cs);
}
@@ -319,9 +336,8 @@ static void clocksource_resume_watchdog(void)

static void clocksource_enqueue_watchdog(struct clocksource *cs)
{
- unsigned long flags;
+ INIT_LIST_HEAD(&cs->wd_list);

- spin_lock_irqsave(&watchdog_lock, flags);
if (cs->flags & CLOCK_SOURCE_MUST_VERIFY) {
/* cs is a clocksource to be watched. */
list_add(&cs->wd_list, &watchdog_list);
@@ -331,7 +347,6 @@ static void clocksource_enqueue_watchdog(struct clocksource *cs)
if (cs->flags & CLOCK_SOURCE_IS_CONTINUOUS)
cs->flags |= CLOCK_SOURCE_VALID_FOR_HRES;
}
- spin_unlock_irqrestore(&watchdog_lock, flags);
}

static void clocksource_select_watchdog(bool fallback)
@@ -373,9 +388,6 @@ static void clocksource_select_watchdog(bool fallback)

static void clocksource_dequeue_watchdog(struct clocksource *cs)
{
- unsigned long flags;
-
- spin_lock_irqsave(&watchdog_lock, flags);
if (cs != watchdog) {
if (cs->flags & CLOCK_SOURCE_MUST_VERIFY) {
/* cs is a watched clocksource. */
@@ -384,7 +396,6 @@ static void clocksource_dequeue_watchdog(struct clocksource *cs)
clocksource_stop_watchdog();
}
}
- spin_unlock_irqrestore(&watchdog_lock, flags);
}

static int __clocksource_watchdog_kthread(void)
@@ -779,14 +790,19 @@ EXPORT_SYMBOL_GPL(__clocksource_update_freq_scale);
*/
int __clocksource_register_scale(struct clocksource *cs, u32 scale, u32 freq)
{
+ unsigned long flags;

/* Initialize mult/shift and max_idle_ns */
__clocksource_update_freq_scale(cs, scale, freq);

/* Add clocksource to the clocksource list */
mutex_lock(&clocksource_mutex);
+
+ clocksource_watchdog_lock(&flags);
clocksource_enqueue(cs);
clocksource_enqueue_watchdog(cs);
+ clocksource_watchdog_unlock(&flags);
+
clocksource_select();
clocksource_select_watchdog(false);
mutex_unlock(&clocksource_mutex);
@@ -808,8 +824,13 @@ static void __clocksource_change_rating(struct clocksource *cs, int rating)
*/
void clocksource_change_rating(struct clocksource *cs, int rating)
{
+ unsigned long flags;
+
mutex_lock(&clocksource_mutex);
+ clocksource_watchdog_lock(&flags);
__clocksource_change_rating(cs, rating);
+ clocksource_watchdog_unlock(&flags);
+
clocksource_select();
clocksource_select_watchdog(false);
mutex_unlock(&clocksource_mutex);
@@ -821,6 +842,8 @@ EXPORT_SYMBOL(clocksource_change_rating);
*/
static int clocksource_unbind(struct clocksource *cs)
{
+ unsigned long flags;
+
if (clocksource_is_watchdog(cs)) {
/* Select and try to install a replacement watchdog. */
clocksource_select_watchdog(true);
@@ -834,8 +857,12 @@ static int clocksource_unbind(struct clocksource *cs)
if (curr_clocksource == cs)
return -EBUSY;
}
+
+ clocksource_watchdog_lock(&flags);
clocksource_dequeue_watchdog(cs);
list_del_init(&cs->list);
+ clocksource_watchdog_lock(&flags);
+
return 0;
}


2018-04-23 12:51:16

by Diego Viola

[permalink] [raw]
Subject: Re: Experiencing freezes with kernel 4.16.3 on a desktop with E5500 CPU (bisect included)

On Mon, Apr 23, 2018 at 9:38 AM, Peter Zijlstra <[email protected]> wrote:
> On Mon, Apr 23, 2018 at 08:49:25AM -0300, Diego Viola wrote:
>> On Mon, Apr 23, 2018 at 8:48 AM, Peter Zijlstra <[email protected]> wrote:
>> > On Mon, Apr 23, 2018 at 08:23:24AM -0300, Diego Viola wrote:
>> >> > That's a Core2 era chip; does it actually have stable TSC ?
>> >>
>> >> I'm not sure.
>> >
>> > dmesg | grep -i tsc
>> >
>> > should be able to tell you.
>>
>> [diego@dualcore ~]$ dmesg | grep -i tsc
>> [ 0.000000] tsc: Fast TSC calibration using PIT
>> [ 0.016666] tsc: Fast TSC calibration using PIT
>> [ 0.019999] tsc: Detected 2793.087 MHz processor
>> [ 0.019999] clocksource: tsc-early: mask: 0xffffffffffffffff
>> max_cycles: 0x2842be30f1f, max_idle_ns: 440795236296 ns
>> [ 0.162058] clocksource: Switched to clocksource tsc-early
>> [ 0.300076] tsc: Marking TSC unstable due to TSC halts in idle
>> [diego@dualcore ~]$
>
> Much thanks.. I suspect there a bunch of fail when marking unstable
> before we register clocksource_tsc.
>
> The below patch is a bit ugly, but should cure a number of things; it
> compiles but hasn't otherwise been tested, can you give it a spin?
>
> ---
>
> - when TSC is unstable and we've already registered tsc-early, don't
> forget to unregister it; this then leaves us without a tsc
> clocksource entirely -- which is good.
>
> - when we call mark_tsc_unstable() before we've registered
> clocksource_tsc things go wobbly because it doesn't know about
> clocksource_tsc_early. Fix that by:
>
> - Make clocksource_mark_unstable() work for unregistered
> clocksources.
>
> - which means we have to be able to detect this; use cs.list
> for this; initialize it empty.
> - means we also have to place all cs.list manipulation under
> watchdog_lock -- bit ugly.
>
> - Make __clocksource_unstable() de-rate the clocksource.
>
> - Call clocksource_mark_unstable() on both tsc and tsc_early.
>
> This way we should either end up with a derated tsc clocksource marked
> UNSTABLE or no tsc clocksource at all, either should result in it not
> becoming the active clocksource.
>
> ---
> arch/x86/kernel/tsc.c | 22 +++++++++++-----------
> kernel/time/clocksource.c | 43 +++++++++++++++++++++++++++++++++++--------
> 2 files changed, 46 insertions(+), 19 deletions(-)
>
> diff --git a/arch/x86/kernel/tsc.c b/arch/x86/kernel/tsc.c
> index 91e6da48cbb6..74392d9d51e0 100644
> --- a/arch/x86/kernel/tsc.c
> +++ b/arch/x86/kernel/tsc.c
> @@ -1067,6 +1067,7 @@ static struct clocksource clocksource_tsc_early = {
> .resume = tsc_resume,
> .mark_unstable = tsc_cs_mark_unstable,
> .tick_stable = tsc_cs_tick_stable,
> + .list = LIST_HEAD_INIT(clocksource_tsc_early.list),
> };
>
> /*
> @@ -1086,6 +1087,7 @@ static struct clocksource clocksource_tsc = {
> .resume = tsc_resume,
> .mark_unstable = tsc_cs_mark_unstable,
> .tick_stable = tsc_cs_tick_stable,
> + .list = LIST_HEAD_INIT(clocksource_tsc.list),
> };
>
> void mark_tsc_unstable(char *reason)
> @@ -1098,13 +1100,9 @@ void mark_tsc_unstable(char *reason)
> clear_sched_clock_stable();
> disable_sched_clock_irqtime();
> pr_info("Marking TSC unstable due to %s\n", reason);
> - /* Change only the rating, when not registered */
> - if (clocksource_tsc.mult) {
> - clocksource_mark_unstable(&clocksource_tsc);
> - } else {
> - clocksource_tsc.flags |= CLOCK_SOURCE_UNSTABLE;
> - clocksource_tsc.rating = 0;
> - }
> +
> + clocksource_mark_unstable(&clocksource_tsc_early);
> + clocksource_mark_unstable(&clocksource_tsc);
> }
>
> EXPORT_SYMBOL_GPL(mark_tsc_unstable);
> @@ -1244,7 +1242,7 @@ static void tsc_refine_calibration_work(struct work_struct *work)
>
> /* Don't bother refining TSC on unstable systems */
> if (tsc_unstable)
> - return;
> + goto unreg;
>
> /*
> * Since the work is started early in boot, we may be
> @@ -1297,11 +1295,12 @@ static void tsc_refine_calibration_work(struct work_struct *work)
>
> out:
> if (tsc_unstable)
> - return;
> + goto unreg;
>
> if (boot_cpu_has(X86_FEATURE_ART))
> art_related_clocksource = &clocksource_tsc;
> clocksource_register_khz(&clocksource_tsc, tsc_khz);
> +unreg:
> clocksource_unregister(&clocksource_tsc_early);
> }
>
> @@ -1311,8 +1310,8 @@ static int __init init_tsc_clocksource(void)
> if (!boot_cpu_has(X86_FEATURE_TSC) || tsc_disabled > 0 || !tsc_khz)
> return 0;
>
> - if (check_tsc_unstable())
> - return 0;
> + if (tsc_unstable)
> + goto unreg;
>
> if (tsc_clocksource_reliable)
> clocksource_tsc.flags &= ~CLOCK_SOURCE_MUST_VERIFY;
> @@ -1328,6 +1327,7 @@ static int __init init_tsc_clocksource(void)
> if (boot_cpu_has(X86_FEATURE_ART))
> art_related_clocksource = &clocksource_tsc;
> clocksource_register_khz(&clocksource_tsc, tsc_khz);
> +unreg:
> clocksource_unregister(&clocksource_tsc_early);
> return 0;
> }
> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
> index 0e974cface0b..f689c9e3ff5e 100644
> --- a/kernel/time/clocksource.c
> +++ b/kernel/time/clocksource.c
> @@ -119,6 +119,16 @@ static DEFINE_SPINLOCK(watchdog_lock);
> static int watchdog_running;
> static atomic_t watchdog_reset_pending;
>
> +static void inline clocksource_watchdog_lock(unsigned long *flags)
> +{
> + spin_lock_irqsave(&watchdog_lock, *flags);
> +}
> +
> +static void inline clocksource_watchdog_unlock(unsigned long *flags)
> +{
> + spin_unlock_irqrestore(&watchdog_lock, *flags);
> +}
> +
> static int clocksource_watchdog_kthread(void *data);
> static void __clocksource_change_rating(struct clocksource *cs, int rating);
>
> @@ -142,6 +152,13 @@ static void __clocksource_unstable(struct clocksource *cs)
> cs->flags &= ~(CLOCK_SOURCE_VALID_FOR_HRES | CLOCK_SOURCE_WATCHDOG);
> cs->flags |= CLOCK_SOURCE_UNSTABLE;
>
> + if (list_empty(&cs->list)) {
> + cs->rating = 0;
> + return;
> + }
> +
> + __clocksource_change_rating(cs, 0);
> +
> if (cs->mark_unstable)
> cs->mark_unstable(cs);
>
> @@ -164,7 +181,7 @@ void clocksource_mark_unstable(struct clocksource *cs)
>
> spin_lock_irqsave(&watchdog_lock, flags);
> if (!(cs->flags & CLOCK_SOURCE_UNSTABLE)) {
> - if (list_empty(&cs->wd_list))
> + if (!list_empty(&cs->list) && list_empty(&cs->wd_list))
> list_add(&cs->wd_list, &watchdog_list);
> __clocksource_unstable(cs);
> }
> @@ -319,9 +336,8 @@ static void clocksource_resume_watchdog(void)
>
> static void clocksource_enqueue_watchdog(struct clocksource *cs)
> {
> - unsigned long flags;
> + INIT_LIST_HEAD(&cs->wd_list);
>
> - spin_lock_irqsave(&watchdog_lock, flags);
> if (cs->flags & CLOCK_SOURCE_MUST_VERIFY) {
> /* cs is a clocksource to be watched. */
> list_add(&cs->wd_list, &watchdog_list);
> @@ -331,7 +347,6 @@ static void clocksource_enqueue_watchdog(struct clocksource *cs)
> if (cs->flags & CLOCK_SOURCE_IS_CONTINUOUS)
> cs->flags |= CLOCK_SOURCE_VALID_FOR_HRES;
> }
> - spin_unlock_irqrestore(&watchdog_lock, flags);
> }
>
> static void clocksource_select_watchdog(bool fallback)
> @@ -373,9 +388,6 @@ static void clocksource_select_watchdog(bool fallback)
>
> static void clocksource_dequeue_watchdog(struct clocksource *cs)
> {
> - unsigned long flags;
> -
> - spin_lock_irqsave(&watchdog_lock, flags);
> if (cs != watchdog) {
> if (cs->flags & CLOCK_SOURCE_MUST_VERIFY) {
> /* cs is a watched clocksource. */
> @@ -384,7 +396,6 @@ static void clocksource_dequeue_watchdog(struct clocksource *cs)
> clocksource_stop_watchdog();
> }
> }
> - spin_unlock_irqrestore(&watchdog_lock, flags);
> }
>
> static int __clocksource_watchdog_kthread(void)
> @@ -779,14 +790,19 @@ EXPORT_SYMBOL_GPL(__clocksource_update_freq_scale);
> */
> int __clocksource_register_scale(struct clocksource *cs, u32 scale, u32 freq)
> {
> + unsigned long flags;
>
> /* Initialize mult/shift and max_idle_ns */
> __clocksource_update_freq_scale(cs, scale, freq);
>
> /* Add clocksource to the clocksource list */
> mutex_lock(&clocksource_mutex);
> +
> + clocksource_watchdog_lock(&flags);
> clocksource_enqueue(cs);
> clocksource_enqueue_watchdog(cs);
> + clocksource_watchdog_unlock(&flags);
> +
> clocksource_select();
> clocksource_select_watchdog(false);
> mutex_unlock(&clocksource_mutex);
> @@ -808,8 +824,13 @@ static void __clocksource_change_rating(struct clocksource *cs, int rating)
> */
> void clocksource_change_rating(struct clocksource *cs, int rating)
> {
> + unsigned long flags;
> +
> mutex_lock(&clocksource_mutex);
> + clocksource_watchdog_lock(&flags);
> __clocksource_change_rating(cs, rating);
> + clocksource_watchdog_unlock(&flags);
> +
> clocksource_select();
> clocksource_select_watchdog(false);
> mutex_unlock(&clocksource_mutex);
> @@ -821,6 +842,8 @@ EXPORT_SYMBOL(clocksource_change_rating);
> */
> static int clocksource_unbind(struct clocksource *cs)
> {
> + unsigned long flags;
> +
> if (clocksource_is_watchdog(cs)) {
> /* Select and try to install a replacement watchdog. */
> clocksource_select_watchdog(true);
> @@ -834,8 +857,12 @@ static int clocksource_unbind(struct clocksource *cs)
> if (curr_clocksource == cs)
> return -EBUSY;
> }
> +
> + clocksource_watchdog_lock(&flags);
> clocksource_dequeue_watchdog(cs);
> list_del_init(&cs->list);
> + clocksource_watchdog_lock(&flags);
> +
> return 0;
> }
>

Yes, compiling the kernel (torvalds/linux.git HEAD) with your patch right now.

Thanks,
Diego

2018-04-23 13:29:23

by Diego Viola

[permalink] [raw]
Subject: Re: Experiencing freezes with kernel 4.16.3 on a desktop with E5500 CPU (bisect included)

On Mon, Apr 23, 2018 at 9:49 AM, Diego Viola <[email protected]> wrote:
> On Mon, Apr 23, 2018 at 9:38 AM, Peter Zijlstra <[email protected]> wrote:
>> On Mon, Apr 23, 2018 at 08:49:25AM -0300, Diego Viola wrote:
>>> On Mon, Apr 23, 2018 at 8:48 AM, Peter Zijlstra <[email protected]> wrote:
>>> > On Mon, Apr 23, 2018 at 08:23:24AM -0300, Diego Viola wrote:
>>> >> > That's a Core2 era chip; does it actually have stable TSC ?
>>> >>
>>> >> I'm not sure.
>>> >
>>> > dmesg | grep -i tsc
>>> >
>>> > should be able to tell you.
>>>
>>> [diego@dualcore ~]$ dmesg | grep -i tsc
>>> [ 0.000000] tsc: Fast TSC calibration using PIT
>>> [ 0.016666] tsc: Fast TSC calibration using PIT
>>> [ 0.019999] tsc: Detected 2793.087 MHz processor
>>> [ 0.019999] clocksource: tsc-early: mask: 0xffffffffffffffff
>>> max_cycles: 0x2842be30f1f, max_idle_ns: 440795236296 ns
>>> [ 0.162058] clocksource: Switched to clocksource tsc-early
>>> [ 0.300076] tsc: Marking TSC unstable due to TSC halts in idle
>>> [diego@dualcore ~]$
>>
>> Much thanks.. I suspect there a bunch of fail when marking unstable
>> before we register clocksource_tsc.
>>
>> The below patch is a bit ugly, but should cure a number of things; it
>> compiles but hasn't otherwise been tested, can you give it a spin?
>>
>> ---
>>
>> - when TSC is unstable and we've already registered tsc-early, don't
>> forget to unregister it; this then leaves us without a tsc
>> clocksource entirely -- which is good.
>>
>> - when we call mark_tsc_unstable() before we've registered
>> clocksource_tsc things go wobbly because it doesn't know about
>> clocksource_tsc_early. Fix that by:
>>
>> - Make clocksource_mark_unstable() work for unregistered
>> clocksources.
>>
>> - which means we have to be able to detect this; use cs.list
>> for this; initialize it empty.
>> - means we also have to place all cs.list manipulation under
>> watchdog_lock -- bit ugly.
>>
>> - Make __clocksource_unstable() de-rate the clocksource.
>>
>> - Call clocksource_mark_unstable() on both tsc and tsc_early.
>>
>> This way we should either end up with a derated tsc clocksource marked
>> UNSTABLE or no tsc clocksource at all, either should result in it not
>> becoming the active clocksource.
>>
>> ---
>> arch/x86/kernel/tsc.c | 22 +++++++++++-----------
>> kernel/time/clocksource.c | 43 +++++++++++++++++++++++++++++++++++--------
>> 2 files changed, 46 insertions(+), 19 deletions(-)
>>
>> diff --git a/arch/x86/kernel/tsc.c b/arch/x86/kernel/tsc.c
>> index 91e6da48cbb6..74392d9d51e0 100644
>> --- a/arch/x86/kernel/tsc.c
>> +++ b/arch/x86/kernel/tsc.c
>> @@ -1067,6 +1067,7 @@ static struct clocksource clocksource_tsc_early = {
>> .resume = tsc_resume,
>> .mark_unstable = tsc_cs_mark_unstable,
>> .tick_stable = tsc_cs_tick_stable,
>> + .list = LIST_HEAD_INIT(clocksource_tsc_early.list),
>> };
>>
>> /*
>> @@ -1086,6 +1087,7 @@ static struct clocksource clocksource_tsc = {
>> .resume = tsc_resume,
>> .mark_unstable = tsc_cs_mark_unstable,
>> .tick_stable = tsc_cs_tick_stable,
>> + .list = LIST_HEAD_INIT(clocksource_tsc.list),
>> };
>>
>> void mark_tsc_unstable(char *reason)
>> @@ -1098,13 +1100,9 @@ void mark_tsc_unstable(char *reason)
>> clear_sched_clock_stable();
>> disable_sched_clock_irqtime();
>> pr_info("Marking TSC unstable due to %s\n", reason);
>> - /* Change only the rating, when not registered */
>> - if (clocksource_tsc.mult) {
>> - clocksource_mark_unstable(&clocksource_tsc);
>> - } else {
>> - clocksource_tsc.flags |= CLOCK_SOURCE_UNSTABLE;
>> - clocksource_tsc.rating = 0;
>> - }
>> +
>> + clocksource_mark_unstable(&clocksource_tsc_early);
>> + clocksource_mark_unstable(&clocksource_tsc);
>> }
>>
>> EXPORT_SYMBOL_GPL(mark_tsc_unstable);
>> @@ -1244,7 +1242,7 @@ static void tsc_refine_calibration_work(struct work_struct *work)
>>
>> /* Don't bother refining TSC on unstable systems */
>> if (tsc_unstable)
>> - return;
>> + goto unreg;
>>
>> /*
>> * Since the work is started early in boot, we may be
>> @@ -1297,11 +1295,12 @@ static void tsc_refine_calibration_work(struct work_struct *work)
>>
>> out:
>> if (tsc_unstable)
>> - return;
>> + goto unreg;
>>
>> if (boot_cpu_has(X86_FEATURE_ART))
>> art_related_clocksource = &clocksource_tsc;
>> clocksource_register_khz(&clocksource_tsc, tsc_khz);
>> +unreg:
>> clocksource_unregister(&clocksource_tsc_early);
>> }
>>
>> @@ -1311,8 +1310,8 @@ static int __init init_tsc_clocksource(void)
>> if (!boot_cpu_has(X86_FEATURE_TSC) || tsc_disabled > 0 || !tsc_khz)
>> return 0;
>>
>> - if (check_tsc_unstable())
>> - return 0;
>> + if (tsc_unstable)
>> + goto unreg;
>>
>> if (tsc_clocksource_reliable)
>> clocksource_tsc.flags &= ~CLOCK_SOURCE_MUST_VERIFY;
>> @@ -1328,6 +1327,7 @@ static int __init init_tsc_clocksource(void)
>> if (boot_cpu_has(X86_FEATURE_ART))
>> art_related_clocksource = &clocksource_tsc;
>> clocksource_register_khz(&clocksource_tsc, tsc_khz);
>> +unreg:
>> clocksource_unregister(&clocksource_tsc_early);
>> return 0;
>> }
>> diff --git a/kernel/time/clocksource.c b/kernel/time/clocksource.c
>> index 0e974cface0b..f689c9e3ff5e 100644
>> --- a/kernel/time/clocksource.c
>> +++ b/kernel/time/clocksource.c
>> @@ -119,6 +119,16 @@ static DEFINE_SPINLOCK(watchdog_lock);
>> static int watchdog_running;
>> static atomic_t watchdog_reset_pending;
>>
>> +static void inline clocksource_watchdog_lock(unsigned long *flags)
>> +{
>> + spin_lock_irqsave(&watchdog_lock, *flags);
>> +}
>> +
>> +static void inline clocksource_watchdog_unlock(unsigned long *flags)
>> +{
>> + spin_unlock_irqrestore(&watchdog_lock, *flags);
>> +}
>> +
>> static int clocksource_watchdog_kthread(void *data);
>> static void __clocksource_change_rating(struct clocksource *cs, int rating);
>>
>> @@ -142,6 +152,13 @@ static void __clocksource_unstable(struct clocksource *cs)
>> cs->flags &= ~(CLOCK_SOURCE_VALID_FOR_HRES | CLOCK_SOURCE_WATCHDOG);
>> cs->flags |= CLOCK_SOURCE_UNSTABLE;
>>
>> + if (list_empty(&cs->list)) {
>> + cs->rating = 0;
>> + return;
>> + }
>> +
>> + __clocksource_change_rating(cs, 0);
>> +
>> if (cs->mark_unstable)
>> cs->mark_unstable(cs);
>>
>> @@ -164,7 +181,7 @@ void clocksource_mark_unstable(struct clocksource *cs)
>>
>> spin_lock_irqsave(&watchdog_lock, flags);
>> if (!(cs->flags & CLOCK_SOURCE_UNSTABLE)) {
>> - if (list_empty(&cs->wd_list))
>> + if (!list_empty(&cs->list) && list_empty(&cs->wd_list))
>> list_add(&cs->wd_list, &watchdog_list);
>> __clocksource_unstable(cs);
>> }
>> @@ -319,9 +336,8 @@ static void clocksource_resume_watchdog(void)
>>
>> static void clocksource_enqueue_watchdog(struct clocksource *cs)
>> {
>> - unsigned long flags;
>> + INIT_LIST_HEAD(&cs->wd_list);
>>
>> - spin_lock_irqsave(&watchdog_lock, flags);
>> if (cs->flags & CLOCK_SOURCE_MUST_VERIFY) {
>> /* cs is a clocksource to be watched. */
>> list_add(&cs->wd_list, &watchdog_list);
>> @@ -331,7 +347,6 @@ static void clocksource_enqueue_watchdog(struct clocksource *cs)
>> if (cs->flags & CLOCK_SOURCE_IS_CONTINUOUS)
>> cs->flags |= CLOCK_SOURCE_VALID_FOR_HRES;
>> }
>> - spin_unlock_irqrestore(&watchdog_lock, flags);
>> }
>>
>> static void clocksource_select_watchdog(bool fallback)
>> @@ -373,9 +388,6 @@ static void clocksource_select_watchdog(bool fallback)
>>
>> static void clocksource_dequeue_watchdog(struct clocksource *cs)
>> {
>> - unsigned long flags;
>> -
>> - spin_lock_irqsave(&watchdog_lock, flags);
>> if (cs != watchdog) {
>> if (cs->flags & CLOCK_SOURCE_MUST_VERIFY) {
>> /* cs is a watched clocksource. */
>> @@ -384,7 +396,6 @@ static void clocksource_dequeue_watchdog(struct clocksource *cs)
>> clocksource_stop_watchdog();
>> }
>> }
>> - spin_unlock_irqrestore(&watchdog_lock, flags);
>> }
>>
>> static int __clocksource_watchdog_kthread(void)
>> @@ -779,14 +790,19 @@ EXPORT_SYMBOL_GPL(__clocksource_update_freq_scale);
>> */
>> int __clocksource_register_scale(struct clocksource *cs, u32 scale, u32 freq)
>> {
>> + unsigned long flags;
>>
>> /* Initialize mult/shift and max_idle_ns */
>> __clocksource_update_freq_scale(cs, scale, freq);
>>
>> /* Add clocksource to the clocksource list */
>> mutex_lock(&clocksource_mutex);
>> +
>> + clocksource_watchdog_lock(&flags);
>> clocksource_enqueue(cs);
>> clocksource_enqueue_watchdog(cs);
>> + clocksource_watchdog_unlock(&flags);
>> +
>> clocksource_select();
>> clocksource_select_watchdog(false);
>> mutex_unlock(&clocksource_mutex);
>> @@ -808,8 +824,13 @@ static void __clocksource_change_rating(struct clocksource *cs, int rating)
>> */
>> void clocksource_change_rating(struct clocksource *cs, int rating)
>> {
>> + unsigned long flags;
>> +
>> mutex_lock(&clocksource_mutex);
>> + clocksource_watchdog_lock(&flags);
>> __clocksource_change_rating(cs, rating);
>> + clocksource_watchdog_unlock(&flags);
>> +
>> clocksource_select();
>> clocksource_select_watchdog(false);
>> mutex_unlock(&clocksource_mutex);
>> @@ -821,6 +842,8 @@ EXPORT_SYMBOL(clocksource_change_rating);
>> */
>> static int clocksource_unbind(struct clocksource *cs)
>> {
>> + unsigned long flags;
>> +
>> if (clocksource_is_watchdog(cs)) {
>> /* Select and try to install a replacement watchdog. */
>> clocksource_select_watchdog(true);
>> @@ -834,8 +857,12 @@ static int clocksource_unbind(struct clocksource *cs)
>> if (curr_clocksource == cs)
>> return -EBUSY;
>> }
>> +
>> + clocksource_watchdog_lock(&flags);
>> clocksource_dequeue_watchdog(cs);
>> list_del_init(&cs->list);
>> + clocksource_watchdog_lock(&flags);
>> +
>> return 0;
>> }
>>
>
> Yes, compiling the kernel (torvalds/linux.git HEAD) with your patch right now.
>
> Thanks,
> Diego

I tried your patch with 4.17-rc2 but now my system won't boot, I
believe it fails at early booting.

2018-04-23 14:02:53

by Peter Zijlstra

[permalink] [raw]
Subject: Re: Experiencing freezes with kernel 4.16.3 on a desktop with E5500 CPU (bisect included)

On Mon, Apr 23, 2018 at 02:38:47PM +0200, Peter Zijlstra wrote:
> @@ -834,8 +857,12 @@ static int clocksource_unbind(struct clocksource *cs)
> if (curr_clocksource == cs)
> return -EBUSY;
> }
> +
> + clocksource_watchdog_lock(&flags);
> clocksource_dequeue_watchdog(cs);
> list_del_init(&cs->list);
> + clocksource_watchdog_lock(&flags);

It works a lot better when this is _unlock();

> +
> return 0;
> }
>

With that, and intel_idle.c modified to always issue the "halts in
idle" thing, my IVB comes up in hpet mode. Let me dig up a Core2 era
machine and see if that works too.

2018-04-23 14:04:37

by Diego Viola

[permalink] [raw]
Subject: Re: Experiencing freezes with kernel 4.16.3 on a desktop with E5500 CPU (bisect included)

On Mon, Apr 23, 2018 at 11:00 AM, Peter Zijlstra <[email protected]> wrote:
> On Mon, Apr 23, 2018 at 02:38:47PM +0200, Peter Zijlstra wrote:
>> @@ -834,8 +857,12 @@ static int clocksource_unbind(struct clocksource *cs)
>> if (curr_clocksource == cs)
>> return -EBUSY;
>> }
>> +
>> + clocksource_watchdog_lock(&flags);
>> clocksource_dequeue_watchdog(cs);
>> list_del_init(&cs->list);
>> + clocksource_watchdog_lock(&flags);
>
> It works a lot better when this is _unlock();
>
>> +
>> return 0;
>> }
>>
>
> With that, and intel_idle.c modified to always issue the "halts in
> idle" thing, my IVB comes up in hpet mode. Let me dig up a Core2 era
> machine and see if that works too.

OK, thanks.

2018-04-23 15:13:23

by Peter Zijlstra

[permalink] [raw]
Subject: Re: Experiencing freezes with kernel 4.16.3 on a desktop with E5500 CPU (bisect included)

On Mon, Apr 23, 2018 at 04:00:52PM +0200, Peter Zijlstra wrote:
> On Mon, Apr 23, 2018 at 02:38:47PM +0200, Peter Zijlstra wrote:
> > @@ -834,8 +857,12 @@ static int clocksource_unbind(struct clocksource *cs)
> > if (curr_clocksource == cs)
> > return -EBUSY;
> > }
> > +
> > + clocksource_watchdog_lock(&flags);
> > clocksource_dequeue_watchdog(cs);
> > list_del_init(&cs->list);
> > + clocksource_watchdog_lock(&flags);
>
> It works a lot better when this is _unlock();
>
> > +
> > return 0;
> > }
> >
>
> With that, and intel_idle.c modified to always issue the "halts in
> idle" thing, my IVB comes up in hpet mode. Let me dig up a Core2 era
> machine and see if that works too.

OK, that was fairly painful, but the box managed to boot a modified
kernel and seems to function correctly, lemme try suspend/resume.



2018-04-23 16:00:17

by Peter Zijlstra

[permalink] [raw]
Subject: Re: Experiencing freezes with kernel 4.16.3 on a desktop with E5500 CPU (bisect included)

On Mon, Apr 23, 2018 at 02:38:47PM +0200, Peter Zijlstra wrote:

> @@ -142,6 +152,13 @@ static void __clocksource_unstable(struct clocksource *cs)
> cs->flags &= ~(CLOCK_SOURCE_VALID_FOR_HRES | CLOCK_SOURCE_WATCHDOG);
> cs->flags |= CLOCK_SOURCE_UNSTABLE;
>
> + if (list_empty(&cs->list)) {
> + cs->rating = 0;
> + return;
> + }
> +
> + __clocksource_change_rating(cs, 0);
> +
> if (cs->mark_unstable)
> cs->mark_unstable(cs);
>

Thomas, we could not find the de-rate stuff, but the above can be
simplified; what happens is:

cs->flags |= UNSTABLE;
schedule_work(&watchdog_work)
kthread_run(clocksource_watchdog_kthread)
__clocksource_watchdog_kthread()
if (cs->flags & UNSTABLE)
__clocksource_change_rating()
clocksource_select()


2018-04-23 16:13:45

by Diego Viola

[permalink] [raw]
Subject: Re: Experiencing freezes with kernel 4.16.3 on a desktop with E5500 CPU (bisect included)

On Mon, Apr 23, 2018 at 12:10 PM, Peter Zijlstra <[email protected]> wrote:
> On Mon, Apr 23, 2018 at 04:00:52PM +0200, Peter Zijlstra wrote:
>> On Mon, Apr 23, 2018 at 02:38:47PM +0200, Peter Zijlstra wrote:
>> > @@ -834,8 +857,12 @@ static int clocksource_unbind(struct clocksource *cs)
>> > if (curr_clocksource == cs)
>> > return -EBUSY;
>> > }
>> > +
>> > + clocksource_watchdog_lock(&flags);
>> > clocksource_dequeue_watchdog(cs);
>> > list_del_init(&cs->list);
>> > + clocksource_watchdog_lock(&flags);
>>
>> It works a lot better when this is _unlock();
>>
>> > +
>> > return 0;
>> > }
>> >
>>
>> With that, and intel_idle.c modified to always issue the "halts in
>> idle" thing, my IVB comes up in hpet mode. Let me dig up a Core2 era
>> machine and see if that works too.
>
> OK, that was fairly painful, but the box managed to boot a modified
> kernel and seems to function correctly, lemme try suspend/resume.
>
>

I can confirm that applying Peter's patch to the 4.17-rc2 kernel and
changing kernel/time/clocksource.c:864 to _unlock solves my problem.

Peter, thank you so much, I appreciate your help a lot.

Diego

2018-04-23 16:46:40

by Peter Zijlstra

[permalink] [raw]
Subject: Re: Experiencing freezes with kernel 4.16.3 on a desktop with E5500 CPU (bisect included)

On Mon, Apr 23, 2018 at 05:58:01PM +0200, Peter Zijlstra wrote:
> Thomas, we could not find the de-rate stuff, but the above can be
> simplified; what happens is:
>
> cs->flags |= UNSTABLE;
> schedule_work(&watchdog_work)
> kthread_run(clocksource_watchdog_kthread)

Also, Thomas, do you remember why we spawn a short running kthread from
a work ? Can't we simply run the whole thing from the worker thread?

> __clocksource_watchdog_kthread()
> if (cs->flags & UNSTABLE)
> __clocksource_change_rating()
> clocksource_select()
>

2018-04-24 09:26:48

by Thomas Gleixner

[permalink] [raw]
Subject: Re: Experiencing freezes with kernel 4.16.3 on a desktop with E5500 CPU (bisect included)

On Mon, 23 Apr 2018, Peter Zijlstra wrote:

> On Mon, Apr 23, 2018 at 05:58:01PM +0200, Peter Zijlstra wrote:
> > Thomas, we could not find the de-rate stuff, but the above can be
> > simplified; what happens is:
> >
> > cs->flags |= UNSTABLE;
> > schedule_work(&watchdog_work)
> > kthread_run(clocksource_watchdog_kthread)
>
> Also, Thomas, do you remember why we spawn a short running kthread from
> a work ? Can't we simply run the whole thing from the worker thread?

No. I think we did it directly in the early days and then it was changed to
that worker/thread stuff for whatever reason. I need to do git archaeology.

Thanks,

tglx