Skip to contentSkip to conversation

? system is stuck in clocksource, >60s delay at boot time without tsc=unstable

REGRESSION Applied Fab Stz 4 participants 14 messages Nov 27, 2024 – Feb 26, 2025 1 message not in the archive Intel idle driver

lore
Share & tools
lore

A message that is not in the archive (sent off-list or not yet received): [email protected]

Fab Stz

author
#1 lore raw

Hi,

While upgrading from Debian bullseye (kernel 5.10) to bookworm (6.1) I noticed that the newer kernel is at the beginning of the boot stuck for more than 60 seconds.

This is apparently related to the clocksource module. If I boot with tsc=unstable there is no more delay.

In the kernel logs, I have:

clocksource: Long readout interval, skipping watchdog check: cs_nsec: 512010551 wd_nsec: 39243763320
clocksource: timekeeping watchdog on CPU0: Marking clocksource 'tsc' as unstable because the skew is too large:
clocksource:                       'hpet' wd_nsec: 537773520 wd_now: 3f0f7632 wd_last: 3e425140 mask: ffffffff
clocksource:                       'tsc' cs_nsec: 511996079 cs_now: 18b0866e6a cs_last: 185f8d68ba mask: ffffffffffffffff
clocksource:                       'tsc' is current clocksource.
tsc: Marking TSC unstable due to clocksource watchdog

TSC found unstable after boot, most likely due to broken BIOS. Use 'tsc=unstable'.
sched_clock: Marking unstable (3765559657, 1276001)<-(3775071370, -8235646)
clocksource: Checking clocksource tsc synchronization from CPU 1 to CPUs 0.
clocksource: Switched to clocksource hpet

I already had such a warning with 5.10, but there was no >60sec freeze with it like with 6.1

The delay is still present in kernel 6.11.

I attach the output of dmesg. On screen, the last line that is displayed before being frozen for >60sec is

[    2.898668] hub 2-0:1.0: 5 ports detected

Because of that, I initially thought that there is a problem with USB, but actually not since tsc=unstable "fixes" the delay. The kernel mentions clocksource only later in the logs, but the timestamps don't reflect the delay. My last measure is a freeze of about 70seconds.

I also noticed that if during that period I do a short press on the power button of the system, it stops the freeze and the boot process continues immediately.

Regards

==== System information ====

It's an Apple iMac 9.1

# cat /proc/version
Linux version 6.1.0-28-amd64 ([email protected]) (gcc-12 (Debian 12.2.0-14) 12.2.0, GNU ld (GNU Binutils for Debian) 2.40) #1 SMP PREEMPT_DYNAMIC Debian 6.1.119-1 (2024-11-22)
# hostnamectl | grep "Operating System"
Operating System: Debian GNU/Linux 12 (bookworm)
# uname -mi
x86_64 unknown
# lspci -nn
00:00.0 Host bridge [0600]: NVIDIA Corporation MCP79 Host Bridge [10de:0a82] (rev b1)
00:00.1 RAM memory [0500]: NVIDIA Corporation MCP79 Memory Controller [10de:0a88] (rev b1)
00:03.0 ISA bridge [0601]: NVIDIA Corporation MCP79 LPC Bridge [10de:0aae] (rev b2)
00:03.1 RAM memory [0500]: NVIDIA Corporation MCP79 Memory Controller [10de:0aa4] (rev b1)
00:03.2 SMBus [0c05]: NVIDIA Corporation MCP79 SMBus [10de:0aa2] (rev b1)
00:03.3 RAM memory [0500]: NVIDIA Corporation MCP79 Memory Controller [10de:0a89] (rev b1)
00:03.4 RAM memory [0500]: NVIDIA Corporation MCP79 Memory Controller [10de:0a98] (rev b1)
00:03.5 Co-processor [0b40]: NVIDIA Corporation MCP79 Co-processor [10de:0aa3] (rev b1)
00:04.0 USB controller [0c03]: NVIDIA Corporation MCP79 OHCI USB 1.1 Controller [10de:0aa5] (rev b1)
00:04.1 USB controller [0c03]: NVIDIA Corporation MCP79 EHCI USB 2.0 Controller [10de:0aa6] (rev b1)
00:06.0 USB controller [0c03]: NVIDIA Corporation MCP79 OHCI USB 1.1 Controller [10de:0aa7] (rev b1)
00:06.1 USB controller [0c03]: NVIDIA Corporation MCP79 EHCI USB 2.0 Controller [10de:0aa9] (rev b1)
00:08.0 Audio device [0403]: NVIDIA Corporation MCP79 High Definition Audio [10de:0ac0] (rev b1)
00:09.0 PCI bridge [0604]: NVIDIA Corporation MCP79 PCI Bridge [10de:0aab] (rev b1)
00:0a.0 Ethernet controller [0200]: NVIDIA Corporation MCP79 Ethernet [10de:0ab0] (rev b1)
00:0b.0 SATA controller [0106]: NVIDIA Corporation MCP79 AHCI Controller [10de:0ab9] (rev b1)
00:0c.0 PCI bridge [0604]: NVIDIA Corporation MCP79 PCI Express Bridge [10de:0ac4] (rev b1)
00:10.0 PCI bridge [0604]: NVIDIA Corporation MCP79 PCI Express Bridge [10de:0aa0] (rev b1)
00:15.0 PCI bridge [0604]: NVIDIA Corporation MCP79 PCI Express Bridge [10de:0ac6] (rev b1)
00:16.0 PCI bridge [0604]: NVIDIA Corporation MCP79 PCI Express Bridge [10de:0ac7] (rev b1)
03:00.0 VGA compatible controller [0300]: NVIDIA Corporation C79 [GeForce 9400] [10de:0867] (rev b1)
04:00.0 Network controller [0280]: Broadcom Inc. and subsidiaries BCM4322 802.11a/b/g/n Wireless LAN Controller [14e4:432b] (rev 01)
05:00.0 FireWire (IEEE 1394) [0c00]: LSI Corporation FW643 [TrueFire] PCIe 1394b Controller [11c1:5901] (rev 07)
author
#2 lore raw

Hello,

It's been one month now that I sent this email. Do you have any clue on this?

Regards
Fab

Quoted 110 lines · Le mercredi 27 novembre 2024, 08:18:41 CET Fab Stz a écrit :

Hi,

While upgrading from Debian bullseye (kernel 5.10) to bookworm (6.1) I noticed that the newer kernel is at the beginning of the boot stuck for more than 60 seconds.

This is apparently related to the clocksource module. If I boot with tsc=unstable there is no more delay.

In the kernel logs, I have:

clocksource: Long readout interval, skipping watchdog check: cs_nsec:
512010551 wd_nsec: 39243763320
clocksource: timekeeping watchdog on CPU0: Marking clocksource 'tsc' as unstable because the skew is too large:
clocksource: 'hpet' wd_nsec: 537773520 wd_now:
3f0f7632 wd_last: 3e425140 mask: ffffffff
clocksource: 'tsc' cs_nsec: 511996079 cs_now:
18b0866e6a cs_last: 185f8d68ba mask: ffffffffffffffff
clocksource: 'tsc' is current clocksource.
tsc: Marking TSC unstable due to clocksource watchdog
TSC found unstable after boot, most likely due to broken BIOS. Use 'tsc=unstable'.
sched_clock: Marking unstable (3765559657, 1276001)<-(3775071370, -8235646)
clocksource: Checking clocksource tsc synchronization from CPU 1 to CPUs 0.
clocksource: Switched to clocksource hpet

I already had such a warning with 5.10, but there was no >60sec freeze with it like with 6.1

The delay is still present in kernel 6.11.

I attach the output of dmesg. On screen, the last line that is displayed before being frozen for >60sec is

[    2.898668] hub 2-0:1.0: 5 ports detected

Because of that, I initially thought that there is a problem with USB, but actually not since tsc=unstable "fixes" the delay. The kernel mentions clocksource only later in the logs, but the timestamps don't reflect the delay. My last measure is a freeze of about 70seconds.

I also noticed that if during that period I do a short press on the power button of the system, it stops the freeze and the boot process continues immediately.

Regards

==== System information ====

It's an Apple iMac 9.1

# cat /proc/version
Linux version 6.1.0-28-amd64 ([email protected]) (gcc-12
(Debian 12.2.0-14) 12.2.0, GNU ld (GNU Binutils for Debian) 2.40) #1 SMP
PREEMPT_DYNAMIC Debian 6.1.119-1 (2024-11-22)
# hostnamectl | grep "Operating System"
Operating System: Debian GNU/Linux 12 (bookworm)
# uname -mi
x86_64 unknown
# lspci -nn
00:00.0 Host bridge [0600]: NVIDIA Corporation MCP79 Host Bridge
[10de:0a82] (rev b1)
00:00.1 RAM memory [0500]: NVIDIA Corporation MCP79 Memory Controller
[10de:0a88] (rev b1)
00:03.0 ISA bridge [0601]: NVIDIA Corporation MCP79 LPC Bridge
[10de:0aae] (rev b2)
00:03.1 RAM memory [0500]: NVIDIA Corporation MCP79 Memory Controller
[10de:0aa4] (rev b1)
00:03.2 SMBus [0c05]: NVIDIA Corporation MCP79 SMBus [10de:0aa2] (rev b1)
00:03.3 RAM memory [0500]: NVIDIA Corporation MCP79 Memory Controller
[10de:0a89] (rev b1)
00:03.4 RAM memory [0500]: NVIDIA Corporation MCP79 Memory Controller
[10de:0a98] (rev b1)
00:03.5 Co-processor [0b40]: NVIDIA Corporation MCP79 Co-processor
[10de:0aa3] (rev b1)
00:04.0 USB controller [0c03]: NVIDIA Corporation MCP79 OHCI USB 1.1
Controller [10de:0aa5] (rev b1)
00:04.1 USB controller [0c03]: NVIDIA Corporation MCP79 EHCI USB 2.0
Controller [10de:0aa6] (rev b1)
00:06.0 USB controller [0c03]: NVIDIA Corporation MCP79 OHCI USB 1.1
Controller [10de:0aa7] (rev b1)
00:06.1 USB controller [0c03]: NVIDIA Corporation MCP79 EHCI USB 2.0
Controller [10de:0aa9] (rev b1)
00:08.0 Audio device [0403]: NVIDIA Corporation MCP79 High Definition
Audio [10de:0ac0] (rev b1)
00:09.0 PCI bridge [0604]: NVIDIA Corporation MCP79 PCI Bridge
[10de:0aab] (rev b1)
00:0a.0 Ethernet controller [0200]: NVIDIA Corporation MCP79 Ethernet
[10de:0ab0] (rev b1)
00:0b.0 SATA controller [0106]: NVIDIA Corporation MCP79 AHCI Controller
[10de:0ab9] (rev b1)
00:0c.0 PCI bridge [0604]: NVIDIA Corporation MCP79 PCI Express Bridge
[10de:0ac4] (rev b1)
00:10.0 PCI bridge [0604]: NVIDIA Corporation MCP79 PCI Express Bridge
[10de:0aa0] (rev b1)
00:15.0 PCI bridge [0604]: NVIDIA Corporation MCP79 PCI Express Bridge
[10de:0ac6] (rev b1)
00:16.0 PCI bridge [0604]: NVIDIA Corporation MCP79 PCI Express Bridge
[10de:0ac7] (rev b1)
03:00.0 VGA compatible controller [0300]: NVIDIA Corporation C79
[GeForce 9400] [10de:0867] (rev b1)
04:00.0 Network controller [0280]: Broadcom Inc. and subsidiaries
BCM4322 802.11a/b/g/n Wireless LAN Controller [14e4:432b] (rev 01)
05:00.0 FireWire (IEEE 1394) [0c00]: LSI Corporation FW643 [TrueFire]
PCIe 1394b Controller [11c1:5901] (rev 07)
#3 lore raw
Quoted 4 lines · Fab Stz

Hello,

It's been one month now that I sent this email. Do you have any clue on this?

Apologies you didn't get a quick response, but you didn't really cc many people on the first one.

Quoted 29 lines · Le mercredi 27 novembre 2024, 08:18:41 CET Fab Stz a écrit :
Quoted 28 lines

Hi,

While upgrading from Debian bullseye (kernel 5.10) to bookworm (6.1) I noticed that the newer kernel is at the beginning of the boot stuck for more than 60 seconds.

This is apparently related to the clocksource module. If I boot with tsc=unstable there is no more delay.

In the kernel logs, I have:

clocksource: Long readout interval, skipping watchdog check: cs_nsec:
512010551 wd_nsec: 39243763320
clocksource: timekeeping watchdog on CPU0: Marking clocksource 'tsc' as unstable because the skew is too large:
clocksource: 'hpet' wd_nsec: 537773520 wd_now:
3f0f7632 wd_last: 3e425140 mask: ffffffff
clocksource: 'tsc' cs_nsec: 511996079 cs_now:
18b0866e6a cs_last: 185f8d68ba mask: ffffffffffffffff
clocksource: 'tsc' is current clocksource.
tsc: Marking TSC unstable due to clocksource watchdog
TSC found unstable after boot, most likely due to broken BIOS. Use 'tsc=unstable'.
sched_clock: Marking unstable (3765559657, 1276001)<-(3775071370, -8235646)
clocksource: Checking clocksource tsc synchronization from CPU 1 to CPUs 0.
clocksource: Switched to clocksource hpet

Quoted 2 lines
Quoted 2 lines

I already had such a warning with 5.10, but there was no >60sec freeze with it like with 6.1

So, it sounds like your TSC stalls in idle (likely missing X86_FEATURE_NONSTOP_TSC), and probably something between 5.10 and 6.1 added a sleep which causes the stall before the clocksource watchdog can check and disable the TSC on its own.

The kernel is telling you tsc=unstable is the way to go here, and it seems that is working for you. From my first glance, I'd not call this a regression, as the kernel was warning you about the problematic hardware before, and it was most likely just luck that it was able to auto-detect the problem before there were any negative results.

That said, if you're still curious, you might try bisecting kernel versions between 5.10 and 6.1 to see which commit might have caused the change in behavior.

thanks
-john

#4 lore raw
Quoted 48 lines · John Stultz
Quoted 4 lines · Fab Stz

Hello,

It's been one month now that I sent this email. Do you have any clue on this?

Apologies you didn't get a quick response, but you didn't really cc many people on the first one.

Quoted 29 lines · Le mercredi 27 novembre 2024, 08:18:41 CET Fab Stz a écrit :
Quoted 28 lines

Hi,

While upgrading from Debian bullseye (kernel 5.10) to bookworm (6.1) I noticed that the newer kernel is at the beginning of the boot stuck for more than 60 seconds.

This is apparently related to the clocksource module. If I boot with tsc=unstable there is no more delay.

In the kernel logs, I have:

clocksource: Long readout interval, skipping watchdog check: cs_nsec:
512010551 wd_nsec: 39243763320
clocksource: timekeeping watchdog on CPU0: Marking clocksource 'tsc' as unstable because the skew is too large:
clocksource: 'hpet' wd_nsec: 537773520 wd_now:
3f0f7632 wd_last: 3e425140 mask: ffffffff
clocksource: 'tsc' cs_nsec: 511996079 cs_now:
18b0866e6a cs_last: 185f8d68ba mask: ffffffffffffffff
clocksource: 'tsc' is current clocksource.
tsc: Marking TSC unstable due to clocksource watchdog
TSC found unstable after boot, most likely due to broken BIOS. Use 'tsc=unstable'.
sched_clock: Marking unstable (3765559657, 1276001)<-(3775071370, -8235646)
clocksource: Checking clocksource tsc synchronization from CPU 1 to CPUs 0.
clocksource: Switched to clocksource hpet

Quoted 2 lines
Quoted 2 lines

I already had such a warning with 5.10, but there was no >60sec freeze with it like with 6.1

So, it sounds like your TSC stalls in idle (likely missing X86_FEATURE_NONSTOP_TSC), and probably something between 5.10 and 6.1 added a sleep which causes the stall before the clocksource watchdog can check and disable the TSC on its own.

Quoted 5 lines

The kernel is telling you tsc=unstable is the way to go here, and it seems that is working for you. From my first glance, I'd not call this a regression, as the kernel was warning you about the problematic hardware before, and it was most likely just luck that it was able to auto-detect the problem before there were any negative results.

Debian even suggests this for the iMac9,1 hardware you're using:
https://wiki.debian.org/InstallingDebianOn/Apple/iMac/9-1#Boot_on_installer

And highlights the exact behavior you describe (maybe this is your efforts?):
https://wiki.debian.org/InstallingDebianOn/Apple/iMac/9-1#Kernel_configuration

thanks
-john

author
#5 lore raw

Hello John,

Le 02/01/2025 à 22:56, John Stultz a écrit :

Quoted 10 lines · John Stultz
Quoted 9 lines · Fab Stz
Quoted 4 lines

Hello,

It's been one month now that I sent this email. Do you have any clue on this?

Apologies you didn't get a quick response, but you didn't really cc many people on the first one.

No problem. I thought it was better not to put too many people in copy in the first message given that it was also sent to the mailing list.

Quoted 43 lines
Quoted 37 lines
Quoted 29 lines · Le mercredi 27 novembre 2024, 08:18:41 CET Fab Stz a écrit :
Quoted 28 lines

Hi,

While upgrading from Debian bullseye (kernel 5.10) to bookworm (6.1) I noticed that the newer kernel is at the beginning of the boot stuck for more than 60 seconds.

This is apparently related to the clocksource module. If I boot with tsc=unstable there is no more delay.

In the kernel logs, I have:

clocksource: Long readout interval, skipping watchdog check: cs_nsec:
512010551 wd_nsec: 39243763320
clocksource: timekeeping watchdog on CPU0: Marking clocksource 'tsc' as unstable because the skew is too large:
clocksource: 'hpet' wd_nsec: 537773520 wd_now:
3f0f7632 wd_last: 3e425140 mask: ffffffff
clocksource: 'tsc' cs_nsec: 511996079 cs_now:
18b0866e6a cs_last: 185f8d68ba mask: ffffffffffffffff
clocksource: 'tsc' is current clocksource.
tsc: Marking TSC unstable due to clocksource watchdog
TSC found unstable after boot, most likely due to broken BIOS. Use 'tsc=unstable'.
sched_clock: Marking unstable (3765559657, 1276001)<-(3775071370, -8235646)
clocksource: Checking clocksource tsc synchronization from CPU 1 to CPUs 0.
clocksource: Switched to clocksource hpet

Quoted 2 lines
Quoted 2 lines

I already had such a warning with 5.10, but there was no >60sec freeze with it like with 6.1

So, it sounds like your TSC stalls in idle (likely missing X86_FEATURE_NONSTOP_TSC), and probably something between 5.10 and 6.1 added a sleep which causes the stall before the clocksource watchdog can check and disable the TSC on its own.

Quoted 5 lines

The kernel is telling you tsc=unstable is the way to go here, and it seems that is working for you. From my first glance, I'd not call this a regression, as the kernel was warning you about the problematic hardware before, and it was most likely just luck that it was able to auto-detect the problem before there were any negative results.

Quoted 5 lines

Debian even suggests this for the iMac9,1 hardware you're using:
https://wiki.debian.org/InstallingDebianOn/Apple/iMac/9-1#Boot_on_installer

And highlights the exact behavior you describe (maybe this is your efforts?):
https://wiki.debian.org/InstallingDebianOn/Apple/iMac/9-1#Kernel_configuration

I'm the author of that page on the debian wiki, indeed.

My findings are as follows:

* No delay with the following kernel versions shipped by debian (when run on up-to-date bookworm as of today) 5.10.226, 5.19.11, 6.0.10, 6.1.4, 6.1.27, 6.1.38, 6.1.66, 6.1.76, 6.1.82

* Delay with the following kernel versions:
5.15.15, 6.1.85, 6.1.119

So something probably happened between 6.1.82 & 6.1.85 (debian doesn't ship packages for versions between them). Why 5.15.15 also has a delay is not clear.

For the versions where there is a delay, the warning from clocksource mentioning an unstable clock always comes after the first line that mentions USB "ACPI: bus type USB registered".

For the versions which don't have a boot delay, the warning from clocksource mentioning an unstable clock always comes before the first line that mentions USB "ACPI: bus type USB registered".

However, with 6.1.82, sometimes the unstable clocksource message comes after the USB line, but when this happens, both messages are very close in time (less than 50ms?) so that the subsequent usb messages always appear after the clocksource message. So the return from the clocksource might be early enough to not encounter the lock.

Actually, the lock is usually bit later than the "ACPI: bus type USB registered", and the message at the time of the lock is related to USB.

Moreover, whether there is a boot delay or not:

- the line "ACPI: bus type USB registered" always comes after "Run /init as init process"

- the warning from clocksource mentioning an unstable clock may or may not be after "Run /init as init process"

Could it be that USB should not be registered/loaded before it was determined whether clocksource is unstable or not?

Regards
Fab

#6 lore raw
Quoted 13 lines · Fab Stz
Quoted 12 lines · John Stultz
Quoted 10 lines · John Stultz

So, it sounds like your TSC stalls in idle (likely missing X86_FEATURE_NONSTOP_TSC), and probably something between 5.10 and 6.1 added a sleep which causes the stall before the clocksource watchdog can check and disable the TSC on its own.

The kernel is telling you tsc=unstable is the way to go here, and it seems that is working for you. From my first glance, I'd not call this a regression, as the kernel was warning you about the problematic hardware before, and it was most likely just luck that it was able to auto-detect the problem before there were any negative results.

Quoted 8 lines
Quoted 5 lines

Debian even suggests this for the iMac9,1 hardware you're using:
https://wiki.debian.org/InstallingDebianOn/Apple/iMac/9-1#Boot_on_installer

And highlights the exact behavior you describe (maybe this is your efforts?):
https://wiki.debian.org/InstallingDebianOn/Apple/iMac/9-1#Kernel_configuration

I'm the author of that page on the debian wiki, indeed.

Heh. It sounded suspiciously similar :)

Quoted 6 lines

My findings are as follows:

* No delay with the following kernel versions shipped by debian (when run on up-to-date bookworm as of today)
5.10.226, 5.19.11, 6.0.10, 6.1.4, 6.1.27, 6.1.38, 6.1.66, 6.1.76, 6.1.82

Quoted 6 lines

* Delay with the following kernel versions:
5.15.15, 6.1.85, 6.1.119

So something probably happened between 6.1.82 & 6.1.85 (debian doesn't ship packages for versions between them). Why 5.15.15 also has a delay is not clear.

So from a quick scan of the v6.1.82..v6.1.85 delta around timekeeping, usb and ACPI, I don't see anything obviously sticking out.

I suspect to get a finer sense of it, you'll need to be able to build and test specific kernel versions so the change in behavior can be properly bisected.

Quoted 7 lines

For the versions where there is a delay, the warning from clocksource mentioning an unstable clock always comes after the first line that mentions USB "ACPI: bus type USB registered".

For the versions which don't have a boot delay, the warning from clocksource mentioning an unstable clock always comes before the first line that mentions USB "ACPI: bus type USB registered".

So for this sort of debugging, it can be helpful to boot with "initcall_debug loglevel=8" boot arguments.

Quoted 9 lines

However, with 6.1.82, sometimes the unstable clocksource message comes after the USB line, but when this happens, both messages are very close in time (less than 50ms?) so that the subsequent usb messages always appear after the clocksource message. So the return from the clocksource might be early enough to not encounter the lock.

Actually, the lock is usually bit later than the "ACPI: bus type USB registered", and the message at the time of the lock is related to USB.

Quoted 7 lines

Moreover, whether there is a boot delay or not:

- the line "ACPI: bus type USB registered" always comes after "Run /init as init process"

- the warning from clocksource mentioning an unstable clock may or may not be after "Run /init as init process"

Thanks for the extra details here. Though I don't have much of an idea right off. There could be other indirect changes that can cause these things (cpuidle tweaks to how deep the cpu sleeps, etc). Bisection is probably the most foolproof method of narrowing this down.

Quoted 2 lines

Could it be that USB should not be registered/loaded before it was determined whether clocksource is unstable or not?

Ideally, but testing the clocksource takes time, and as we are optimizing for the case where the hardware works properly, we don't want to delay booting for everyone. There might be other approaches, like not selecting the TSC until its proven itself stable, but that opens a whole different can of worms for systems where the TSC was fine but the other clocksources (like HPET or ACPI PM) were buggy, effectively moving your regression to someone else.

Booting with "tsc=unstable" or possibly in your case "processor.max_cstate=1" (it's been awhile since I tried it, but it should keep the cpu out of deep idle where the TSC halts) are likely the best workarounds.

thanks
-john

author
#7 lore raw
Quoted 66 lines · John Stultz
Quoted 6 lines · Fab Stz

My findings are as follows:

* No delay with the following kernel versions shipped by debian (when run on up-to-date bookworm as of today)
5.10.226, 5.19.11, 6.0.10, 6.1.4, 6.1.27, 6.1.38, 6.1.66, 6.1.76, 6.1.82

Quoted 6 lines

* Delay with the following kernel versions:
5.15.15, 6.1.85, 6.1.119

So something probably happened between 6.1.82 & 6.1.85 (debian doesn't ship packages for versions between them). Why 5.15.15 also has a delay is not clear.

So from a quick scan of the v6.1.82..v6.1.85 delta around timekeeping, usb and ACPI, I don't see anything obviously sticking out.

I suspect to get a finer sense of it, you'll need to be able to build and test specific kernel versions so the change in behavior can be properly bisected.

Quoted 7 lines

For the versions where there is a delay, the warning from clocksource mentioning an unstable clock always comes after the first line that mentions USB "ACPI: bus type USB registered".

For the versions which don't have a boot delay, the warning from clocksource mentioning an unstable clock always comes before the first line that mentions USB "ACPI: bus type USB registered".

So for this sort of debugging, it can be helpful to boot with "initcall_debug loglevel=8" boot arguments.

Quoted 9 lines

However, with 6.1.82, sometimes the unstable clocksource message comes after the USB line, but when this happens, both messages are very close in time (less than 50ms?) so that the subsequent usb messages always appear after the clocksource message. So the return from the clocksource might be early enough to not encounter the lock.

Actually, the lock is usually bit later than the "ACPI: bus type USB registered", and the message at the time of the lock is related to USB.

Quoted 7 lines

Moreover, whether there is a boot delay or not:

- the line "ACPI: bus type USB registered" always comes after "Run /init as init process"

- the warning from clocksource mentioning an unstable clock may or may not be after "Run /init as init process"

Thanks for the extra details here. Though I don't have much of an idea right off. There could be other indirect changes that can cause these things (cpuidle tweaks to how deep the cpu sleeps, etc). Bisection is probably the most foolproof method of narrowing this down.

Quoted 2 lines

Could it be that USB should not be registered/loaded before it was determined whether clocksource is unstable or not?

Ideally, but testing the clocksource takes time, and as we are optimizing for the case where the hardware works properly, we don't want to delay booting for everyone. There might be other approaches, like not selecting the TSC until its proven itself stable, but that opens a whole different can of worms for systems where the TSC was fine but the other clocksources (like HPET or ACPI PM) were buggy, effectively moving your regression to someone else.

Quoted 4 lines

Booting with "tsc=unstable" or possibly in your case "processor.max_cstate=1" (it's been awhile since I tried it, but it should keep the cpu out of deep idle where the TSC halts) are likely the best workarounds.

When building the kernel from the sources from the stable repo of the kernel to try a git bisect I couldn't reproduce a case where the warning is before loading '/init' with the versions I mentioned as working. Maybe I was just lucky as you mentioned. If the warning comes before the loading of USB modules, there is no delay. If it comes after, there is a delay.

If I break/pause at the beginning of the /init script, the warning never comes before. I don't really understand what is happening and where the problem actually lies (kernel? systemd? udev? somewhere else?). If I add a "sleep 5" as 1st command in "/init" it would take ages. So as long as the warning from the clocksource is not displayed, the delays seem completely wrong. Maybe the USB drivers somehow rely on a reliable clock source for proper functioning.

BTW, I tried the "processor.max_cstate=1" you mentioned but it didn't change anything on the delay and/or warning.

Regards
Fab

#8 lore raw
Quoted 7 lines · Fab Stz

Le 03/01/2025 à 20:02, John Stultz a écrit :
When building the kernel from the sources from the stable repo of the kernel to try a git bisect I couldn't reproduce a case where the warning is before loading '/init' with the versions I mentioned as working. Maybe I was just lucky as you mentioned. If the warning comes before the loading of USB modules, there is no delay. If it comes after, there is a delay.

This is a timing problem, which depends on kernel configuration and run-time differences, but that's just a symptom. It explains why you are seeing it sometimes and sometimes not. Nothing else.

Quoted 6 lines

If I break/pause at the beginning of the /init script, the warning never comes before. I don't really understand what is happening and where the problem actually lies (kernel? systemd? udev? somewhere else?). If I add a "sleep 5" as 1st command in "/init" it would take ages. So as long as the warning from the clocksource is not displayed, the delays seem completely wrong.

That's an interesting data point because that 'sleep 5' puts the system into idle and probably into deep idle for the first time during boot.

Quoted 2 lines

Maybe the USB drivers somehow rely on a reliable clock source for proper functioning.

The kernel relies on a reliable clocksource. Loading the USB driver merely exposes the problem because it probably causes a long enough delay to get the CPUs into a state which exposes the issue.

AFAICT, that iMac 9.1 is Core 2 Duo based and that generation of processors definitely had issues with the TSC in deeper idle states.

Quoted 2 lines

BTW, I tried the "processor.max_cstate=1" you mentioned but it didn't change anything on the delay and/or warning.

That's weird, but we have no idea what kind of magic the BIOS implements there for power management behind the kernels back. I assume that it does because this generation of CPUs uses the ACPI processor idle driver and that disables TSC when it detects that the system supports C-states > 1.

# cat /sys/devices/system/cpu/cpuidle/

tells which idle driver is actually in use.

# ls /sys/devices/system/cpu/cpu0/cpuidle/

tells which states are supported by the driver

# cat /sys/devices/system/cpu/cpu0/cpuidle/state$N/name
# cat /sys/devices/system/cpu/cpu0/cpuidle/state$N/disable

tells the actual C-state name and the disabled state, but I expect that there is nothing to see.

Can you try 'idle=halt' instead?

Thanks,

tglx

author
#9 lore raw

Dear Thomas,

I eventually could proceed with the suggested checks. See below.

Le 15/01/2025 à 17:59, Thomas Gleixner a écrit :

Quoted 9 lines
Quoted 2 lines

Maybe the USB drivers somehow rely on a reliable clock source for proper functioning.

The kernel relies on a reliable clocksource. Loading the USB driver merely exposes the problem because it probably causes a long enough delay to get the CPUs into a state which exposes the issue.

AFAICT, that iMac 9.1 is Core 2 Duo based and that generation of processors definitely had issues with the TSC in deeper idle states.

Indeed, cpuinfo reports:

model name : Intel(R) Core(TM)2 Duo CPU E8135 @ 2.66GHz

Quoted 15 lines
Quoted 2 lines

BTW, I tried the "processor.max_cstate=1" you mentioned but it didn't change anything on the delay and/or warning.

That's weird, but we have no idea what kind of magic the BIOS implements there for power management behind the kernels back. I assume that it does because this generation of CPUs uses the ACPI processor idle driver and that disables TSC when it detects that the system supports C-states > 1.

# cat /sys/devices/system/cpu/cpuidle/

tells which idle driver is actually in use.

# ls /sys/devices/system/cpu/cpu0/cpuidle/
Quoted 7 lines

tells which states are supported by the driver

# cat /sys/devices/system/cpu/cpu0/cpuidle/state$N/name
# cat /sys/devices/system/cpu/cpu0/cpuidle/state$N/disable

tells the actual C-state name and the disabled state, but I expect that there is nothing to see.

Output of these commands can be found in attached file cpuidle.txt

Quoted 1 line

Can you try 'idle=halt' instead?

When using idle=halt (without tsc=unstable) I haven't encountered the delay.

Extract of the kernel log can be found in attached file kernel_log_idle=halt.txt I also attach it for when using tsc=unstable & wihtout any of these two.

So, which parameter is most suitable for this CPU/system?

Can the kernel be patched so that the proper config is used automatically (ie. without the user having to set any parameter)? I'm not sure my question actually makes sense.

Thank you, & regards.
Fab

######## When run in kernel with tsc=unstable trace_clock=global ########

+ cat /sys/devices/system/cpu/cpuidle/available_governors ladder menu
+ cat /sys/devices/system/cpu/cpuidle/current_driver intel_idle
+ cat /sys/devices/system/cpu/cpuidle/current_governor menu
+ cat /sys/devices/system/cpu/cpuidle/current_governor_ro menu
+ ls /sys/devices/system/cpu/cpu0/cpuidle/ state0 state1 state2 state3
+ cat /sys/devices/system/cpu/cpu0/cpuidle/state0/name POLL
+ cat /sys/devices/system/cpu/cpu0/cpuidle/state0/disable 0
+ cat /sys/devices/system/cpu/cpu0/cpuidle/state1/name C1_ACPI
+ cat /sys/devices/system/cpu/cpu0/cpuidle/state1/disable 0
+ cat /sys/devices/system/cpu/cpu0/cpuidle/state2/name C2_ACPI
+ cat /sys/devices/system/cpu/cpu0/cpuidle/state2/disable 0
+ cat /sys/devices/system/cpu/cpu0/cpuidle/state3/name C3_ACPI
+ cat /sys/devices/system/cpu/cpu0/cpuidle/state3/disable 0

######## When run in kernel with idle=halt ########
+ cat /sys/devices/system/cpu/cpuidle/available_governors
ladder menu
+ cat /sys/devices/system/cpu/cpuidle/current_driver
none
+ cat /sys/devices/system/cpu/cpuidle/current_governor
menu
+ cat /sys/devices/system/cpu/cpuidle/current_governor_ro
menu
+ ls /sys/devices/system/cpu/cpu0/cpuidle/
ls: cannot access '/sys/devices/system/cpu/cpu0/cpuidle/': No such file or directory
+ cat /sys/devices/system/cpu/cpu0/cpuidle/state0/name
cat: /sys/devices/system/cpu/cpu0/cpuidle/state0/name: No such file or directory
+ cat /sys/devices/system/cpu/cpu0/cpuidle/state0/disable
cat: /sys/devices/system/cpu/cpu0/cpuidle/state0/disable: No such file or directory
+ cat /sys/devices/system/cpu/cpu0/cpuidle/state1/name
cat: /sys/devices/system/cpu/cpu0/cpuidle/state1/name: No such file or directory
+ cat /sys/devices/system/cpu/cpu0/cpuidle/state1/disable
cat: /sys/devices/system/cpu/cpu0/cpuidle/state1/disable: No such file or directory
+ cat /sys/devices/system/cpu/cpu0/cpuidle/state2/name
cat: /sys/devices/system/cpu/cpu0/cpuidle/state2/name: No such file or directory
+ cat /sys/devices/system/cpu/cpu0/cpuidle/state2/disable
cat: /sys/devices/system/cpu/cpu0/cpuidle/state2/disable: No such file or directory
+ cat /sys/devices/system/cpu/cpu0/cpuidle/state3/name
cat: /sys/devices/system/cpu/cpu0/cpuidle/state3/name: No such file or directory
+ cat /sys/devices/system/cpu/cpu0/cpuidle/state3/disable
cat: /sys/devices/system/cpu/cpu0/cpuidle/state3/disable: No such file or directory

######## When run in kernel WITHOUT idle=halt & WITHOUT tsc=unstable ########

+ cat /sys/devices/system/cpu/cpuidle/available_governors ladder menu
+ cat /sys/devices/system/cpu/cpuidle/current_driver intel_idle
+ cat /sys/devices/system/cpu/cpuidle/current_governor menu
+ cat /sys/devices/system/cpu/cpuidle/current_governor_ro menu
+ ls /sys/devices/system/cpu/cpu0/cpuidle/ state0 state1 state2 state3
+ cat /sys/devices/system/cpu/cpu0/cpuidle/state0/name POLL
+ cat /sys/devices/system/cpu/cpu0/cpuidle/state0/disable 0
+ cat /sys/devices/system/cpu/cpu0/cpuidle/state1/name C1_ACPI
+ cat /sys/devices/system/cpu/cpu0/cpuidle/state1/disable 0
+ cat /sys/devices/system/cpu/cpu0/cpuidle/state2/name C2_ACPI
+ cat /sys/devices/system/cpu/cpu0/cpuidle/state2/disable 0
+ cat /sys/devices/system/cpu/cpu0/cpuidle/state3/name C3_ACPI
+ cat /sys/devices/system/cpu/cpu0/cpuidle/state3/disable 0

Feb 23 17:41:27 debian kernel: Command line: root=UUID=462f57b4-136e-4c18-8c55-e4bc59cfb7aa ro idle=halt swap.enabled=1 mem_sleep_default=deep module_blacklist=nouveau initrd=boot\initrd.img-6.1.0-28-amd64
Feb 23 17:41:27 debian kernel: tsc: Fast TSC calibration using PIT
Feb 23 17:41:27 debian kernel: tsc: Detected 2653.370 MHz processor
Feb 23 17:41:27 debian kernel: clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645519600211568 ns
Feb 23 17:41:27 debian kernel: Kernel command line: root=UUID=462f57b4-136e-4c18-8c55-e4bc59cfb7aa ro idle=halt swap.enabled=1 mem_sleep_default=deep module_blacklist=nouveau initrd=boot\initrd.img-6.1.0-28-amd64
Feb 23 17:41:27 debian kernel: clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 76450417870 ns
Feb 23 17:41:27 debian kernel: clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x263f2cb57f4, max_idle_ns: 440795235998 ns
Feb 23 17:41:27 debian kernel: clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
Feb 23 17:41:27 debian kernel: clocksource: Switched to clocksource tsc-early
Feb 23 17:41:27 debian kernel: clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
Feb 23 17:41:27 debian kernel: tsc: Refined TSC clocksource calibration: 2653.335 MHz
Feb 23 17:41:27 debian kernel: clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x263f0bda6a8, max_idle_ns: 440795254345 ns
Feb 23 17:41:27 debian kernel: clocksource: Switched to clocksource tsc
Feb 23 17:33:21 debian kernel: Command line: root=UUID=462f57b4-136e-4c18-8c55-e4bc59cfb7aa ro tsc=unstable trace_clock=global quiet zswap.enabled=1 mem_sleep_default=deep module_blacklist=nouveau initrd=boot\initrd.img-6.1.0-28-amd64
Feb 23 17:33:21 debian kernel: tsc: Fast TSC calibration using PIT
Feb 23 17:33:21 debian kernel: tsc: Detected 2653.373 MHz processor
Feb 23 17:33:21 debian kernel: clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645519600211568 ns
Feb 23 17:33:21 debian kernel: Kernel command line: root=UUID=462f57b4-136e-4c18-8c55-e4bc59cfb7aa ro tsc=unstable trace_clock=global quiet zswap.enabled=1 mem_sleep_default=deep module_blacklist=nouveau initrd=boot\initrd.img-6.1.0-28-amd64
Feb 23 17:33:21 debian kernel: tsc: Marking TSC unstable due to boot parameter
Feb 23 17:33:21 debian kernel: clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 76450417870 ns
Feb 23 17:33:21 debian kernel: clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
Feb 23 17:33:21 debian kernel: clocksource: Switched to clocksource hpet
Feb 23 17:33:21 debian kernel: clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
Feb 23 17:46:41 debian kernel: Command line: root=UUID=462f57b4-136e-4c18-8c55-e4bc59cfb7aa ro zswap.enabled=1 mem_sleep_default=deep module_blacklist=nouveau initrd=boot\initrd.img-6.1.0-28-amd64                                      
Feb 23 17:46:41 debian kernel: tsc: Fast TSC calibration using PIT
Feb 23 17:46:41 debian kernel: tsc: Detected 2653.319 MHz processor
Feb 23 17:46:41 debian kernel: clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645519600211568 ns
Feb 23 17:46:41 debian kernel: Kernel command line: root=UUID=462f57b4-136e-4c18-8c55-e4bc59cfb7aa ro zswap.enabled=1 mem_sleep_default=deep module_blacklist=nouveau initrd=boot\initrd.img-6.1.0-28-amd64                                      
Feb 23 17:46:41 debian kernel: clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 76450417870 ns
Feb 23 17:46:41 debian kernel: clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x263efc7f39c, max_idle_ns: 440795295273 ns
Feb 23 17:46:41 debian kernel: clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
Feb 23 17:46:41 debian kernel: clocksource: Switched to clocksource tsc-early
Feb 23 17:46:41 debian kernel: clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
Feb 23 17:46:41 debian kernel: tsc: Refined TSC clocksource calibration: 2653.335 MHz
Feb 23 17:46:41 debian kernel: clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x263f0bda6a8, max_idle_ns: 440795254345 ns
Feb 23 17:46:41 debian kernel: clocksource: Switched to clocksource tsc
Feb 23 17:46:41 debian kernel: clocksource: Long readout interval, skipping watchdog check: cs_nsec: 512005976 wd_nsec: 20666406840
Feb 23 17:46:41 debian kernel: clocksource: timekeeping watchdog on CPU0: Marking clocksource 'tsc' as unstable because the skew is too large:
Feb 23 17:46:41 debian kernel: clocksource:                       'hpet' wd_nsec: 790554840 wd_now: 23c18feb wd_last: 2293fd4c mask: ffffffff
Feb 23 17:46:41 debian kernel: clocksource:                       'tsc' cs_nsec: 511994526 cs_now: 1b57fd14b2 cs_last: 1b07041f1a mask: ffffffffffffffff
Feb 23 17:46:41 debian kernel: clocksource:                       'tsc' is current clocksource.
Feb 23 17:46:41 debian kernel: tsc: Marking TSC unstable due to clocksource watchdog
Feb 23 17:46:41 debian kernel: TSC found unstable after boot, most likely due to broken BIOS. Use 'tsc=unstable'.
Feb 23 17:46:41 debian kernel: clocksource: Checking clocksource tsc synchronization from CPU 0 to CPUs 1.
Feb 23 17:46:41 debian kernel: clocksource: Switched to clocksource hpet
#10 lore raw

Fab!

Quoted 7 lines · Fab Stz

Le 15/01/2025 à 17:59, Thomas Gleixner a écrit :

Quoted 2 lines

AFAICT, that iMac 9.1 is Core 2 Duo based and that generation of processors definitely had issues with the TSC in deeper idle states.

Indeed, cpuinfo reports:

model name : Intel(R) Core(TM)2 Duo CPU E8135 @ 2.66GHz

Ok.

Quoted 9 lines
Quoted 8 lines
Quoted 2 lines

BTW, I tried the "processor.max_cstate=1" you mentioned but it didn't change anything on the delay and/or warning.

That's weird, but we have no idea what kind of magic the BIOS implements there for power management behind the kernels back. I assume that it does because this generation of CPUs uses the ACPI processor idle driver and that disables TSC when it detects that the system supports C-states > 1.

Quoted 4 lines

Output of these commands can be found in attached file cpuidle.txt

+ cat /sys/devices/system/cpu/cpuidle/current_driver intel_idle

So according to that the intel_idle driver is in use, which does not have the magic TSC workarounds like the acpi processor driver has, but it seems to be loaded preferred.

Sigh. Why is the intel_idle driver so agressive in taking over despite the fact that it does not handle the old CPUs, which are known to require the TSC workaround? It handles the APIC stops in C2, but not the TSC oddity while the original ACPI processor_idle driver does the right thing for more than two decades....

Quoted 3 lines

Can the kernel be patched so that the proper config is used automatically (ie. without the user having to set any parameter)? I'm not sure my question actually makes sense.

Yes, we can. Untested patch below. It just brings the intel idle driver on par with the original ACPI processor idle driver to deal with that problem.

Thanks,

tglx
---

drivers/idle/intel_idle.c +4 -0
index 118fe1d37c22..0fdb1d1316c4 100644
@@ -56,6 +56,7 @@
 #include <asm/intel-family.h>
 #include <asm/mwait.h>
 #include <asm/spec-ctrl.h>
+#include <asm/tsc.h>
 #include <asm/fpu/api.h>
 
 #define INTEL_IDLE_VERSION "0.5.1"
@@ -1799,6 +1800,9 @@ static void __init intel_idle_init_cstates_acpi(struct cpuidle_driver *drv)
 		if (intel_idle_state_needs_timer_stop(state))
 			state->flags |= CPUIDLE_FLAG_TIMER_STOP;
 
+		if (cx->type > ACPI_STATE_C1 && !boot_cpu_has(X86_FEATURE_NONSTOP_TSC))
+			mark_tsc_unstable("TSC halts in idle");
+
 		state->enter = intel_idle;
 		state->enter_s2idle = intel_idle_s2idle;
 	}
author
#11 lore raw

Hello Thomas,

Thank you for the patch! I built the 6.1 kernel with it applied and it apparently works as expected (no delay). Please find logs below & attached dmesg log. Maybe the interesting line is:

Feb 25 08:53:51 debian kernel: tsc: Marking TSC unstable due to TSC halts in idle

Comparison shows that it is "Marking TSC unstable due to boot parameter" with a non patched kernel + tsc=unstable.

+ cat /sys/devices/system/cpu/cpuidle/available_governors ladder menu
+ cat /sys/devices/system/cpu/cpuidle/current_driver intel_idle
+ cat /sys/devices/system/cpu/cpuidle/current_governor menu
+ cat /sys/devices/system/cpu/cpuidle/current_governor_ro menu
+ ls /sys/devices/system/cpu/cpu0/cpuidle/ state0 state1 state2 state3
+ cat /sys/devices/system/cpu/cpu0/cpuidle/state0/name POLL
+ cat /sys/devices/system/cpu/cpu0/cpuidle/state0/disable 0
+ cat /sys/devices/system/cpu/cpu0/cpuidle/state1/name C1_ACPI
+ cat /sys/devices/system/cpu/cpu0/cpuidle/state1/disable 0
+ cat /sys/devices/system/cpu/cpu0/cpuidle/state2/name C2_ACPI
+ cat /sys/devices/system/cpu/cpu0/cpuidle/state2/disable 0
+ cat /sys/devices/system/cpu/cpu0/cpuidle/state3/name C3_ACPI
+ cat /sys/devices/system/cpu/cpu0/cpuidle/state3/disable 0

Will the patch also enter the longterm releases like 6.1?

Regards
Fab

Le 24/02/2025 à 09:13, Thomas Gleixner a écrit :

Quoted 49 lines
Quoted 9 lines
Quoted 8 lines
Quoted 2 lines

BTW, I tried the "processor.max_cstate=1" you mentioned but it didn't change anything on the delay and/or warning.

That's weird, but we have no idea what kind of magic the BIOS implements there for power management behind the kernels back. I assume that it does because this generation of CPUs uses the ACPI processor idle driver and that disables TSC when it detects that the system supports C-states > 1.

Quoted 4 lines

Output of these commands can be found in attached file cpuidle.txt

+ cat /sys/devices/system/cpu/cpuidle/current_driver intel_idle

So according to that the intel_idle driver is in use, which does not have the magic TSC workarounds like the acpi processor driver has, but it seems to be loaded preferred.

Sigh. Why is the intel_idle driver so agressive in taking over despite the fact that it does not handle the old CPUs, which are known to require the TSC workaround? It handles the APIC stops in C2, but not the TSC oddity while the original ACPI processor_idle driver does the right thing for more than two decades....

Quoted 3 lines

Can the kernel be patched so that the proper config is used automatically (ie. without the user having to set any parameter)? I'm not sure my question actually makes sense.

Yes, we can. Untested patch below. It just brings the intel idle driver on par with the original ACPI processor idle driver to deal with that problem.

Thanks,

tglx
---

drivers/idle/intel_idle.c +1 -0
index 118fe1d37c22..0fdb1d1316c4 100644
@@ -56,6 +56,7 @@
  #include <asm/intel-family.h>
  #include <asm/mwait.h>
  #include <asm/spec-ctrl.h>
+#include <asm/tsc.h>
  #include <asm/fpu/api.h>
 
  #define INTEL_IDLE_VERSION "0.5.1"

drivers/idle/intel_idle.c static void __init intel_idle_init_cstates_acpi(struct cpuidle_driver *drv) · line 1808

Quoted 9 lines
drivers/idle/intel_idle.c +3 -0
@@ -1799,6 +1800,9 @@ static void __init intel_idle_init_cstates_acpi(struct cpuidle_driver *drv)
  		if (intel_idle_state_needs_timer_stop(state))
  			state->flags |= CPUIDLE_FLAG_TIMER_STOP;
 
+		if (cx->type > ACPI_STATE_C1 && !boot_cpu_has(X86_FEATURE_NONSTOP_TSC))
+			mark_tsc_unstable("TSC halts in idle");
+
  		state->enter = intel_idle;
  		state->enter_s2idle = intel_idle_s2idle;
  	}
Feb 25 08:53:50 debian kernel: Command line: root=UUID=462f57b4-136e-4c18-8c55-e4bc59cfb7aa ro  zswap.enabled=1 mem_sleep_default=deep single initrd=\boot\initrd.img-6.1.0-0.a.test-amd64                                     
Feb 25 08:53:50 debian kernel: tsc: Fast TSC calibration using PIT
Feb 25 08:53:50 debian kernel: tsc: Detected 2653.363 MHz processor
Feb 25 08:53:50 debian kernel: clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645519600211568 ns
Feb 25 08:53:50 debian kernel: Kernel command line: root=UUID=462f57b4-136e-4c18-8c55-e4bc59cfb7aa ro  zswap.enabled=1 mem_sleep_default=deep single initrd=\boot\initrd.img-6.1.0-0.a.test-amd64                                     
Feb 25 08:53:50 debian kernel: Unknown kernel command line parameters "single", will be passed to user space.
Feb 25 08:53:50 debian kernel: clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 76450417870 ns
Feb 25 08:53:50 debian kernel: clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x263f25ec687, max_idle_ns: 440795217651 ns
Feb 25 08:53:50 debian kernel: clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
Feb 25 08:53:51 debian kernel: clocksource: Switched to clocksource tsc-early
Feb 25 08:53:51 debian kernel: clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
Feb 25 08:53:51 debian kernel: tsc: Refined TSC clocksource calibration: 2653.335 MHz
Feb 25 08:53:51 debian kernel: clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x263f0bda6a8, max_idle_ns: 440795254345 ns
Feb 25 08:53:51 debian kernel: clocksource: Switched to clocksource tsc
Feb 25 08:53:51 debian kernel: tsc: Marking TSC unstable due to TSC halts in idle
Feb 25 08:53:51 debian kernel: clocksource: Checking clocksource tsc synchronization from CPU 1 to CPUs 0.
Feb 25 08:53:51 debian kernel: clocksource: Switched to clocksource hpet
                               on the kernel command line
#12 lore raw
Quoted 6 lines · Fab Stz

Thank you for the patch! I built the 6.1 kernel with it applied and it apparently works as expected (no delay). Please find logs below & attached dmesg log. Maybe the interesting line is:

Feb 25 08:53:51 debian kernel: tsc: Marking TSC unstable due to TSC 

halts in idle

Correct. That's the missing piece.

Quoted 1 line

Will the patch also enter the longterm releases like 6.1?

Let me write a proper change log with a Fixes tag and cc stable, so it will be automatically picked up.

Thanks,

tglx

#13 lore raw

PATCH 1/1 intel_idle: Handle older CPUs, which stop the TSC in deeper C states, correctly

The Intel idle driver is preferred over the ACPI processor idle driver, but fails to implement the work around for Core2 generation CPUs, where the TSC stops in C2 and deeper C-states. This causes stalls and boot delays, when the clocksource watchdog does not catch the unstable TSC before the CPU goes deep idle for the first time.

The ACPI driver marks the TSC unstable when it detects that the CPU supports C2 or deeper and the CPU does not have a non-stop TSC.

Add the equivivalent work around to the Intel idle driver to cure that.

Fixes 18734958e9bf ("intel_idle: Use ACPI _CST for processor models without C-state tables")
---
 drivers/idle/intel_idle.c |    4 ++++
 1 file changed, 4 insertions(+)
drivers/idle/intel_idle.c +4 -0
@@ -56,6 +56,7 @@
 #include <asm/intel-family.h>
 #include <asm/mwait.h>
 #include <asm/spec-ctrl.h>
+#include <asm/tsc.h>
 #include <asm/fpu/api.h>
 
 #define INTEL_IDLE_VERSION "0.5.1"
@@ -1799,6 +1800,9 @@ static void __init intel_idle_init_cstat
 		if (intel_idle_state_needs_timer_stop(state))
 			state->flags |= CPUIDLE_FLAG_TIMER_STOP;
 
+		if (cx->type > ACPI_STATE_C1 && !boot_cpu_has(X86_FEATURE_NONSTOP_TSC))
+			mark_tsc_unstable("TSC halts in idle");
+
 		state->enter = intel_idle;
 		state->enter_s2idle = intel_idle_s2idle;
 	}
maintainer Applied
#14 lore raw

Re: [PATCH] intel_idle: Handle older CPUs, which stop the TSC in deeper C states, correctly

Quoted 33 lines · Thomas Gleixner

The Intel idle driver is preferred over the ACPI processor idle driver, but fails to implement the work around for Core2 generation CPUs, where the TSC stops in C2 and deeper C-states. This causes stalls and boot delays, when the clocksource watchdog does not catch the unstable TSC before the CPU goes deep idle for the first time.

The ACPI driver marks the TSC unstable when it detects that the CPU supports C2 or deeper and the CPU does not have a non-stop TSC.

Add the equivivalent work around to the Intel idle driver to cure that.

Fixes 18734958e9bf ("intel_idle: Use ACPI _CST for processor models without C-state tables")
---
 drivers/idle/intel_idle.c |    4 ++++
 1 file changed, 4 insertions(+)
drivers/idle/intel_idle.c +1 -0
@@ -56,6 +56,7 @@
 #include <asm/intel-family.h>
 #include <asm/mwait.h>
 #include <asm/spec-ctrl.h>
+#include <asm/tsc.h>
 #include <asm/fpu/api.h>
 
 #define INTEL_IDLE_VERSION "0.5.1"

drivers/idle/intel_idle.c static void __init intel_idle_init_cstat · line 1808

Quoted 9 lines
drivers/idle/intel_idle.c +3 -0
@@ -1799,6 +1800,9 @@ static void __init intel_idle_init_cstat
                if (intel_idle_state_needs_timer_stop(state))
                        state->flags |= CPUIDLE_FLAG_TIMER_STOP;
 
+               if (cx->type > ACPI_STATE_C1 && !boot_cpu_has(X86_FEATURE_NONSTOP_TSC))
+                       mark_tsc_unstable("TSC halts in idle");
+
                state->enter = intel_idle;
                state->enter_s2idle = intel_idle_s2idle;
        }

Applied as a fix for 6.14-rc5, thank you!