ASIO audio glitches on ASUS ROG FLOW X16 - need help with WPA

The timer resolution is intermittently being changed to 15.6ms - take a look at the Timer Resolution graph - you can see that it jumps from 1ms to 15.6ms at the moment the ~13ms glitch ends (presumably around the time of the timer interrupt) How can we determine what requested this change? My audio interface does require a 1ms timer, so this tallies. I know this because I had set the default interval to 15.6ms (by running powercfg /energy - I didn't know it would make a permanent change!). I couldn't figure out how to put it back to 1ms, so I reasoned that my audio interface probably requires 1ms, and wondered whether if I installed the driver that it would put the system default to 1ms - indeed it did. I don't think the default matters much though - it appears that anything that needs a particular resolution can simply make the change, at least for the duration if requires it.

Hello Greg,

The timer resolution is a major area of investigation for your issue but it is a complex topic (see the section "Timer processing" in the Windows Internals book).

I don't think that the event you are referring to is an explicit setting of the resolution to 15.625 ms but rather the end of a period when a different resolution had been set (probably matching a timeEndPeriod call) and the resolution reverts to its default value.

Gary

With respect, I completely disagree with your assessment - it is very obvious that the timer resolution was set to 15.6ms, for a single timer tick - that's why all the timer related events (refer kernel activity) which normally occur every 1ms, stop for roughly 15.6ms. That's why there's a glitch in the audio - the USB is stalled for a whopping 15.6ms. Remember, I'm using a buffer size of 128 samples @ 44.1kHz - that's just 2.9ms. In any case - GOOD NEWS - I've found the culprit - it's optional AMD Radeon related software which I can simply disable. (shows up as "AMD Software" in Task Manager). Updating it doesn't fix it, so I'll report this to ASUS and/or AMD, just for good measure, even though it's not important to me for audio. I'll refer them to this discussion. Thanks again for your time. 😀

Active Gary, if you're simply saying that whilst the timer resolution appears to have been changed, it may not have been set to 15.6ms as the graph suggests, I'll go along with that. It does seem very clear to me though that it was changed, and that change causes the problem - agreed? The evidence seems overwhelming.

I might be wrong about Radeon - I need to do more testing. (I do think stopping that process has improved things, though, if it doesn't completely solve it)
In any case, here's another trace, and the timer resolution trace looks VERY different to the previous one. Why is Chrome now requesting an 8ms clock? And why does it seem to be saying that the "actual" system timer is a constant 15.6ms now? The command line Clockres utility says the "current" resolution is 1ms - not 15.6. This trace was recorded using battery power - maybe that has something to do with it.
I owe you an apology Gary - I have no idea what's going on with the timer. Sorry. 🤣

https://drive.google.com/file/d/1_tOMtke9FEhhjDUyT3nMx1iOw1Lvf18q/view?usp=sharing
Refer ~48.1s for the familiar ~14ms interruption of timer ticks.

Should I crosspost in the systems internals forum?

Hello Greg,

dynamic tick, coalescable timers, multimedia timers, waitable timers (plus/minus flag CREATE_WAITABLE_TIMER_HIGH_RESOLUTION), serialized timer expiration, etc. all combine to make analysis of timer behaviour complicated.

I am currently working on finding the best set of trace providers, keywords, levels and stack traces that give me the best insight into what is happening in any particular case.

Cross posting to relevant forums can do no harm; it is my impression that the "Sysinternals" forum is for users of the tools rather than developers - its summary says "Advanced system utilities to manage, troubleshoot, and diagnose Windows and Linux systems and applications."

Gary

Thanks. I'll hold off cross posting for now. I'll try to reproduce on another machine in the meantime. Just in case it's relevant, the "Perfinfo" category looks busier on the problematic machine in terms of timer related calls, compared to the well behaving machine.

Hello Greg,

This is the type of thing that I am looking at: I am using CreateWaitableTimerEx to create a timer with flag CREATE_WAITABLE_TIMER_HIGH_RESOLUTION. I send a UDP packet when the timer runs to make that time easily findable in the trace. Here is one example where a timer with interval 5 ms first runs after 6.2 ms.

My timer with 5 ms period (50,000 100 ns ticks) triggers (opcode ExpireKTimer2) and thread 0x20AC (decimal 8364) is made ready; 0.5 ms later the thread begins to run on processor 2 (the previous thread on that processor was 0 (i.e. idle)). So 0.5 ms of the 1.2 ms delay was due to thread scheduling - possible the power/idle state of processor 2; I will need to add some more trace providers to track that behaviour.

Gary

I've made a silly mistake. Setting the power profile settings "Processor Idle Demote Threshold" & "Processor Idle Promote Threshold" both to 100% makes a big improvement, but over the last few days, I've been testing with these on the default values. Sorry about that.
With these set to 100%, I think it's still failing in the same manner, but less often - about once very 30 to 60 minutes. I've uploaded another trace. This trace was taken using the aforementioned ASIO driver test utility, and WPR was stopped automatically with a Powershell Script that did the same kind of thing as that web page - it repeatedly looped until it detected a 10ms dead period, and then spawned a shell to stop the WPR. The number of times the ASIO utility detected a callback error of 100% was 1, so I'm assuming the script caught the right moment in time.
In order to restrict the buffer size of WPR, I started it with a command and a profile file - it appears that my profile isn't yet as comprehensive as the settings I've been using with the GUI - I'll work on that. Is there a way to simply limit the buffer size that the GUI version uses?
WPR trace - refer time 3515.57s: https://drive.google.com/file/d/1SNYjNNWGWKO9LGDg-A4FfdpXRAowc391/view?usp=sharing
PowerShell script (courtesy Grok): https://drive.google.com/file/d/1t3Vyxf9-a04bybxUk-NV4sGjMOThpr4A/view?usp=sharing

Pete Brown @ Microsoft is helping me over on Gearspace - he's suggested that I try a different way to set my power profile (Settings > System > Power > Power Mode > "Best Performance" - I'll try that next.

Hello Greg,

Your custom profile seems to be missing the "IdleStates" events - these now seem key to understanding the unexpected pauses (this is my current focus).

The only way to set the buffer size that I know of is via the WPRP XML; the custom WPRP can be started via either the command line or the GUI. Using "Memory" rather than "File" "Logging mode" should limit the size of the resulting trace file to the size of the buffered data (or less, if compression is performed).

Gary

Gary - that aforementioned setting has fixed the problem - the test has run for 10+ hours. 😎
Again: Settings > System > Power & Battery > Power Mode > select "Best Performance"
I suggest Microsoft consider merging the "old" and "new" methods of setting the power profile. I was very familiar with the old method, but completely unaware of the new method.

Hello Greg,

Good to hear. It has been interesting to delve into this topic.

A detailed view of a section (around the 48.1 s mark) of your second trace looks like this:

The column marked in green is the processor number; at the bottom of the green section, most processors are in the C3 (Sleep) state - just 7 and 13 (the clock owner) are still running.

In the yellow section, processor 13 enters the sleep state (leaving only processor 7 running) and expects to be woken in 14986 ticks (14.986 ms).

After 13.8 ms, the processors start waking and the next clock tick occurs.

Gary

Excellent! Thanks Gary.
Just FYI, I've concluded that the ASUS utility app "Armoury Crate" is broken, and I have reported this to ASUS.
The way forward for me at the moment seems to be to use a vanilla install of Windows, and to avoid installing A.C at all costs. (even removing it doesn't undo the damage)
I'm trying to find a utility for querying the configuration of the running processor, regarding c-states etc - if anyone knows of something that will work with the mobile AMD processors please advise. (the main one from AMD doesn't support mobile)

Hello Greg,

More insight into the power configuration is my goal too.

There are "hidden" power settings. You could try the following:

• Issue the command "powercfg /list" to get a list of power scheme GUIDs
• Issue the command "powercfg /qh <scheme_guid> 54533251-82be-4824-96c1-47b60b740d00"; 54533251-82be-4824-96c1-47b60b740d00 is the value of GUID_PROCESSOR_SETTINGS_SUBGROUP. "/qh" is undocumented and possibly means "query hidden".
• Perhaps save the output to files and compare schemes. For idle state management settings IDLESCALING, IDLEPROMOTE and IDLEDEMOTE seem to be particularly relevant.

Please let us/me know if you find anything interesting when comparing working/non-working settings that you find for your audio problem.

Gary

Will do. Just a small correction to my previous reply - the root cause may well be the BIOS. I say this because there's an open source substitute for Armoury Crate called "G-Helper", and it's notes say something about the profiles being baked into the BIOS. Sure enough, as soon as I open G-Helper, I can see the ASIO timing get worse, suggesting CPU throttling, despite the fact I've selected it's "Turbo" profile. This happens with Armoury Crate as well. I've checked my BIOS - it's up to date.

Gary,
I need help configuring WPR to run with a small memory buffer. I've created a profile by exporting cpu + power, and I've then tried reducing the system & event buffers, maintaining the same relative proportion. It appears that if I let the capture run for long enough for a wrap-around, it's overwriting old events in a way I don't understand. For example, looking at the absolute time of the events, it appears that categories such as kernel-processor-power &kernel-power don't have any data before the recording was stopped, but do have events AFTER it was stopped. Why do I have anything after it was stopped at all? I don't see a "trace rundown" in this situation either. Is the trace rundown process somehow causing a problem? If so, is there a way to abruptly stop the recording, without the rundown? I only care about events leading up to the STOP command.

Hello Greg,

WPR typically starts two ETW trace sessions, as can be seen with the "logman query -ets" command:

Data Collector Set                        Type                          Status
-------------------------------------------------------------------------------
Circular Kernel Context Logger            Trace                         Running
Diagtrack-Listener                        Trace                         Running
[...]
WPR_initiated_WprApp_WPR System Collector Trace                         Running
WPR_initiated_WprApp_ETW                  Trace                         Running
WinDiag-Realtime-Session                  Trace                         Running

These two files are then merged when WPR is stopped. If you look at the Header event of the resulting trace then the SessionName property is "Relogger" (the files are merged by "relogging") and the LogFileName property is "[multiple files]".

This behaviour, combined with contributions from any rundown and state capture providers could explain what you are seeing.

If you are willing to share your .wprp file and perhaps an example .etl file exhibiting the characteristics that you mention, I can check if the behaviour is expected and perhaps suggest changes to the profile.

Gary

Thanks again. Firstly, the reason I'm still capturing traces is that the aforementioned setting does NOT actually fix the problem. Yes, the test ran for a long time on that particular occasion, but unfortunately, the same problem is still occurring sometimes.
Anyway, I've attached a new WPA screen grab for your perusal, along with the profile file I'm using, and which I'd like to be able to run with a much smaller circular buffer, to make it easier to share ETL files. This profile was created with the following command:
wpr -exportprofile cpu+power cpu_power.wprp
Referring to the screen grab, the test ran for a whopping 5.4 hours before what appears to be the same kind of idling event occurred. It's not apparent from the image, but upon closer inspection of the CPU Idle States graph, CPU 8 appears to be the only core at Idle state 0 (fully active?) during the idle period. For this test, I forced both my Powershell script and the ASIO driver test utility to use CPU 8. (I thought it would make sense for both to be on the same core, and I chose #8 at random)
Regardless of what kind of power plan is active, does it actually make sense to EVER allow CPU 0 to idle for this long (~14ms), given that it's the "main" core, servicing most of the interrupts etc?
Is Idle state 1 actually a true "idle" though? wpa_screen_grab.png
Profile file: cpu_power_wprp.txt

Hello Greg,

Here is some immediate feedback - I might be able to follow-up with some more information/ideas.

I think that idle state 1 (which I interpret to mean C1) just means that the processor has executed the HLT instruction - the processor is "idle" (waiting for an interrupt) but not otherwise in a reduced power state.

Under the menu point Trace -> System Configuration, tab Trace Statistics, one can see how much space each trace provider is using. I just made a very short trace using the CPU + Power profile and this is what that tab shows:

The vast majority of the space is used by information that I consider totally irrelevant for your purposes (DotNET information, only used (as far as I known) in this case to give more meaningful stack traces (IL method names rather than JIT code addresses)).

File operations also seem irrelevant and the ImageId events are only needed for detailed stack traces (routine names rather than just "module" information).

Some large items in the trace file are "genuine" events (created while the trace is still running), such as the DotNET events; some other events (e.g. the ImageId events) are "fabricated" by WPR after the trace has stopped.

If you want to trace for hours then I would carefully consider what needs to be included in the resulting trace file; I would also dispense with most of the "CaptureState Providers on Save" elements since, in the circular capture mode (Memory vs. File), these can cause too much history to be ejected from the buffer(s) when the trace is stopped.

Gary

Hello Greg,

It might be useful to look at: https://stackoverflow.com/questions/48420309/disabling-cpu-idle-c-states-from-kernel-mode-driver

The question is old, but there is a recent (May) response which seems relevant and mentions, in passing, DAWs.

Gary

Thanks. Haven't fully digested it yet, BUT, note that I have tried setting "Processor idle disable" to "Disable idle". It immediately increases the temperature of the cpu, and actually doesn't stop this condition from occurring.
IMPORTANT: This condition (~14ms "idle" time) actually occurs more often if I simply use the system normally, with the network enabled. (open & close apps, browsing, etc etc)
Should I log a support call with Microsoft?
I don't think I've been able to reproduce this idle event thing on the Dell XPS 15 9560 yet, but I'll try a bit more.
Note that Pete Brown@Microsoft asked (on Gearspace) whether I was monitoring temperature, and I replied that I was not. My Powershell script's tight loop was causing the processor to get hot (90C) - I've now improved the script. (and the problem persists)
EDIT: I'll try that new setting (which I know you mentioned earlier):
Processor idle threshold scaling -> Disable scaling
EDIT 2: Unfortunately this setting is already set to "Disable scaling" (sigh!)

Problem reproduced on Windows 10 (on the same hardware)
(I'm very impressed at how well Windows 10 is working overall though, on this relatively modern machine - I expected it to be very difficult to get running, but it was easy)

Hello Greg,

I just noticed another "provider" that could be useful for detailed traces: Microsoft.Windows.Kernel.Timer (notice the dots rather than dashes in the name). This is a TLG (TraceLogging) provider; it can be added to a .wprp profile by preceding its name with an asterisk:

    <EventProvider Id="Timer" Name="*Microsoft.Windows.Kernel.Timer" NonPagedMemory="true" Stack="false" />

It is a "high volume" provider (generates lots of events):

Gary

Thanks. Do you know of a way to trim down an ETL file, to retain only a certain time range?

Hello Greg,

APIs capable of being used to provide this functionality exist (https://learn.microsoft.com/en-us/windows/win32/api/relogger/nn-relogger-itracerelogger) but I am not aware of any publicly available tools that provide this feature.

Gary

Gary,
I added that timer category that you suggested, but I don't see it in the traces. I've attached my profile. wpr_wprp.txt

Hello Greg,

I used your profile to create a trace and the Microsoft.Windows.Kernel.Timer events were present:

Gary

Thanks. When I use logman to query the providers, it doesn't appear - should it?

Hello Greg,

Do you mean "logman query -ets <sessionname>"? It probably does appear in that output, but with a GUID instead of a name:

Provider:
Name:                 {F2D06F08-592D-508C-C3AA-76F396FE18BD}
Provider Guid:        {F2D06F08-592D-508C-C3AA-76F396FE18BD}
Level:                255
KeywordsAll:          0x0
KeywordsAny:          0xffffffffffffffff
Properties:           64
Filter Type:          0

It is a TraceLogging provider rather than a manifested (Crimson) provider, so its definition is not registered and logman can not perform a GUID to name translation.

The reason for the asterisk in front of the name in the profile is that the name cannot be looked up but, in this case, can be calculated by performing a hash calculation on the name (so name to GUID is possible but the reverse process is not possible).

Gary

Here's the output of logman query -ets. Which "session" should I query?

Data Collector Set                      Type                          Status
-------------------------------------------------------------------------------
Circular Kernel Context Logger          Trace                         Running 
Eventlog-Security                       Trace                         Running 
CimFSUnionFS-Filter                     Trace                         Running 
DiagLog                                 Trace                         Running 
Diagtrack-Listener                      Trace                         Running 
EventLog-Application                    Trace                         Running 
EventLog-System                         Trace                         Running 
FaceCredProv                            Trace                         Running 
FilterMgr-Logger                        Trace                         Running 
LwtNetLog                               Trace                         Running 
Microsoft-Windows-Rdp-Graphics-RdpIdd-Trace Trace                         Running 
NetCore                                 Trace                         Running 
NtfsLog                                 Trace                         Running 
RadioMgr                                Trace                         Running 
ScreenOnPowerStudyTraceSession          Trace                         Running 
ReFSLog                                 Trace                         Running 
UBPM                                    Trace                         Running 
WdiContextLog                           Trace                         Running 
WiFiSession                             Trace                         Running 
WPR_initiated_DiagTrackMiniLogger_WPR System Collector Trace                         Running 
WPR_initiated_DiagTrackMiniLogger_OneTrace_User_Logger_20250811_1_EC_0 Trace                         Running 
8696EAC4-1288-4288-A4EE-49EE431B0AD9    Trace                         Running 
SleepStudyTraceSession                  Trace                         Running 
CldFltLog                               Trace                         Running 
ASUS_System_Control_Interface_TraceSession Trace                         Running 
NVIDIA-NVTOPPS-NOCAT                    Trace                         Running 
NVIDIA-NVTOPPS-FILTER                   Trace                         Running 
MpWppCoreTracing-20250808-104119-00000003-100000000 Trace                         Running 
MpWppTracing-20250808-004122-00000003-fffffffeffffffff Trace                         Running 
1DSListener                             Trace                         Running 
WPR_initiated_WprApp_WPR System Collector Trace                         Running 
WPR_initiated_WprApp_WPR Event Collector Trace                         Running 
UpdateSessionOrchestration              Trace                         Running 
MoUxCoreWorker                          Trace                         Running 
Microsoft.Windows.Remediation           Trace                         Running 
SHS-08082025-100058-7-1ff               Trace                         Running 
WinDiag-Realtime-Session                Trace                         Running 

The command completed successfully.

Ah - yes - I see it in the WPR_initiated_WprApp_WPR Event Collector!
So why aren't I seeing that event category? I'm looking at exactly the same screen as you - the Trace Statistics.

Hello Greg,

You have mentioned both Windows 10 and Windows 11 in this thread; are you trying to capture these events on the Windows 11 system?

I don't know with which release of Windows these events were introduced; the "ver" command on my PC shows "Microsoft Windows [Version 10.0.26100.4770]" (Windows 11 24H2).

Gary

Windows 11 Home - currently running the installation that was installed when shipped, updated recently. Will supply exact version soon.

Hello Greg,

I checked the Windows kernel version used when you created browser_01.etl and that seems to support these events.

Gary

Microsoft Windows [Version 10.0.26100.4652]

Hello Greg,

A test for the presence/absence of the events would be to execute the command:

logman start gary -ets -p {F2D06F08-592D-508C-C3AA-76F396FE18BD} -o timer.etl & logman stop gary -ets

The "&" joins the two commands (start and stop); this keeps the duration of the trace short. On my system, a 2.5 MB trace file (timer.etl) was created (a lot of events are generated).

Gary

I fiddled with the buffer sizes, and now it's working. (but I know my original settings worked for you. shrugs) Thanks for your patience.
Here's a new trace - about 90MB compressed: https://drive.google.com/file/d/1rU-JsxBmel71D8XepTjPOJvdLBQMf6hX/view?usp=sharing

This was created by simply opening & closing apps. I don't expect to be able to do this kind of thing when I get back to audio, but it's an easier way to create these strange idle events, that's all. The idle event is right near the end of the trace.

(deleted)

Hello Greg,

Here is a brief extract from the trace at the time of the 14 ms delay between clock interrupts:

There is quite a bit of analysis and inference work to do to determine if the reason for the length of delay can be understood.

Gary