• Open Menu Close Menu
  • Apple
  • Shopping Bag
  • Apple
  • Mac
  • iPad
  • iPhone
  • Watch
  • TV
  • Music
  • Support
  • Search apple.com
  • Shopping Bag

Lists

Open Menu Close Menu
  • Terms and Conditions
  • Lists hosted on this site
  • Email the Postmaster
  • Tips for posting to public mailing lists
Re: Tracing latencies
[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

Re: Tracing latencies


  • Subject: Re: Tracing latencies
  • From: Jeff Moore <email@hidden>
  • Date: Tue, 15 Nov 2005 11:38:03 -0800


On Nov 15, 2005, at 8:08 AM, Stéphane Letz wrote:

Hi,

I'm trying to use latency tracing tools to understand what happens in a IO proc running at 64 frames on a recent Powerbook 64 (OSX 10.4.3) that shows constant kAudioDeviceProcessorOverload.

I'm using latency.c and CALatencyLog code (starting from the AUTracer.cpp file) to trigger latency capture when an kAudioDeviceProcessorOverload notification is received.


I get this kind if file and I'm wondering why iI see a policy = TIMESHARE type of thread when a was expecting tracing the real- time IO thread.

You should just ignore the header when you are using the latency code in this fashion. It's there because the code is repurposed from the code in Darwin that implements the latency(1) command. The data you want to look at is the trace itself.


Captured Latency Log for I/O Cycle Overload


---------------------------------------------------------------------- -------------------------------------------------------
Thu Jan 1 01:00:00 scheduling latency = 9001.2us sleep_request = 1000us policy = TIMESHARE priority = default


RelTime(Us) Delta debugid arg1 arg2 arg3 arg4 thread cpu command

862.0 0.0 MACH_MKRUNNABLE 1e4d318 5e 0 0 2306000 0 jackdmp
875.8 13.8 MACH_SCHED jackdmp @ pri 27 --> kernel_task @ pri 94K 2306000 0
883.8 7.9 MACH_CALLOUT 143f38 0 0 0 1e4d318 0 kernel_task
892.0 8.2 MACH_SCHED kernel_task @ pri 94 -- > jackdmp @ pri 27* 1e4d318 0
907.6 15.6 MACH_MKRUNNABLE 1732000 51 0 0 2306000 0 jackdmp



then I don't think the result can be analysed because I don't see the RT thread in the trace.

Indeed. This trace shows the kernel pre-empting a normal user thread.

How the latency tools must be configurated ?

There isn't any configuration beyond instantiating the CALatencyLog object with the path to the log file. It's all self configuring.


The trick is figuring out the correct time values to pass to Capture (). HALLab uses the host time portions of the HAL's time stamps coming in from the telemetry as the guide. When this code finds an overload in the telemetry, it finds the host times for the start and end of the cycle containing the overload and pads them by a couple of milliseconds to be sure that it gets the right data from the trace buffer. These are the values it passes to Capture() and it seems to work pretty well. It captures the trace data for the bad cycle and enough context around it to be able to figure out what's going on.

--

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
References: 
 >Tracing latencies (From: Stéphane Letz <email@hidden>)

  • Prev by Date: Tracing latencies
  • Next by Date: AudioFileGetPropertyInfo() on kAudioFilePropertyDataFormat returning 0?
  • Previous by thread: Tracing latencies
  • Next by thread: AudioFileGetPropertyInfo() on kAudioFilePropertyDataFormat returning 0?
  • Index(es):
    • Date
    • Thread