Topic: Constant and periodic high kernel timer latency in Windows 10

Hi, I recently installed Win10pro-64bit from scratch and got some dropouts and cracks in both Reaper and Sonar.
After examining the system I found that there is a constant periodic spike in kernel timer latency: 998ns..999.9ns, i.e. ~ 1ms every 2-3 seconds. Other than that the kernel timer latency values are around 5ns.

A typical spike:
TYPICAL bbcode test1


This did not occur on my previous Win7pro: despite it has much more hardware and software installed, Win7 has no such periodic kernel timer latency spikes like Win10 has.

The only difference between OSes is that Win7pro is installed on Samsung 850PRO and Win10pro is installed on Samsung 970 EVO, which is m2. Otherwise they share the same hardware.

The system has no WIFI controller, Power Plan is set on max performance, C-states and CPU power saving are turned off in BIOS, all apps are closed before running LatencyMon, etc.

System:
-- i7-4790K, 32GB, ASUS Z97A
-- ASUS Thunderbolt II PCI card
-- TI IE1394 PCI card
-- USB keyboard and USB Logitech mouse

Again, Win7 has no such problem with this hardware. Only Win10 has.

WHAT I TRIED SO FAR

-- installed all the latest drivers for all hardware I have
-- physically removed video card GTX 760 and uninstalled its drivers. DPC got improved but that periodic spike was still there
-- disabled/enabled LAN drivers
-- disabled/enabled HPET in Device Manager
-- disconnected both USB keyboard and USB mouse, and connected plain USB Logitech keyboard
-- disconnected some SATA drives
-- uninstalled RME drivers and disconnected UFX+

No difference. The spike still occurs every 2-3 seconds.

Has anyone seen anything like that? What could that be?
Thank you!!

LatencyMon Report
_________________________________________________________________________________________________________
CONCLUSION
_________________________________________________________________________________________________________
Your system appears to be suitable for handling real-time audio and other tasks without dropouts.
LatencyMon has been analyzing your system for  0:05:00  (h:mm:ss) on all processors in the system.


_________________________________________________________________________________________________________
SYSTEM INFORMATION
_________________________________________________________________________________________________________
Computer name:                                        HELIOS
OS version:                                           Windows 8 , 6.2, build: 9200 (x64)
CPU:                                                  GenuineIntel Intel(R) Core(TM) i7-4790K CPU @ 4.00GHz
Logical processors:                                   8
Processor groups:                                     1
RAM:                                                  32710 MB total


_________________________________________________________________________________________________________
CPU SPEED
_________________________________________________________________________________________________________
Reported CPU speed:                                   4000.0 MHz
Measured CPU speed:                                   4590.0 MHz (approx.)

Note: reported execution times may be calculated based on a fixed reported CPU speed. Disable variable speed settings like Intel Speed Step and AMD Cool N Quiet in the BIOS setup for more accurate results.


_________________________________________________________________________________________________________
MEASURED KERNEL TIMER LATENCIES
_________________________________________________________________________________________________________
Highest measured kernel timer latency (µs):           998.911489


_________________________________________________________________________________________________________
MEASURED SMIs AND CPU STALLS
_________________________________________________________________________________________________________
Highest measured SMI, IPI or CPU stall (µs)           1.279999


_________________________________________________________________________________________________________
REPORTED DPCs
_________________________________________________________________________________________________________
Highest DPC routine execution time (µs):              603.790
Driver with highest DPC routine execution time:       nvlddmkm.sys - NVIDIA Windows Kernel Mode Driver, Version 398.36 , NVIDIA Corporation

Highest reported total DPC routine time (%):          0.019218
Driver with highest DPC total execution time:         nvlddmkm.sys - NVIDIA Windows Kernel Mode Driver, Version 398.36 , NVIDIA Corporation

Total time spent in DPCs (%)                          0.037358

DPC count (execution time <250 µs):                   284921
DPC count (execution time 250-500 µs):                0
DPC count (execution time 500-999 µs):                2
DPC count (execution time 1000-1999 µs):              0
DPC count (execution time 2000-3999 µs):              0
DPC count (execution time >=4000 µs):                 0


_________________________________________________________________________________________________________
REPORTED ISRs
_________________________________________________________________________________________________________
Highest ISR routine execution time (µs):              116.6260
Driver with highest ISR routine execution time:       dxgkrnl.sys - DirectX Graphics Kernel, Microsoft Corporation

Highest reported total ISR routine time (%):          0.030004
Driver with highest ISR total time:                   dxgkrnl.sys - DirectX Graphics Kernel, Microsoft Corporation

Total time spent in ISRs (%)                          0.035281

ISR count (execution time <250 µs):                   81203
ISR count (execution time 250-500 µs):                0
ISR count (execution time 500-999 µs):                0
ISR count (execution time 1000-1999 µs):              0
ISR count (execution time 2000-3999 µs):              0
ISR count (execution time >=4000 µs):                 0


_________________________________________________________________________________________________________
REPORTED HARD PAGEFAULTS
_________________________________________________________________________________________________________
Process with highest pagefault count:                 none

Total number of hard pagefaults                       0
Hard pagefault count of hardest hit process:          0
Highest hard pagefault resolution time (µs):          0.0
Total time spent in hard pagefaults (%):              0.0
Number of processes hit:                              0


_________________________________________________________________________________________________________
PER CPU DATA
_________________________________________________________________________________________________________
CPU 0 Interrupt cycle time (s):                       2.045286
CPU 0 ISR highest execution time (µs):                116.6260
CPU 0 ISR total execution time (s):                   0.847624
CPU 0 ISR count:                                      81203
CPU 0 DPC highest execution time (µs):                603.790
CPU 0 DPC total execution time (s):                   0.809099
CPU 0 DPC count:                                      243104
_________________________________________________________________________________________________________
CPU 1 Interrupt cycle time (s):                       0.055227
CPU 1 ISR highest execution time (µs):                0.0
CPU 1 ISR total execution time (s):                   0.0
CPU 1 ISR count:                                      0
CPU 1 DPC highest execution time (µs):                34.290750
CPU 1 DPC total execution time (s):                   0.009719
CPU 1 DPC count:                                      4000
_________________________________________________________________________________________________________
CPU 2 Interrupt cycle time (s):                       0.209211
CPU 2 ISR highest execution time (µs):                0.0
CPU 2 ISR total execution time (s):                   0.0
CPU 2 ISR count:                                      0
CPU 2 DPC highest execution time (µs):                71.4470
CPU 2 DPC total execution time (s):                   0.047101
CPU 2 DPC count:                                      25142
_________________________________________________________________________________________________________
CPU 3 Interrupt cycle time (s):                       0.081193
CPU 3 ISR highest execution time (µs):                0.0
CPU 3 ISR total execution time (s):                   0.0
CPU 3 ISR count:                                      0
CPU 3 DPC highest execution time (µs):                13.03850
CPU 3 DPC total execution time (s):                   0.004011
CPU 3 DPC count:                                      1868
_________________________________________________________________________________________________________
CPU 4 Interrupt cycle time (s):                       0.149769
CPU 4 ISR highest execution time (µs):                0.0
CPU 4 ISR total execution time (s):                   0.0
CPU 4 ISR count:                                      0
CPU 4 DPC highest execution time (µs):                30.760
CPU 4 DPC total execution time (s):                   0.009534
CPU 4 DPC count:                                      3780
_________________________________________________________________________________________________________
CPU 5 Interrupt cycle time (s):                       0.137798
CPU 5 ISR highest execution time (µs):                0.0
CPU 5 ISR total execution time (s):                   0.0
CPU 5 ISR count:                                      0
CPU 5 DPC highest execution time (µs):                11.900750
CPU 5 DPC total execution time (s):                   0.002510
CPU 5 DPC count:                                      1209
_________________________________________________________________________________________________________
CPU 6 Interrupt cycle time (s):                       0.144412
CPU 6 ISR highest execution time (µs):                0.0
CPU 6 ISR total execution time (s):                   0.0
CPU 6 ISR count:                                      0
CPU 6 DPC highest execution time (µs):                43.30
CPU 6 DPC total execution time (s):                   0.006260
CPU 6 DPC count:                                      2481
_________________________________________________________________________________________________________
CPU 7 Interrupt cycle time (s):                       0.160420
CPU 7 ISR highest execution time (µs):                0.0
CPU 7 ISR total execution time (s):                   0.0
CPU 7 ISR count:                                      0
CPU 7 DPC highest execution time (µs):                11.4870
CPU 7 DPC total execution time (s):                   0.009287
CPU 7 DPC count:                                      3339
_________________________________________________________________________________________________________
Main screen for the report above
MAIN bbcode test1

Times for the report above
DPC bbcode test1

2 (edited by ramses 2018-08-27 18:03:26)

Re: Constant and periodic high kernel timer latency in Windows 10

Which version 1709 or 1804 ?

v4.02 doesn't support Win8 + Win10. Use the latest version.

Please also note, that Win8 and Win10 had changes in the kernel, so that the values are not compareable anymore with v4.02 for Windows 7 .. the old kernel latency timer with values down to 1.75 microseconds are gone.

Reasons for spikes might be this: https://www.tonstudio-forum.de/blog/ind … ing-EN-DE/
Maybe you can cross check with the test tool of this company, VBAudioMMUStressTest_x64.exe
If you look into the links you find this tool on their forums.

BR Ramses - UFX III, 12Mic, XTC, ADI-2 Pro FS R BE, RayDAT, X10SRi-F, E5-1680v4, Win10Pro22H2, Cub14

Re: Constant and periodic high kernel timer latency in Windows 10

1) Windows 10 Pro, 1803, build 17134.228

2) VBAudioMMUStressTest -- I'll post in a second

3) Indeed you are right: latency measure with LatencyMon 6.70 is very different: the spikes are gone)

_________________________________________________________________________________________________________
CONCLUSION
_________________________________________________________________________________________________________
Your system appears to be suitable for handling real-time audio and other tasks without dropouts.
LatencyMon has been analyzing your system for  0:01:00  (h:mm:ss) on all processors.


_________________________________________________________________________________________________________
SYSTEM INFORMATION
_________________________________________________________________________________________________________
Computer name:                                        HELIOS
OS version:                                           Windows 10 , 10.0, build: 17134 (x64)
Hardware:                                             All Series, ASUS, ASUSTeK COMPUTER INC., Z97-A
CPU:                                                  GenuineIntel Intel(R) Core(TM) i7-4790K CPU @ 4.00GHz
Logical processors:                                   8
Processor groups:                                     1
RAM:                                                  32710 MB total


_________________________________________________________________________________________________________
CPU SPEED
_________________________________________________________________________________________________________
Reported CPU speed:                                   40 MHz

Note: reported execution times may be calculated based on a fixed reported CPU speed. Disable variable speed settings like Intel Speed Step and AMD Cool N Quiet in the BIOS setup for more accurate results.

WARNING: the CPU speed that was measured is only a fraction of the CPU speed reported. Your CPUs may be throttled back due to variable speed settings and thermal issues. It is suggested that you run a utility which reports your actual CPU frequency and temperature.



_________________________________________________________________________________________________________
MEASURED INTERRUPT TO USER PROCESS LATENCIES
_________________________________________________________________________________________________________
The interrupt to process latency reflects the measured interval that a usermode process needed to respond to a hardware request from the moment the interrupt service routine started execution. This includes the scheduling and execution of a DPC routine, the signaling of an event and the waking up of a usermode thread from an idle wait state in response to that event.

Highest measured interrupt to process latency (µs):   97.535875
Average measured interrupt to process latency (µs):   2.354683

Highest measured interrupt to DPC latency (µs):       95.487878
Average measured interrupt to DPC latency (µs):       0.841593


_________________________________________________________________________________________________________
REPORTED ISRs
_________________________________________________________________________________________________________
Interrupt service routines are routines installed by the OS and device drivers that execute in response to a hardware interrupt signal.

Highest ISR routine execution time (µs):              111.857750
Driver with highest ISR routine execution time:       dxgkrnl.sys - DirectX Graphics Kernel, Microsoft Corporation

Highest reported total ISR routine time (%):          0.009641
Driver with highest ISR total time:                   dxgkrnl.sys - DirectX Graphics Kernel, Microsoft Corporation

Total time spent in ISRs (%)                          0.011486

ISR count (execution time <250 µs):                   5408
ISR count (execution time 250-500 µs):                0
ISR count (execution time 500-999 µs):                0
ISR count (execution time 1000-1999 µs):              0
ISR count (execution time 2000-3999 µs):              0
ISR count (execution time >=4000 µs):                 0


_________________________________________________________________________________________________________
REPORTED DPCs
_________________________________________________________________________________________________________
DPC routines are part of the interrupt servicing dispatch mechanism and disable the possibility for a process to utilize the CPU while it is interrupted until the DPC has finished execution.

Highest DPC routine execution time (µs):              166.692250
Driver with highest DPC routine execution time:       nvlddmkm.sys - NVIDIA Windows Kernel Mode Driver, Version 398.82 , NVIDIA Corporation

Highest reported total DPC routine time (%):          0.005455
Driver with highest DPC total execution time:         nvlddmkm.sys - NVIDIA Windows Kernel Mode Driver, Version 398.82 , NVIDIA Corporation

Total time spent in DPCs (%)                          0.009693

DPC count (execution time <250 µs):                   14358
DPC count (execution time 250-500 µs):                0
DPC count (execution time 500-999 µs):                0
DPC count (execution time 1000-1999 µs):              0
DPC count (execution time 2000-3999 µs):              0
DPC count (execution time >=4000 µs):                 0


_________________________________________________________________________________________________________
REPORTED HARD PAGEFAULTS
_________________________________________________________________________________________________________
Hard pagefaults are events that get triggered by making use of virtual memory that is not resident in RAM but backed by a memory mapped file on disk. The process of resolving the hard pagefault requires reading in the memory from disk while the process is interrupted and blocked from execution.

NOTE: some processes were hit by hard pagefaults. If these were programs producing audio, they are likely to interrupt the audio stream resulting in dropouts, clicks and pops. Check the Processes tab to see which programs were hit.

Process with highest pagefault count:                 wmiadap.exe

Total number of hard pagefaults                       15
Hard pagefault count of hardest hit process:          7
Number of processes hit:                              5


_________________________________________________________________________________________________________
PER CPU DATA
_________________________________________________________________________________________________________
CPU 0 Interrupt cycle time (s):                       0.363526
CPU 0 ISR highest execution time (µs):                111.857750
CPU 0 ISR total execution time (s):                   0.055131
CPU 0 ISR count:                                      5408
CPU 0 DPC highest execution time (µs):                166.692250
CPU 0 DPC total execution time (s):                   0.040203
CPU 0 DPC count:                                      10654
_________________________________________________________________________________________________________
CPU 1 Interrupt cycle time (s):                       0.020582
CPU 1 ISR highest execution time (µs):                0.0
CPU 1 ISR total execution time (s):                   0.0
CPU 1 ISR count:                                      0
CPU 1 DPC highest execution time (µs):                6.7230
CPU 1 DPC total execution time (s):                   0.000061
CPU 1 DPC count:                                      25
_________________________________________________________________________________________________________
CPU 2 Interrupt cycle time (s):                       0.028916
CPU 2 ISR highest execution time (µs):                0.0
CPU 2 ISR total execution time (s):                   0.0
CPU 2 ISR count:                                      0
CPU 2 DPC highest execution time (µs):                107.665250
CPU 2 DPC total execution time (s):                   0.004254
CPU 2 DPC count:                                      2812
_________________________________________________________________________________________________________
CPU 3 Interrupt cycle time (s):                       0.026559
CPU 3 ISR highest execution time (µs):                0.0
CPU 3 ISR total execution time (s):                   0.0
CPU 3 ISR count:                                      0
CPU 3 DPC highest execution time (µs):                6.9470
CPU 3 DPC total execution time (s):                   0.000024
CPU 3 DPC count:                                      16
_________________________________________________________________________________________________________
CPU 4 Interrupt cycle time (s):                       0.025607
CPU 4 ISR highest execution time (µs):                0.0
CPU 4 ISR total execution time (s):                   0.0
CPU 4 ISR count:                                      0
CPU 4 DPC highest execution time (µs):                47.917750
CPU 4 DPC total execution time (s):                   0.000347
CPU 4 DPC count:                                      197
_________________________________________________________________________________________________________
CPU 5 Interrupt cycle time (s):                       0.028243
CPU 5 ISR highest execution time (µs):                0.0
CPU 5 ISR total execution time (s):                   0.0
CPU 5 ISR count:                                      0
CPU 5 DPC highest execution time (µs):                12.97850
CPU 5 DPC total execution time (s):                   0.001323
CPU 5 DPC count:                                      487
_________________________________________________________________________________________________________
CPU 6 Interrupt cycle time (s):                       0.029179
CPU 6 ISR highest execution time (µs):                0.0
CPU 6 ISR total execution time (s):                   0.0
CPU 6 ISR count:                                      0
CPU 6 DPC highest execution time (µs):                11.006250
CPU 6 DPC total execution time (s):                   0.000299
CPU 6 DPC count:                                      161
_________________________________________________________________________________________________________
CPU 7 Interrupt cycle time (s):                       0.033472
CPU 7 ISR highest execution time (µs):                0.0
CPU 7 ISR total execution time (s):                   0.0
CPU 7 ISR count:                                      0
CPU 7 DPC highest execution time (µs):                6.18850
CPU 7 DPC total execution time (s):                   0.000014
CPU 7 DPC count:                                      6
_________________________________________________________________________________________________________

4 (edited by alex128 2018-08-27 23:13:46)

Re: Constant and periodic high kernel timer latency in Windows 10

VBAudioMMUStressTest has identical result on my Win7pro & Win10pro: 0.12ms and 0.10ms after 5 minutes run.

Having said that, the test is test: I clearly hear cracks and dropouts in Reaper in Windows 10 when GR5 track is armed. Interestingly, if I disarm GR5 track then dropouts are gone.

Reaper in Win7 has no dropouts in both situations.

Sonar on Win10 appears to have no dropouts (or significantly less than in Reaper, it is hard to properly measure them) in both cases as well.

5 (edited by ramses 2018-08-28 04:44:09)

Re: Constant and periodic high kernel timer latency in Windows 10

My VB Audio Memory Management Stress Test results
Win7, Xeon E5-1650v3
100.000 frames, ~9 minutes.
Biggest processing time on frame 9535: 0.14ms
No incidents.
CPU Usage: 1%.

BTW, when you remeasured with the correct LatencyMon version you delivered only the report, not the screenshots anymore.
But it would have been interesting to see, whether the measured values for highest execution time also change.
I noticed that your nVidia kernel driver uses quite a lot, 0.6 seconds.
For me its 0,08 seconds.

Try different versions of nVidia driver, I reinstalled my oldest for Win7 which seems to be most compact 361.43.
Theoretically you only need to install the graficdriver.
I usually install also PhysX software and eventually Geforce experience if you like / need it.

BR Ramses - UFX III, 12Mic, XTC, ADI-2 Pro FS R BE, RayDAT, X10SRi-F, E5-1680v4, Win10Pro22H2, Cub14

Re: Constant and periodic high kernel timer latency in Windows 10

Yes, I would imagine that the measured values for highest execution time had also changed because the highest value was 603.790 = nvlddmkm.sys (Version 398.36) and became 166.692250 (Version 398.82). Furthermore, on Win7 I ran LatencyMon 6.70:
Highest measured interrupt to process latency (µs):   205.822472
Average measured interrupt to process latency (µs):   2.138321
Highest DPC routine execution time (µs):              607.070750 for nvlddmkm.sys  (Version 388.13).
Highest ISR routine execution time (µs):              114.656250

LatencyMon6.70 shows that Win10 has better stats than Win7 in every aspect (latency, IRS, DPC) and yet Win10 has dropouts in Reaper with armed track. I am not sure what the problem is but now I recall that I observed the same "armed track in Reaper" effect in Win7 back in time and then it somehow had gone. This is important for me because it's my usual workflow: arm GR5 track, play, done, and now I cannot playback/record this way without crackles.

Not sure where to move now. And yes, Win7/Win10 have only GPU drivers, nothing else.

7

Re: Constant and periodic high kernel timer latency in Windows 10

Did you play with the MMCSS settings?

Regards
Matthias Carstens
RME

8 (edited by ramses 2018-08-28 07:55:57)

Re: Constant and periodic high kernel timer latency in Windows 10

Whats GR5 ?

On my Win10 Testinstallation I am using O&O Win10 Shutup to disable everything in regards to "unnedded" processes / privacy / telemetry processes.

As I do not trust UAC I have reenabled the Administrator user and are running the normal user without admin bit set.
If this is the case, then you should run O&O 10 Win10 Shutup on both accounts, Admin and your user account.

Some of the settings are system global, some per user account.

Its really a lot which you can perform there and I think it makes sense and is the only way to have Win10 more under control.

BR Ramses - UFX III, 12Mic, XTC, ADI-2 Pro FS R BE, RayDAT, X10SRi-F, E5-1680v4, Win10Pro22H2, Cub14

Re: Constant and periodic high kernel timer latency in Windows 10

MC wrote:

Did you play with the MMCSS settings?

Yes, no difference.

ramses wrote:

Whats GR5 ?

Guitar Rig 5 VST

I actually have Win10 setup like you, I just disabled telemetry and spying manually.

Re: Constant and periodic high kernel timer latency in Windows 10

It appears that the problem is solved.

And you know what was the reason?

Win7 Reaper had GR5 and BiasFX plugins bridged as separate processes. Since I used the same Reaper config it was the same in Reaper on Win10. Once I made that armed GR5 plugin native - the dropouts disappeared! Any bridged mode - separate, dedicated, and 32bit/64bit did not change the observation: only native mode works.

The same is actually applicable to BiasFX plugins, I armed them and dropouts had appeared even worse than for GR5. However, after making BiasFX native - the dropouts on armed track disappeared as well.

As you might know, my working buffer size = 512, Sample Rate = 96KHz. And since my armed GR5/BiasFX is native now - I can set buffer size = 256 with no problems. I even tried 128 and have not noticed dropouts as well (!). In contrast, Win7 is capable to run the armed plugins bridged (not native) BUT it badly chokes with buffer size = 256.

Thank you, Ramses and Matthias for your help, it appears Win10 is worth to try. I hope such a great performance would not degrade after I contaminate Win10 with VMs and my other working stuff smile

11 (edited by ramses 2018-08-29 05:56:30)

Re: Constant and periodic high kernel timer latency in Windows 10

How did it come that the plugin ran in bridged mode ? Did you change this ?

https://forum.cockos.com/showthread.php?t=165667

"Native is the default way plugins are run inside the main Reaper process. "

"For those who don't know, this option is available in Windows from the FX Browser (Shift+F by default) by right clicking any VST Plugin's name."

"Dedicated process puts each bridged plugin into its own bridge process. This has the downside that it will increase the overall CPU load since Reaper will need to communicate with several bridge processes."

BR Ramses - UFX III, 12Mic, XTC, ADI-2 Pro FS R BE, RayDAT, X10SRi-F, E5-1680v4, Win10Pro22H2, Cub14

12 (edited by alex128 2018-08-29 11:12:40)

Re: Constant and periodic high kernel timer latency in Windows 10

ramses wrote:

How did it come that the plugin ran in bridged mode ? Did you change this ?

Yes, I did, long ago. This somehow did not affect armed tracks in Win7. Bridged/native only has an effect for armed tracks on my Win10. If tracks are unarmed then it doesn't matter for Win10 - even bridged plugins can be played back with no issues with buffer = 128.

Since I saw no difference between bridged and native in Win7 I kept it bridged for "better stability". However, now I see that even in Win7 native also gives some boost: e.g. I can set buffer=256 with armed native GR5 in Win7 and hear no dropouts. This is not possible with a bridged connection where only buffer=512 works (and even that doesn't help on Win10)

So the conclusion is: use the native mode whenever possible!