blob: 21df1d7666661f6f05c373078af9ba16156533f3 [file] [log] [blame]
Glenn Kasten97b5d0d2012-03-23 18:54:19 -07001/*
2 * Copyright (C) 2012 The Android Open Source Project
3 *
4 * Licensed under the Apache License, Version 2.0 (the "License");
5 * you may not use this file except in compliance with the License.
6 * You may obtain a copy of the License at
7 *
8 * http://www.apache.org/licenses/LICENSE-2.0
9 *
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License.
15 */
16
Glenn Kastena3d26282012-11-30 07:57:43 -080017// <IMPORTANT_WARNING>
18// Design rules for threadLoop() are given in the comments at section "Fast mixer thread" of
19// StateQueue.h. In particular, avoid library and system calls except at well-known points.
20// The design rules are only for threadLoop(), and don't apply to FastMixerDumpState methods.
21// </IMPORTANT_WARNING>
22
Glenn Kasten97b5d0d2012-03-23 18:54:19 -070023#define LOG_TAG "FastMixer"
Glenn Kasten7f5d3352013-02-15 23:55:04 +000024//#define LOG_NDEBUG 0
Glenn Kasten97b5d0d2012-03-23 18:54:19 -070025
Alex Rayb3a83642012-11-30 19:42:28 -080026#define ATRACE_TAG ATRACE_TAG_AUDIO
Alex Ray371eb972012-11-30 11:11:54 -080027
Glenn Kasten97b5d0d2012-03-23 18:54:19 -070028#include <sys/atomics.h>
29#include <time.h>
30#include <utils/Log.h>
Glenn Kastend8e6fd32012-05-07 11:07:57 -070031#include <utils/Trace.h>
Glenn Kasten97b5d0d2012-03-23 18:54:19 -070032#include <system/audio.h>
33#ifdef FAST_MIXER_STATISTICS
34#include <cpustats/CentralTendencyStatistics.h>
Glenn Kasten0a14c4c2012-06-13 14:58:49 -070035#ifdef CPU_FREQUENCY_STATISTICS
Glenn Kasten42d45cf2012-05-02 10:34:47 -070036#include <cpustats/ThreadCpuUsage.h>
Glenn Kasten97b5d0d2012-03-23 18:54:19 -070037#endif
Glenn Kasten0a14c4c2012-06-13 14:58:49 -070038#endif
Glenn Kasten97b5d0d2012-03-23 18:54:19 -070039#include "AudioMixer.h"
40#include "FastMixer.h"
41
42#define FAST_HOT_IDLE_NS 1000000L // 1 ms: time to sleep while hot idling
43#define FAST_DEFAULT_NS 999999999L // ~1 sec: default time to sleep
Glenn Kasteneb157162012-06-13 14:59:07 -070044#define MIN_WARMUP_CYCLES 2 // minimum number of loop cycles to wait for warmup
Glenn Kasten288ed212012-04-25 17:52:27 -070045#define MAX_WARMUP_CYCLES 10 // maximum number of loop cycles to wait for warmup
Glenn Kasten97b5d0d2012-03-23 18:54:19 -070046
47namespace android {
48
49// Fast mixer thread
50bool FastMixer::threadLoop()
51{
52 static const FastMixerState initial;
53 const FastMixerState *previous = &initial, *current = &initial;
54 FastMixerState preIdle; // copy of state before we went into idle
55 struct timespec oldTs = {0, 0};
56 bool oldTsValid = false;
57 long slopNs = 0; // accumulated time we've woken up too early (> 0) or too late (< 0)
58 long sleepNs = -1; // -1: busy wait, 0: sched_yield, > 0: nanosleep
59 int fastTrackNames[FastMixerState::kMaxFastTracks]; // handles used by mixer to identify tracks
60 int generations[FastMixerState::kMaxFastTracks]; // last observed mFastTracks[i].mGeneration
61 unsigned i;
62 for (i = 0; i < FastMixerState::kMaxFastTracks; ++i) {
63 fastTrackNames[i] = -1;
64 generations[i] = 0;
65 }
66 NBAIO_Sink *outputSink = NULL;
67 int outputSinkGen = 0;
68 AudioMixer* mixer = NULL;
69 short *mixBuffer = NULL;
70 enum {UNDEFINED, MIXED, ZEROED} mixBufferState = UNDEFINED;
71 NBAIO_Format format = Format_Invalid;
72 unsigned sampleRate = 0;
73 int fastTracksGen = 0;
74 long periodNs = 0; // expected period; the time required to render one mix buffer
Glenn Kasten288ed212012-04-25 17:52:27 -070075 long underrunNs = 0; // underrun likely when write cycle is greater than this value
76 long overrunNs = 0; // overrun likely when write cycle is less than this value
Glenn Kasten972af222012-06-13 17:14:03 -070077 long forceNs = 0; // if overrun detected, force the write cycle to take this much time
Glenn Kasten288ed212012-04-25 17:52:27 -070078 long warmupNs = 0; // warmup complete when write cycle is greater than to this value
Glenn Kasten97b5d0d2012-03-23 18:54:19 -070079 FastMixerDumpState dummyDumpState, *dumpState = &dummyDumpState;
80 bool ignoreNextOverrun = true; // used to ignore initial overrun and first after an underrun
81#ifdef FAST_MIXER_STATISTICS
Glenn Kasten42d45cf2012-05-02 10:34:47 -070082 struct timespec oldLoad = {0, 0}; // previous value of clock_gettime(CLOCK_THREAD_CPUTIME_ID)
83 bool oldLoadValid = false; // whether oldLoad is valid
84 uint32_t bounds = 0;
85 bool full = false; // whether we have collected at least kSamplingN samples
Glenn Kasten0a14c4c2012-06-13 14:58:49 -070086#ifdef CPU_FREQUENCY_STATISTICS
Glenn Kasten42d45cf2012-05-02 10:34:47 -070087 ThreadCpuUsage tcu; // for reading the current CPU clock frequency in kHz
Glenn Kasten97b5d0d2012-03-23 18:54:19 -070088#endif
Glenn Kasten0a14c4c2012-06-13 14:58:49 -070089#endif
Glenn Kasten97b5d0d2012-03-23 18:54:19 -070090 unsigned coldGen = 0; // last observed mColdGen
Glenn Kasten288ed212012-04-25 17:52:27 -070091 bool isWarm = false; // true means ready to mix, false means wait for warmup before mixing
92 struct timespec measuredWarmupTs = {0, 0}; // how long did it take for warmup to complete
93 uint32_t warmupCycles = 0; // counter of number of loop cycles required to warmup
Glenn Kastenfbae5da2012-05-21 09:17:20 -070094 NBAIO_Sink* teeSink = NULL; // if non-NULL, then duplicate write() to this non-blocking sink
Glenn Kasten9e58b552013-01-18 15:09:48 -080095 NBLog::Writer dummyLogWriter, *logWriter = &dummyLogWriter;
Glenn Kasten97b5d0d2012-03-23 18:54:19 -070096
97 for (;;) {
98
99 // either nanosleep, sched_yield, or busy wait
100 if (sleepNs >= 0) {
101 if (sleepNs > 0) {
102 ALOG_ASSERT(sleepNs < 1000000000);
103 const struct timespec req = {0, sleepNs};
104 nanosleep(&req, NULL);
105 } else {
106 sched_yield();
107 }
108 }
109 // default to long sleep for next cycle
110 sleepNs = FAST_DEFAULT_NS;
111
112 // poll for state change
113 const FastMixerState *next = mSQ.poll();
114 if (next == NULL) {
115 // continue to use the default initial state until a real state is available
116 ALOG_ASSERT(current == &initial && previous == &initial);
117 next = current;
118 }
119
120 FastMixerState::Command command = next->mCommand;
121 if (next != current) {
122
123 // As soon as possible of learning of a new dump area, start using it
124 dumpState = next->mDumpState != NULL ? next->mDumpState : &dummyDumpState;
Glenn Kastenfbae5da2012-05-21 09:17:20 -0700125 teeSink = next->mTeeSink;
Glenn Kasten9e58b552013-01-18 15:09:48 -0800126 logWriter = next->mNBLogWriter != NULL ? next->mNBLogWriter : &dummyLogWriter;
Glenn Kastenab7d72f2013-02-27 09:05:28 -0800127 if (mixer != NULL) {
128 mixer->setLog(logWriter);
129 }
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700130
131 // We want to always have a valid reference to the previous (non-idle) state.
132 // However, the state queue only guarantees access to current and previous states.
133 // So when there is a transition from a non-idle state into an idle state, we make a
134 // copy of the last known non-idle state so it is still available on return from idle.
135 // The possible transitions are:
136 // non-idle -> non-idle update previous from current in-place
137 // non-idle -> idle update previous from copy of current
138 // idle -> idle don't update previous
139 // idle -> non-idle don't update previous
140 if (!(current->mCommand & FastMixerState::IDLE)) {
141 if (command & FastMixerState::IDLE) {
142 preIdle = *current;
143 current = &preIdle;
144 oldTsValid = false;
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700145 oldLoadValid = false;
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700146 ignoreNextOverrun = true;
147 }
148 previous = current;
149 }
150 current = next;
151 }
152#if !LOG_NDEBUG
153 next = NULL; // not referenced again
154#endif
155
156 dumpState->mCommand = command;
157
158 switch (command) {
159 case FastMixerState::INITIAL:
160 case FastMixerState::HOT_IDLE:
161 sleepNs = FAST_HOT_IDLE_NS;
162 continue;
163 case FastMixerState::COLD_IDLE:
164 // only perform a cold idle command once
Glenn Kasten21e8c502012-04-12 09:39:42 -0700165 // FIXME consider checking previous state and only perform if previous != COLD_IDLE
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700166 if (current->mColdGen != coldGen) {
167 int32_t *coldFutexAddr = current->mColdFutexAddr;
168 ALOG_ASSERT(coldFutexAddr != NULL);
169 int32_t old = android_atomic_dec(coldFutexAddr);
170 if (old <= 0) {
171 __futex_syscall4(coldFutexAddr, FUTEX_WAIT_PRIVATE, old - 1, NULL);
172 }
Glenn Kastena07f17c2013-04-23 12:39:37 -0700173 int policy = sched_getscheduler(0);
174 if (!(policy == SCHED_FIFO || policy == SCHED_RR)) {
175 ALOGE("did not receive expected priority boost");
176 }
Glenn Kasten288ed212012-04-25 17:52:27 -0700177 // This may be overly conservative; there could be times that the normal mixer
178 // requests such a brief cold idle that it doesn't require resetting this flag.
179 isWarm = false;
180 measuredWarmupTs.tv_sec = 0;
181 measuredWarmupTs.tv_nsec = 0;
182 warmupCycles = 0;
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700183 sleepNs = -1;
184 coldGen = current->mColdGen;
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700185 bounds = 0;
186 full = false;
Glenn Kasten04a4ca42012-06-01 10:49:51 -0700187 oldTsValid = !clock_gettime(CLOCK_MONOTONIC, &oldTs);
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700188 } else {
189 sleepNs = FAST_HOT_IDLE_NS;
190 }
191 continue;
192 case FastMixerState::EXIT:
193 delete mixer;
194 delete[] mixBuffer;
195 return false;
196 case FastMixerState::MIX:
197 case FastMixerState::WRITE:
198 case FastMixerState::MIX_WRITE:
199 break;
200 default:
201 LOG_FATAL("bad command %d", command);
202 }
203
204 // there is a non-idle state available to us; did the state change?
205 size_t frameCount = current->mFrameCount;
206 if (current != previous) {
207
208 // handle state change here, but since we want to diff the state,
209 // we're prepared for previous == &initial the first time through
210 unsigned previousTrackMask;
211
212 // check for change in output HAL configuration
213 NBAIO_Format previousFormat = format;
214 if (current->mOutputSinkGen != outputSinkGen) {
215 outputSink = current->mOutputSink;
216 outputSinkGen = current->mOutputSinkGen;
217 if (outputSink == NULL) {
218 format = Format_Invalid;
219 sampleRate = 0;
220 } else {
221 format = outputSink->format();
222 sampleRate = Format_sampleRate(format);
223 ALOG_ASSERT(Format_channelCount(format) == 2);
224 }
Glenn Kasten21e8c502012-04-12 09:39:42 -0700225 dumpState->mSampleRate = sampleRate;
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700226 }
227
228 if ((format != previousFormat) || (frameCount != previous->mFrameCount)) {
229 // FIXME to avoid priority inversion, don't delete here
230 delete mixer;
231 mixer = NULL;
232 delete[] mixBuffer;
233 mixBuffer = NULL;
234 if (frameCount > 0 && sampleRate > 0) {
235 // FIXME new may block for unbounded time at internal mutex of the heap
236 // implementation; it would be better to have normal mixer allocate for us
237 // to avoid blocking here and to prevent possible priority inversion
238 mixer = new AudioMixer(frameCount, sampleRate, FastMixerState::kMaxFastTracks);
239 mixBuffer = new short[frameCount * 2];
240 periodNs = (frameCount * 1000000000LL) / sampleRate; // 1.00
241 underrunNs = (frameCount * 1750000000LL) / sampleRate; // 1.75
Glenn Kasten0d27c652012-08-07 10:38:59 -0700242 overrunNs = (frameCount * 500000000LL) / sampleRate; // 0.50
243 forceNs = (frameCount * 950000000LL) / sampleRate; // 0.95
Glenn Kasten288ed212012-04-25 17:52:27 -0700244 warmupNs = (frameCount * 500000000LL) / sampleRate; // 0.50
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700245 } else {
246 periodNs = 0;
247 underrunNs = 0;
248 overrunNs = 0;
Glenn Kasten972af222012-06-13 17:14:03 -0700249 forceNs = 0;
250 warmupNs = 0;
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700251 }
252 mixBufferState = UNDEFINED;
253#if !LOG_NDEBUG
254 for (i = 0; i < FastMixerState::kMaxFastTracks; ++i) {
255 fastTrackNames[i] = -1;
256 }
257#endif
258 // we need to reconfigure all active tracks
259 previousTrackMask = 0;
260 fastTracksGen = current->mFastTracksGen - 1;
Glenn Kasten21e8c502012-04-12 09:39:42 -0700261 dumpState->mFrameCount = frameCount;
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700262 } else {
263 previousTrackMask = previous->mTrackMask;
264 }
265
266 // check for change in active track set
267 unsigned currentTrackMask = current->mTrackMask;
Glenn Kasten1295bb4d2012-05-31 07:43:43 -0700268 dumpState->mTrackMask = currentTrackMask;
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700269 if (current->mFastTracksGen != fastTracksGen) {
270 ALOG_ASSERT(mixBuffer != NULL);
271 int name;
272
273 // process removed tracks first to avoid running out of track names
274 unsigned removedTracks = previousTrackMask & ~currentTrackMask;
275 while (removedTracks != 0) {
276 i = __builtin_ctz(removedTracks);
277 removedTracks &= ~(1 << i);
278 const FastTrack* fastTrack = &current->mFastTracks[i];
Glenn Kasten288ed212012-04-25 17:52:27 -0700279 ALOG_ASSERT(fastTrack->mBufferProvider == NULL);
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700280 if (mixer != NULL) {
281 name = fastTrackNames[i];
282 ALOG_ASSERT(name >= 0);
283 mixer->deleteTrackName(name);
284 }
285#if !LOG_NDEBUG
286 fastTrackNames[i] = -1;
287#endif
Glenn Kasten288ed212012-04-25 17:52:27 -0700288 // don't reset track dump state, since other side is ignoring it
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700289 generations[i] = fastTrack->mGeneration;
290 }
291
292 // now process added tracks
293 unsigned addedTracks = currentTrackMask & ~previousTrackMask;
294 while (addedTracks != 0) {
295 i = __builtin_ctz(addedTracks);
296 addedTracks &= ~(1 << i);
297 const FastTrack* fastTrack = &current->mFastTracks[i];
298 AudioBufferProvider *bufferProvider = fastTrack->mBufferProvider;
299 ALOG_ASSERT(bufferProvider != NULL && fastTrackNames[i] == -1);
300 if (mixer != NULL) {
Jean-Michel Trivife3156e2012-09-10 18:58:27 -0700301 // calling getTrackName with default channel mask and a random invalid
302 // sessionId (no effects here)
303 name = mixer->getTrackName(AUDIO_CHANNEL_OUT_STEREO, -555);
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700304 ALOG_ASSERT(name >= 0);
305 fastTrackNames[i] = name;
306 mixer->setBufferProvider(name, bufferProvider);
307 mixer->setParameter(name, AudioMixer::TRACK, AudioMixer::MAIN_BUFFER,
308 (void *) mixBuffer);
309 // newly allocated track names default to full scale volume
Glenn Kasten21e8c502012-04-12 09:39:42 -0700310 if (fastTrack->mSampleRate != 0 && fastTrack->mSampleRate != sampleRate) {
311 mixer->setParameter(name, AudioMixer::RESAMPLE,
312 AudioMixer::SAMPLE_RATE, (void*) fastTrack->mSampleRate);
313 }
314 mixer->setParameter(name, AudioMixer::TRACK, AudioMixer::CHANNEL_MASK,
315 (void *) fastTrack->mChannelMask);
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700316 mixer->enable(name);
317 }
318 generations[i] = fastTrack->mGeneration;
319 }
320
Glenn Kastenab7d72f2013-02-27 09:05:28 -0800321 // finally process (potentially) modified tracks; these use the same slot
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700322 // but may have a different buffer provider or volume provider
323 unsigned modifiedTracks = currentTrackMask & previousTrackMask;
324 while (modifiedTracks != 0) {
325 i = __builtin_ctz(modifiedTracks);
326 modifiedTracks &= ~(1 << i);
327 const FastTrack* fastTrack = &current->mFastTracks[i];
328 if (fastTrack->mGeneration != generations[i]) {
Glenn Kastenab7d72f2013-02-27 09:05:28 -0800329 // this track was actually modified
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700330 AudioBufferProvider *bufferProvider = fastTrack->mBufferProvider;
331 ALOG_ASSERT(bufferProvider != NULL);
332 if (mixer != NULL) {
333 name = fastTrackNames[i];
334 ALOG_ASSERT(name >= 0);
335 mixer->setBufferProvider(name, bufferProvider);
336 if (fastTrack->mVolumeProvider == NULL) {
337 mixer->setParameter(name, AudioMixer::VOLUME, AudioMixer::VOLUME0,
338 (void *)0x1000);
339 mixer->setParameter(name, AudioMixer::VOLUME, AudioMixer::VOLUME1,
340 (void *)0x1000);
341 }
Glenn Kasten21e8c502012-04-12 09:39:42 -0700342 if (fastTrack->mSampleRate != 0 &&
343 fastTrack->mSampleRate != sampleRate) {
344 mixer->setParameter(name, AudioMixer::RESAMPLE,
345 AudioMixer::SAMPLE_RATE, (void*) fastTrack->mSampleRate);
346 } else {
347 mixer->setParameter(name, AudioMixer::RESAMPLE,
348 AudioMixer::REMOVE, NULL);
349 }
350 mixer->setParameter(name, AudioMixer::TRACK, AudioMixer::CHANNEL_MASK,
351 (void *) fastTrack->mChannelMask);
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700352 // already enabled
353 }
354 generations[i] = fastTrack->mGeneration;
355 }
356 }
357
358 fastTracksGen = current->mFastTracksGen;
359
360 dumpState->mNumTracks = popcount(currentTrackMask);
361 }
362
363#if 1 // FIXME shouldn't need this
364 // only process state change once
365 previous = current;
366#endif
367 }
368
369 // do work using current state here
Glenn Kasten288ed212012-04-25 17:52:27 -0700370 if ((command & FastMixerState::MIX) && (mixer != NULL) && isWarm) {
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700371 ALOG_ASSERT(mixBuffer != NULL);
Glenn Kasten288ed212012-04-25 17:52:27 -0700372 // for each track, update volume and check for underrun
373 unsigned currentTrackMask = current->mTrackMask;
374 while (currentTrackMask != 0) {
375 i = __builtin_ctz(currentTrackMask);
376 currentTrackMask &= ~(1 << i);
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700377 const FastTrack* fastTrack = &current->mFastTracks[i];
378 int name = fastTrackNames[i];
379 ALOG_ASSERT(name >= 0);
380 if (fastTrack->mVolumeProvider != NULL) {
381 uint32_t vlr = fastTrack->mVolumeProvider->getVolumeLR();
382 mixer->setParameter(name, AudioMixer::VOLUME, AudioMixer::VOLUME0,
383 (void *)(vlr & 0xFFFF));
384 mixer->setParameter(name, AudioMixer::VOLUME, AudioMixer::VOLUME1,
385 (void *)(vlr >> 16));
386 }
Glenn Kasten288ed212012-04-25 17:52:27 -0700387 // FIXME The current implementation of framesReady() for fast tracks
388 // takes a tryLock, which can block
389 // up to 1 ms. If enough active tracks all blocked in sequence, this would result
390 // in the overall fast mix cycle being delayed. Should use a non-blocking FIFO.
391 size_t framesReady = fastTrack->mBufferProvider->framesReady();
Alex Rayb3a83642012-11-30 19:42:28 -0800392 if (ATRACE_ENABLED()) {
393 // I wish we had formatted trace names
394 char traceName[16];
Glenn Kastenc9b2e202013-02-26 11:32:32 -0800395 strcpy(traceName, "fRdy");
396 traceName[4] = i + (i < 10 ? '0' : 'A' - 10);
397 traceName[5] = '\0';
Alex Rayb3a83642012-11-30 19:42:28 -0800398 ATRACE_INT(traceName, framesReady);
399 }
Glenn Kasten288ed212012-04-25 17:52:27 -0700400 FastTrackDump *ftDump = &dumpState->mTracks[i];
Glenn Kasten09474df2012-05-10 14:48:07 -0700401 FastTrackUnderruns underruns = ftDump->mUnderruns;
Glenn Kasten288ed212012-04-25 17:52:27 -0700402 if (framesReady < frameCount) {
Glenn Kasten288ed212012-04-25 17:52:27 -0700403 if (framesReady == 0) {
Glenn Kasten09474df2012-05-10 14:48:07 -0700404 underruns.mBitFields.mEmpty++;
405 underruns.mBitFields.mMostRecent = UNDERRUN_EMPTY;
Glenn Kasten288ed212012-04-25 17:52:27 -0700406 mixer->disable(name);
407 } else {
408 // allow mixing partial buffer
Glenn Kasten09474df2012-05-10 14:48:07 -0700409 underruns.mBitFields.mPartial++;
410 underruns.mBitFields.mMostRecent = UNDERRUN_PARTIAL;
Glenn Kasten288ed212012-04-25 17:52:27 -0700411 mixer->enable(name);
412 }
Glenn Kasten09474df2012-05-10 14:48:07 -0700413 } else {
414 underruns.mBitFields.mFull++;
415 underruns.mBitFields.mMostRecent = UNDERRUN_FULL;
Glenn Kasten288ed212012-04-25 17:52:27 -0700416 mixer->enable(name);
417 }
Glenn Kasten09474df2012-05-10 14:48:07 -0700418 ftDump->mUnderruns = underruns;
Glenn Kasten1295bb4d2012-05-31 07:43:43 -0700419 ftDump->mFramesReady = framesReady;
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700420 }
John Grossman2c3b2da2012-08-02 17:08:54 -0700421
422 int64_t pts;
423 if (outputSink == NULL || (OK != outputSink->getNextWriteTimestamp(&pts)))
424 pts = AudioBufferProvider::kInvalidPTS;
425
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700426 // process() is CPU-bound
John Grossman2c3b2da2012-08-02 17:08:54 -0700427 mixer->process(pts);
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700428 mixBufferState = MIXED;
429 } else if (mixBufferState == MIXED) {
430 mixBufferState = UNDEFINED;
431 }
Glenn Kasten288ed212012-04-25 17:52:27 -0700432 bool attemptedWrite = false;
433 //bool didFullWrite = false; // dumpsys could display a count of partial writes
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700434 if ((command & FastMixerState::WRITE) && (outputSink != NULL) && (mixBuffer != NULL)) {
435 if (mixBufferState == UNDEFINED) {
436 memset(mixBuffer, 0, frameCount * 2 * sizeof(short));
437 mixBufferState = ZEROED;
438 }
Glenn Kastenfbae5da2012-05-21 09:17:20 -0700439 if (teeSink != NULL) {
440 (void) teeSink->write(mixBuffer, frameCount);
441 }
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700442 // FIXME write() is non-blocking and lock-free for a properly implemented NBAIO sink,
443 // but this code should be modified to handle both non-blocking and blocking sinks
444 dumpState->mWriteSequence++;
Simon Wilson2d590962012-11-29 15:18:50 -0800445 ATRACE_BEGIN("write");
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700446 ssize_t framesWritten = outputSink->write(mixBuffer, frameCount);
Simon Wilson2d590962012-11-29 15:18:50 -0800447 ATRACE_END();
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700448 dumpState->mWriteSequence++;
449 if (framesWritten >= 0) {
Glenn Kastenab7d72f2013-02-27 09:05:28 -0800450 ALOG_ASSERT((size_t) framesWritten <= frameCount);
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700451 dumpState->mFramesWritten += framesWritten;
Glenn Kasten288ed212012-04-25 17:52:27 -0700452 //if ((size_t) framesWritten == frameCount) {
453 // didFullWrite = true;
454 //}
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700455 } else {
456 dumpState->mWriteErrors++;
457 }
Glenn Kasten288ed212012-04-25 17:52:27 -0700458 attemptedWrite = true;
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700459 // FIXME count # of writes blocked excessively, CPU usage, etc. for dump
460 }
461
462 // To be exactly periodic, compute the next sleep time based on current time.
463 // This code doesn't have long-term stability when the sink is non-blocking.
464 // FIXME To avoid drift, use the local audio clock or watch the sink's fill status.
465 struct timespec newTs;
466 int rc = clock_gettime(CLOCK_MONOTONIC, &newTs);
467 if (rc == 0) {
Glenn Kastenab7d72f2013-02-27 09:05:28 -0800468 //logWriter->logTimestamp(newTs);
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700469 if (oldTsValid) {
470 time_t sec = newTs.tv_sec - oldTs.tv_sec;
471 long nsec = newTs.tv_nsec - oldTs.tv_nsec;
Glenn Kasten80b32732012-09-24 11:29:00 -0700472 ALOGE_IF(sec < 0 || (sec == 0 && nsec < 0),
473 "clock_gettime(CLOCK_MONOTONIC) failed: was %ld.%09ld but now %ld.%09ld",
474 oldTs.tv_sec, oldTs.tv_nsec, newTs.tv_sec, newTs.tv_nsec);
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700475 if (nsec < 0) {
476 --sec;
477 nsec += 1000000000;
478 }
Glenn Kasten288ed212012-04-25 17:52:27 -0700479 // To avoid an initial underrun on fast tracks after exiting standby,
480 // do not start pulling data from tracks and mixing until warmup is complete.
481 // Warmup is considered complete after the earlier of:
Glenn Kasteneb157162012-06-13 14:59:07 -0700482 // MIN_WARMUP_CYCLES write() attempts and last one blocks for at least warmupNs
Glenn Kasten288ed212012-04-25 17:52:27 -0700483 // MAX_WARMUP_CYCLES write() attempts.
484 // This is overly conservative, but to get better accuracy requires a new HAL API.
485 if (!isWarm && attemptedWrite) {
486 measuredWarmupTs.tv_sec += sec;
487 measuredWarmupTs.tv_nsec += nsec;
488 if (measuredWarmupTs.tv_nsec >= 1000000000) {
489 measuredWarmupTs.tv_sec++;
490 measuredWarmupTs.tv_nsec -= 1000000000;
491 }
492 ++warmupCycles;
Glenn Kasteneb157162012-06-13 14:59:07 -0700493 if ((nsec > warmupNs && warmupCycles >= MIN_WARMUP_CYCLES) ||
Glenn Kasten288ed212012-04-25 17:52:27 -0700494 (warmupCycles >= MAX_WARMUP_CYCLES)) {
495 isWarm = true;
496 dumpState->mMeasuredWarmupTs = measuredWarmupTs;
497 dumpState->mWarmupCycles = warmupCycles;
498 }
499 }
Glenn Kasten972af222012-06-13 17:14:03 -0700500 sleepNs = -1;
501 if (isWarm) {
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700502 if (sec > 0 || nsec > underrunNs) {
Alex Rayb3a83642012-11-30 19:42:28 -0800503 ATRACE_NAME("underrun");
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700504 // FIXME only log occasionally
505 ALOGV("underrun: time since last cycle %d.%03ld sec",
506 (int) sec, nsec / 1000000L);
507 dumpState->mUnderruns++;
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700508 ignoreNextOverrun = true;
509 } else if (nsec < overrunNs) {
510 if (ignoreNextOverrun) {
511 ignoreNextOverrun = false;
512 } else {
513 // FIXME only log occasionally
514 ALOGV("overrun: time since last cycle %d.%03ld sec",
515 (int) sec, nsec / 1000000L);
516 dumpState->mOverruns++;
517 }
Glenn Kasten972af222012-06-13 17:14:03 -0700518 // This forces a minimum cycle time. It:
519 // - compensates for an audio HAL with jitter due to sample rate conversion
520 // - works with a variable buffer depth audio HAL that never pulls at a rate
521 // < than overrunNs per buffer.
522 // - recovers from overrun immediately after underrun
523 // It doesn't work with a non-blocking audio HAL.
524 sleepNs = forceNs - nsec;
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700525 } else {
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700526 ignoreNextOverrun = false;
527 }
Glenn Kasten972af222012-06-13 17:14:03 -0700528 }
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700529#ifdef FAST_MIXER_STATISTICS
Glenn Kasteneb157162012-06-13 14:59:07 -0700530 if (isWarm) {
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700531 // advance the FIFO queue bounds
532 size_t i = bounds & (FastMixerDumpState::kSamplingN - 1);
Glenn Kastene58ccce2012-05-11 15:19:24 -0700533 bounds = (bounds & 0xFFFF0000) | ((bounds + 1) & 0xFFFF);
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700534 if (full) {
535 bounds += 0x10000;
536 } else if (!(bounds & (FastMixerDumpState::kSamplingN - 1))) {
537 full = true;
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700538 }
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700539 // compute the delta value of clock_gettime(CLOCK_MONOTONIC)
540 uint32_t monotonicNs = nsec;
541 if (sec > 0 && sec < 4) {
542 monotonicNs += sec * 1000000000;
543 }
544 // compute the raw CPU load = delta value of clock_gettime(CLOCK_THREAD_CPUTIME_ID)
545 uint32_t loadNs = 0;
546 struct timespec newLoad;
547 rc = clock_gettime(CLOCK_THREAD_CPUTIME_ID, &newLoad);
548 if (rc == 0) {
549 if (oldLoadValid) {
550 sec = newLoad.tv_sec - oldLoad.tv_sec;
551 nsec = newLoad.tv_nsec - oldLoad.tv_nsec;
552 if (nsec < 0) {
553 --sec;
554 nsec += 1000000000;
555 }
556 loadNs = nsec;
557 if (sec > 0 && sec < 4) {
558 loadNs += sec * 1000000000;
559 }
560 } else {
561 // first time through the loop
562 oldLoadValid = true;
563 }
564 oldLoad = newLoad;
565 }
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700566#ifdef CPU_FREQUENCY_STATISTICS
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700567 // get the absolute value of CPU clock frequency in kHz
568 int cpuNum = sched_getcpu();
569 uint32_t kHz = tcu.getCpukHz(cpuNum);
Glenn Kastenc059bd42012-05-14 17:41:09 -0700570 kHz = (kHz << 4) | (cpuNum & 0xF);
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700571#endif
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700572 // save values in FIFO queues for dumpsys
573 // these stores #1, #2, #3 are not atomic with respect to each other,
574 // or with respect to store #4 below
575 dumpState->mMonotonicNs[i] = monotonicNs;
576 dumpState->mLoadNs[i] = loadNs;
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700577#ifdef CPU_FREQUENCY_STATISTICS
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700578 dumpState->mCpukHz[i] = kHz;
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700579#endif
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700580 // this store #4 is not atomic with respect to stores #1, #2, #3 above, but
581 // the newest open and oldest closed halves are atomic with respect to each other
582 dumpState->mBounds = bounds;
Glenn Kasten99c99d02012-05-14 16:37:13 -0700583 ATRACE_INT("cycle_ms", monotonicNs / 1000000);
584 ATRACE_INT("load_us", loadNs / 1000);
Glenn Kasteneb157162012-06-13 14:59:07 -0700585 }
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700586#endif
587 } else {
588 // first time through the loop
589 oldTsValid = true;
590 sleepNs = periodNs;
591 ignoreNextOverrun = true;
592 }
593 oldTs = newTs;
594 } else {
595 // monotonic clock is broken
596 oldTsValid = false;
597 sleepNs = periodNs;
598 }
599
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700600
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700601 } // for (;;)
602
603 // never return 'true'; Thread::_threadLoop() locks mutex which can result in priority inversion
604}
605
606FastMixerDumpState::FastMixerDumpState() :
607 mCommand(FastMixerState::INITIAL), mWriteSequence(0), mFramesWritten(0),
Glenn Kasten21e8c502012-04-12 09:39:42 -0700608 mNumTracks(0), mWriteErrors(0), mUnderruns(0), mOverruns(0),
Glenn Kasten1295bb4d2012-05-31 07:43:43 -0700609 mSampleRate(0), mFrameCount(0), /* mMeasuredWarmupTs({0, 0}), */ mWarmupCycles(0),
610 mTrackMask(0)
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700611#ifdef FAST_MIXER_STATISTICS
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700612 , mBounds(0)
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700613#endif
614{
Glenn Kasten288ed212012-04-25 17:52:27 -0700615 mMeasuredWarmupTs.tv_sec = 0;
616 mMeasuredWarmupTs.tv_nsec = 0;
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700617 // sample arrays aren't accessed atomically with respect to the bounds,
618 // so clearing reduces chance for dumpsys to read random uninitialized samples
619 memset(&mMonotonicNs, 0, sizeof(mMonotonicNs));
620 memset(&mLoadNs, 0, sizeof(mLoadNs));
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700621#ifdef CPU_FREQUENCY_STATISTICS
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700622 memset(&mCpukHz, 0, sizeof(mCpukHz));
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700623#endif
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700624}
625
626FastMixerDumpState::~FastMixerDumpState()
627{
628}
629
Glenn Kasten1ab212cf2012-09-07 12:58:38 -0700630// helper function called by qsort()
631static int compare_uint32_t(const void *pa, const void *pb)
632{
633 uint32_t a = *(const uint32_t *)pa;
634 uint32_t b = *(const uint32_t *)pb;
635 if (a < b) {
636 return -1;
637 } else if (a > b) {
638 return 1;
639 } else {
640 return 0;
641 }
642}
643
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700644void FastMixerDumpState::dump(int fd)
645{
Glenn Kasten868c0ab2012-06-13 14:59:17 -0700646 if (mCommand == FastMixerState::INITIAL) {
647 fdprintf(fd, "FastMixer not initialized\n");
648 return;
649 }
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700650#define COMMAND_MAX 32
651 char string[COMMAND_MAX];
652 switch (mCommand) {
653 case FastMixerState::INITIAL:
654 strcpy(string, "INITIAL");
655 break;
656 case FastMixerState::HOT_IDLE:
657 strcpy(string, "HOT_IDLE");
658 break;
659 case FastMixerState::COLD_IDLE:
660 strcpy(string, "COLD_IDLE");
661 break;
662 case FastMixerState::EXIT:
663 strcpy(string, "EXIT");
664 break;
665 case FastMixerState::MIX:
666 strcpy(string, "MIX");
667 break;
668 case FastMixerState::WRITE:
669 strcpy(string, "WRITE");
670 break;
671 case FastMixerState::MIX_WRITE:
672 strcpy(string, "MIX_WRITE");
673 break;
674 default:
675 snprintf(string, COMMAND_MAX, "%d", mCommand);
676 break;
677 }
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700678 double measuredWarmupMs = (mMeasuredWarmupTs.tv_sec * 1000.0) +
Glenn Kasten288ed212012-04-25 17:52:27 -0700679 (mMeasuredWarmupTs.tv_nsec / 1000000.0);
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700680 double mixPeriodSec = (double) mFrameCount / (double) mSampleRate;
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700681 fdprintf(fd, "FastMixer command=%s writeSequence=%u framesWritten=%u\n"
Glenn Kasten21e8c502012-04-12 09:39:42 -0700682 " numTracks=%u writeErrors=%u underruns=%u overruns=%u\n"
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700683 " sampleRate=%u frameCount=%u measuredWarmup=%.3g ms, warmupCycles=%u\n"
684 " mixPeriod=%.2f ms\n",
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700685 string, mWriteSequence, mFramesWritten,
Glenn Kasten21e8c502012-04-12 09:39:42 -0700686 mNumTracks, mWriteErrors, mUnderruns, mOverruns,
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700687 mSampleRate, mFrameCount, measuredWarmupMs, mWarmupCycles,
688 mixPeriodSec * 1e3);
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700689#ifdef FAST_MIXER_STATISTICS
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700690 // find the interval of valid samples
691 uint32_t bounds = mBounds;
692 uint32_t newestOpen = bounds & 0xFFFF;
693 uint32_t oldestClosed = bounds >> 16;
694 uint32_t n = (newestOpen - oldestClosed) & 0xFFFF;
695 if (n > kSamplingN) {
696 ALOGE("too many samples %u", n);
697 n = kSamplingN;
698 }
699 // statistics for monotonic (wall clock) time, thread raw CPU load in time, CPU clock frequency,
700 // and adjusted CPU load in MHz normalized for CPU clock frequency
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700701 CentralTendencyStatistics wall, loadNs;
702#ifdef CPU_FREQUENCY_STATISTICS
703 CentralTendencyStatistics kHz, loadMHz;
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700704 uint32_t previousCpukHz = 0;
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700705#endif
Glenn Kasten1ab212cf2012-09-07 12:58:38 -0700706 // Assuming a normal distribution for cycle times, three standard deviations on either side of
707 // the mean account for 99.73% of the population. So if we take each tail to be 1/1000 of the
708 // sample set, we get 99.8% combined, or close to three standard deviations.
709 static const uint32_t kTailDenominator = 1000;
710 uint32_t *tail = n >= kTailDenominator ? new uint32_t[n] : NULL;
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700711 // loop over all the samples
Glenn Kasten1ab212cf2012-09-07 12:58:38 -0700712 for (uint32_t j = 0; j < n; ++j) {
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700713 size_t i = oldestClosed++ & (kSamplingN - 1);
714 uint32_t wallNs = mMonotonicNs[i];
Glenn Kasten1ab212cf2012-09-07 12:58:38 -0700715 if (tail != NULL) {
716 tail[j] = wallNs;
717 }
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700718 wall.sample(wallNs);
719 uint32_t sampleLoadNs = mLoadNs[i];
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700720 loadNs.sample(sampleLoadNs);
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700721#ifdef CPU_FREQUENCY_STATISTICS
722 uint32_t sampleCpukHz = mCpukHz[i];
Glenn Kastenc059bd42012-05-14 17:41:09 -0700723 // skip bad kHz samples
724 if ((sampleCpukHz & ~0xF) != 0) {
725 kHz.sample(sampleCpukHz >> 4);
726 if (sampleCpukHz == previousCpukHz) {
727 double megacycles = (double) sampleLoadNs * (double) (sampleCpukHz >> 4) * 1e-12;
728 double adjMHz = megacycles / mixPeriodSec; // _not_ wallNs * 1e9
729 loadMHz.sample(adjMHz);
730 }
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700731 }
732 previousCpukHz = sampleCpukHz;
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700733#endif
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700734 }
735 fdprintf(fd, "Simple moving statistics over last %.1f seconds:\n", wall.n() * mixPeriodSec);
736 fdprintf(fd, " wall clock time in ms per mix cycle:\n"
737 " mean=%.2f min=%.2f max=%.2f stddev=%.2f\n",
738 wall.mean()*1e-6, wall.minimum()*1e-6, wall.maximum()*1e-6, wall.stddev()*1e-6);
739 fdprintf(fd, " raw CPU load in us per mix cycle:\n"
740 " mean=%.0f min=%.0f max=%.0f stddev=%.0f\n",
741 loadNs.mean()*1e-3, loadNs.minimum()*1e-3, loadNs.maximum()*1e-3,
742 loadNs.stddev()*1e-3);
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700743#ifdef CPU_FREQUENCY_STATISTICS
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700744 fdprintf(fd, " CPU clock frequency in MHz:\n"
745 " mean=%.0f min=%.0f max=%.0f stddev=%.0f\n",
746 kHz.mean()*1e-3, kHz.minimum()*1e-3, kHz.maximum()*1e-3, kHz.stddev()*1e-3);
747 fdprintf(fd, " adjusted CPU load in MHz (i.e. normalized for CPU clock frequency):\n"
748 " mean=%.1f min=%.1f max=%.1f stddev=%.1f\n",
749 loadMHz.mean(), loadMHz.minimum(), loadMHz.maximum(), loadMHz.stddev());
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700750#endif
Glenn Kasten1ab212cf2012-09-07 12:58:38 -0700751 if (tail != NULL) {
752 qsort(tail, n, sizeof(uint32_t), compare_uint32_t);
753 // assume same number of tail samples on each side, left and right
754 uint32_t count = n / kTailDenominator;
755 CentralTendencyStatistics left, right;
756 for (uint32_t i = 0; i < count; ++i) {
757 left.sample(tail[i]);
758 right.sample(tail[n - (i + 1)]);
759 }
760 fdprintf(fd, "Distribution of mix cycle times in ms for the tails (> ~3 stddev outliers):\n"
761 " left tail: mean=%.2f min=%.2f max=%.2f stddev=%.2f\n"
762 " right tail: mean=%.2f min=%.2f max=%.2f stddev=%.2f\n",
763 left.mean()*1e-6, left.minimum()*1e-6, left.maximum()*1e-6, left.stddev()*1e-6,
764 right.mean()*1e-6, right.minimum()*1e-6, right.maximum()*1e-6,
765 right.stddev()*1e-6);
766 delete[] tail;
767 }
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700768#endif
Glenn Kasten1295bb4d2012-05-31 07:43:43 -0700769 // The active track mask and track states are updated non-atomically.
770 // So if we relied on isActive to decide whether to display,
771 // then we might display an obsolete track or omit an active track.
772 // Instead we always display all tracks, with an indication
773 // of whether we think the track is active.
774 uint32_t trackMask = mTrackMask;
775 fdprintf(fd, "Fast tracks: kMaxFastTracks=%u activeMask=%#x\n",
776 FastMixerState::kMaxFastTracks, trackMask);
777 fdprintf(fd, "Index Active Full Partial Empty Recent Ready\n");
778 for (uint32_t i = 0; i < FastMixerState::kMaxFastTracks; ++i, trackMask >>= 1) {
779 bool isActive = trackMask & 1;
780 const FastTrackDump *ftDump = &mTracks[i];
781 const FastTrackUnderruns& underruns = ftDump->mUnderruns;
782 const char *mostRecent;
783 switch (underruns.mBitFields.mMostRecent) {
784 case UNDERRUN_FULL:
785 mostRecent = "full";
786 break;
787 case UNDERRUN_PARTIAL:
788 mostRecent = "partial";
789 break;
790 case UNDERRUN_EMPTY:
791 mostRecent = "empty";
792 break;
793 default:
794 mostRecent = "?";
795 break;
796 }
797 fdprintf(fd, "%5u %6s %4u %7u %5u %7s %5u\n", i, isActive ? "yes" : "no",
798 (underruns.mBitFields.mFull) & UNDERRUN_MASK,
799 (underruns.mBitFields.mPartial) & UNDERRUN_MASK,
800 (underruns.mBitFields.mEmpty) & UNDERRUN_MASK,
801 mostRecent, ftDump->mFramesReady);
802 }
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700803}
804
805} // namespace android