Re: need help with AUHAL audio glitching at high cpu utilisation
Re: need help with AUHAL audio glitching at high cpu utilisation
- Subject: Re: need help with AUHAL audio glitching at high cpu utilisation
- From: Jeff Moore <email@hidden>
- Date: Tue, 7 Jul 2009 12:08:44 -0700
Writing some docs for the telemetry window has been on my to-do list
for a while now. At any rate, the best way to see what the events mean
is to just see where they are used in the code. The
SampleHardwarePlugIn project in our sample code is a fine place to see
it in action.
On Jul 6, 2009, at 10:47 PM, Ross Bencina wrote:
Thanks for your response Jeff
I thought you might be away. I will file a bug -- note that this is
with the built in audio driver on a MacBook, so its an Apple driver
-- do you guys deal with the drivers as well?
Finally, I know you're probably pretty busy catching up, but it
would still be helpful to me if you could answer my questions below
about what computations happen inside CoreAudio inbetween each of
the telemetry events in the log. I'm thinking I should add a
telemetry viewer to my app so people can track performance in more
detail and chase down possible system configuration issues.
Thanks!
Ross.
===================================
AudioMulch 2.0 is here!
http://www.audiomulch.com
----- Original Message ----- From: "Jeff Moore" <email@hidden>
To: "CoreAudio API" <email@hidden>
Sent: Tuesday, July 07, 2009 8:54 AM
Subject: Re: need help with AUHAL audio glitching at high cpu
utilisation
Sorry this took so long. I've been out on leave for the past week
or so.
At any rate, yes it certainly looks like the audio driver in
question is returning the error from the kernel trap at a time
when I wouldn't expect an error. There have been several similar
reports in the past (including a few filed by myself). It can't
hurt to file a bug report about your particular case though.
On Jul 2, 2009, at 6:55 PM, Ross Bencina wrote:
Hi Jeff
Are you able to offer any further insight into the issue below?
Stephane Letz reproduced similar behavior on another machine
(kAudioDeviceProcessorOverload being set) with 70-80% CPU.
Should we file a bug report?
Thanks
Ross.
===================================
AudioMulch 2.0 is here!
http://www.audiomulch.com
----- Original Message ----- From: "Ross Bencina" <email@hidden
>
To: "CoreAudio API" <email@hidden>
Sent: Thursday, June 25, 2009 8:43 PM
Subject: Re: need help with AUHAL audio glitching at high cpu
utilisation
Hi again Jeff
(sorry about the dup, didn't reply to list the first time)
I've generated some telemetry from HALLab now, and the results
confuse me
and imply that neither variance in CPU clock speed, execution
time of my
code, nor CA doing extra work, nor scheduling jitter is the
cause of the
glitching I'm observing:
http://www.audiomulch.com/~rossb/junk/patest_telemetry.png
This dump is from running a simple application that mixes 175
sine waves
generated with the sin() function. It consumes about 85% CPU on
my first gen
MacBook (according to my gettimeofday measurements). The nominal
sample rate
was 44100Hz with 256 frame i/o buffers. I was using built in
audio with
external speakers.
btw. I tried to save the dump out as text but the text file
contained data
in a different format and didn't include the event names. Is
there a way to
get the data in a more analyzable form without writing my own
telemetry
client? Its a shame i can't cut and paste the contents of the
telemetry
window into a text file.
I think I understand the data (but see below for some questions)
and I'm
still not sure why the writes are returning the late error (I found
somewhere where you noted that 0x2EE is a missed deadline).
Here's my analysis, please let me know what you think:
I'm outputing 256 sample blocks at nominal SR of 44100Hz. The
indicated rate
is 1.000002, so the actual sample rate is 44100.088, giving a
block period
of 5.805ms.
Now, if we consider the overrun with timestamp 299.841:
229.81 (+5.876, +0.103)
->cycle 229.842 ( 0.000)
->calls 229.844 (0.002)
->ioproc 229.845 (0.002)
<-ioproc 234.895 (5.049)
sig out: 234.896 (0.001)
<-calls 234.896 (0.001)
->write 234.897 (0.001)
<-write 234.912 (0.015)
<-cycle 234.939
The processing cycle starts 0.103ms late (presumably due to
scheduling
jitter). The total duration of the processing cycle (including
any write
overhead) is 5.071ms (234.912 - 229.841), if we include the
scheduling
jitter, the time from the ideal cycle start time to "<-
write" (presumably
write completion) is 5.174ms. Given that the block period is
5.805ms it is
unclear to me why write() is marking this as an underrun. What
actually is
it that CA is writing to that's indicated by <-write/->write?
And why would
it return that the data is late when according to my analysis
above it is
being delivered within bounds? I could guess that the driver
actually needs
the data earlier than it has requested it, or that the phase of
the CA
cycles is lagging what is necessary but I don't really know.
A separate observation is that the entire cycle takes 5.098ms
(234.939-229.841) yet the following cycle is scheduled at
+10.977 which
suggests that CA has dropped a cycle even though the entire
cycle at 229.841
executed within 5.805ms of the schedule cycle start time.
5.098 is about 87% of 5.805 which suggests that CA is throttling
at less
that 100% utilisation.
Can you explain this behavior please?
Now for some questions about the AUHAL telemetry events. I found
some
documentation about the CA telemetry events in a header file but
it didn't
really enlighten me. Could you please correct, fill in the gaps
and answer
the questions below?
->cycle = start of io cycle. the thread has just woken up
( what happens here? )
-> calls = what does this indicate?
(what happens here?)
-> ioproc = call to user io processing routine?
(user performs processing)
<- ioproc = user io processing routine returns?
(what happens here?)
<- calls = what does this indicate
(what happens here?)
-> write = CoreAudio writes buffers to the driver (does it
invoke the driver
synchronously here or is there some async handshake?)
<- write = Driver has completed writing samples to the device
(by this time
audio data is definitely queued with the driver)
(what happens here?)
<-cycle = end of io cycle, the thread is about to go to sleep
until the
next deadline
--
You mentioned that CA does extra processing to handle speaker
protection,
does this happen in the IO thread? if so where in the telemetry
sequence
does this occurr?
Thanks!
Ross.
_______________________________________________
Do not post admin requests to the list. They will be ignored.
Coreaudio-api mailing list (email@hidden)
Help/Unsubscribe/Update your Subscription:
This email sent to email@hidden
_______________________________________________
Do not post admin requests to the list. They will be ignored.
Coreaudio-api mailing list (email@hidden)
Help/Unsubscribe/Update your Subscription:
This email sent to email@hidden
--
Jeff Moore
Core Audio
Apple
_______________________________________________
Do not post admin requests to the list. They will be ignored.
Coreaudio-api mailing list (email@hidden)
Help/Unsubscribe/Update your Subscription:
This email sent to email@hidden
_______________________________________________
Do not post admin requests to the list. They will be ignored.
Coreaudio-api mailing list (email@hidden)
Help/Unsubscribe/Update your Subscription:
This email sent to email@hidden
--
Jeff Moore
Core Audio
Apple
_______________________________________________
Do not post admin requests to the list. They will be ignored.
Coreaudio-api mailing list (email@hidden)
Help/Unsubscribe/Update your Subscription:
This email sent to email@hidden