blob: 0366dfe26228ff0d03d6bd8e669976684d88d004 [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
17#define LOG_TAG "FastMixer"
18//#define LOG_NDEBUG 0
19
Alex Rayaf348742012-11-30 11:11:54 -080020/** Uncomment for systrace.
21 * ATRACE_TAG will default to ATRACE_TAG_NEVER in the header.
22 */
23//#define ATRACE_TAG ATRACE_TAG_AUDIO
24
Glenn Kasten97b5d0d2012-03-23 18:54:19 -070025#include <sys/atomics.h>
26#include <time.h>
27#include <utils/Log.h>
Glenn Kastend8e6fd32012-05-07 11:07:57 -070028#include <utils/Trace.h>
Glenn Kasten97b5d0d2012-03-23 18:54:19 -070029#include <system/audio.h>
30#ifdef FAST_MIXER_STATISTICS
31#include <cpustats/CentralTendencyStatistics.h>
Glenn Kasten0a14c4c2012-06-13 14:58:49 -070032#ifdef CPU_FREQUENCY_STATISTICS
Glenn Kasten42d45cf2012-05-02 10:34:47 -070033#include <cpustats/ThreadCpuUsage.h>
Glenn Kasten97b5d0d2012-03-23 18:54:19 -070034#endif
Glenn Kasten0a14c4c2012-06-13 14:58:49 -070035#endif
Glenn Kasten97b5d0d2012-03-23 18:54:19 -070036#include "AudioMixer.h"
37#include "FastMixer.h"
38
39#define FAST_HOT_IDLE_NS 1000000L // 1 ms: time to sleep while hot idling
40#define FAST_DEFAULT_NS 999999999L // ~1 sec: default time to sleep
Glenn Kasteneb157162012-06-13 14:59:07 -070041#define MIN_WARMUP_CYCLES 2 // minimum number of loop cycles to wait for warmup
Glenn Kasten288ed212012-04-25 17:52:27 -070042#define MAX_WARMUP_CYCLES 10 // maximum number of loop cycles to wait for warmup
Glenn Kasten97b5d0d2012-03-23 18:54:19 -070043
44namespace android {
45
46// Fast mixer thread
47bool FastMixer::threadLoop()
48{
49 static const FastMixerState initial;
50 const FastMixerState *previous = &initial, *current = &initial;
51 FastMixerState preIdle; // copy of state before we went into idle
52 struct timespec oldTs = {0, 0};
53 bool oldTsValid = false;
54 long slopNs = 0; // accumulated time we've woken up too early (> 0) or too late (< 0)
55 long sleepNs = -1; // -1: busy wait, 0: sched_yield, > 0: nanosleep
56 int fastTrackNames[FastMixerState::kMaxFastTracks]; // handles used by mixer to identify tracks
57 int generations[FastMixerState::kMaxFastTracks]; // last observed mFastTracks[i].mGeneration
58 unsigned i;
59 for (i = 0; i < FastMixerState::kMaxFastTracks; ++i) {
60 fastTrackNames[i] = -1;
61 generations[i] = 0;
62 }
63 NBAIO_Sink *outputSink = NULL;
64 int outputSinkGen = 0;
65 AudioMixer* mixer = NULL;
66 short *mixBuffer = NULL;
67 enum {UNDEFINED, MIXED, ZEROED} mixBufferState = UNDEFINED;
68 NBAIO_Format format = Format_Invalid;
69 unsigned sampleRate = 0;
70 int fastTracksGen = 0;
71 long periodNs = 0; // expected period; the time required to render one mix buffer
Glenn Kasten288ed212012-04-25 17:52:27 -070072 long underrunNs = 0; // underrun likely when write cycle is greater than this value
73 long overrunNs = 0; // overrun likely when write cycle is less than this value
Glenn Kasten972af222012-06-13 17:14:03 -070074 long forceNs = 0; // if overrun detected, force the write cycle to take this much time
Glenn Kasten288ed212012-04-25 17:52:27 -070075 long warmupNs = 0; // warmup complete when write cycle is greater than to this value
Glenn Kasten97b5d0d2012-03-23 18:54:19 -070076 FastMixerDumpState dummyDumpState, *dumpState = &dummyDumpState;
77 bool ignoreNextOverrun = true; // used to ignore initial overrun and first after an underrun
78#ifdef FAST_MIXER_STATISTICS
Glenn Kasten42d45cf2012-05-02 10:34:47 -070079 struct timespec oldLoad = {0, 0}; // previous value of clock_gettime(CLOCK_THREAD_CPUTIME_ID)
80 bool oldLoadValid = false; // whether oldLoad is valid
81 uint32_t bounds = 0;
82 bool full = false; // whether we have collected at least kSamplingN samples
Glenn Kasten0a14c4c2012-06-13 14:58:49 -070083#ifdef CPU_FREQUENCY_STATISTICS
Glenn Kasten42d45cf2012-05-02 10:34:47 -070084 ThreadCpuUsage tcu; // for reading the current CPU clock frequency in kHz
Glenn Kasten97b5d0d2012-03-23 18:54:19 -070085#endif
Glenn Kasten0a14c4c2012-06-13 14:58:49 -070086#endif
Glenn Kasten97b5d0d2012-03-23 18:54:19 -070087 unsigned coldGen = 0; // last observed mColdGen
Glenn Kasten288ed212012-04-25 17:52:27 -070088 bool isWarm = false; // true means ready to mix, false means wait for warmup before mixing
89 struct timespec measuredWarmupTs = {0, 0}; // how long did it take for warmup to complete
90 uint32_t warmupCycles = 0; // counter of number of loop cycles required to warmup
Glenn Kastenfbae5da2012-05-21 09:17:20 -070091 NBAIO_Sink* teeSink = NULL; // if non-NULL, then duplicate write() to this non-blocking sink
Glenn Kasten97b5d0d2012-03-23 18:54:19 -070092
93 for (;;) {
94
95 // either nanosleep, sched_yield, or busy wait
96 if (sleepNs >= 0) {
97 if (sleepNs > 0) {
98 ALOG_ASSERT(sleepNs < 1000000000);
99 const struct timespec req = {0, sleepNs};
100 nanosleep(&req, NULL);
101 } else {
102 sched_yield();
103 }
104 }
105 // default to long sleep for next cycle
106 sleepNs = FAST_DEFAULT_NS;
107
108 // poll for state change
109 const FastMixerState *next = mSQ.poll();
110 if (next == NULL) {
111 // continue to use the default initial state until a real state is available
112 ALOG_ASSERT(current == &initial && previous == &initial);
113 next = current;
114 }
115
116 FastMixerState::Command command = next->mCommand;
117 if (next != current) {
118
119 // As soon as possible of learning of a new dump area, start using it
120 dumpState = next->mDumpState != NULL ? next->mDumpState : &dummyDumpState;
Glenn Kastenfbae5da2012-05-21 09:17:20 -0700121 teeSink = next->mTeeSink;
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700122
123 // We want to always have a valid reference to the previous (non-idle) state.
124 // However, the state queue only guarantees access to current and previous states.
125 // So when there is a transition from a non-idle state into an idle state, we make a
126 // copy of the last known non-idle state so it is still available on return from idle.
127 // The possible transitions are:
128 // non-idle -> non-idle update previous from current in-place
129 // non-idle -> idle update previous from copy of current
130 // idle -> idle don't update previous
131 // idle -> non-idle don't update previous
132 if (!(current->mCommand & FastMixerState::IDLE)) {
133 if (command & FastMixerState::IDLE) {
134 preIdle = *current;
135 current = &preIdle;
136 oldTsValid = false;
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700137 oldLoadValid = false;
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700138 ignoreNextOverrun = true;
139 }
140 previous = current;
141 }
142 current = next;
143 }
144#if !LOG_NDEBUG
145 next = NULL; // not referenced again
146#endif
147
148 dumpState->mCommand = command;
149
150 switch (command) {
151 case FastMixerState::INITIAL:
152 case FastMixerState::HOT_IDLE:
153 sleepNs = FAST_HOT_IDLE_NS;
154 continue;
155 case FastMixerState::COLD_IDLE:
156 // only perform a cold idle command once
Glenn Kasten21e8c502012-04-12 09:39:42 -0700157 // FIXME consider checking previous state and only perform if previous != COLD_IDLE
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700158 if (current->mColdGen != coldGen) {
159 int32_t *coldFutexAddr = current->mColdFutexAddr;
160 ALOG_ASSERT(coldFutexAddr != NULL);
161 int32_t old = android_atomic_dec(coldFutexAddr);
162 if (old <= 0) {
163 __futex_syscall4(coldFutexAddr, FUTEX_WAIT_PRIVATE, old - 1, NULL);
164 }
Glenn Kasten288ed212012-04-25 17:52:27 -0700165 // This may be overly conservative; there could be times that the normal mixer
166 // requests such a brief cold idle that it doesn't require resetting this flag.
167 isWarm = false;
168 measuredWarmupTs.tv_sec = 0;
169 measuredWarmupTs.tv_nsec = 0;
170 warmupCycles = 0;
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700171 sleepNs = -1;
172 coldGen = current->mColdGen;
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700173 bounds = 0;
174 full = false;
Glenn Kasten04a4ca42012-06-01 10:49:51 -0700175 oldTsValid = !clock_gettime(CLOCK_MONOTONIC, &oldTs);
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700176 } else {
177 sleepNs = FAST_HOT_IDLE_NS;
178 }
179 continue;
180 case FastMixerState::EXIT:
181 delete mixer;
182 delete[] mixBuffer;
183 return false;
184 case FastMixerState::MIX:
185 case FastMixerState::WRITE:
186 case FastMixerState::MIX_WRITE:
187 break;
188 default:
189 LOG_FATAL("bad command %d", command);
190 }
191
192 // there is a non-idle state available to us; did the state change?
193 size_t frameCount = current->mFrameCount;
194 if (current != previous) {
195
196 // handle state change here, but since we want to diff the state,
197 // we're prepared for previous == &initial the first time through
198 unsigned previousTrackMask;
199
200 // check for change in output HAL configuration
201 NBAIO_Format previousFormat = format;
202 if (current->mOutputSinkGen != outputSinkGen) {
203 outputSink = current->mOutputSink;
204 outputSinkGen = current->mOutputSinkGen;
205 if (outputSink == NULL) {
206 format = Format_Invalid;
207 sampleRate = 0;
208 } else {
209 format = outputSink->format();
210 sampleRate = Format_sampleRate(format);
211 ALOG_ASSERT(Format_channelCount(format) == 2);
212 }
Glenn Kasten21e8c502012-04-12 09:39:42 -0700213 dumpState->mSampleRate = sampleRate;
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700214 }
215
216 if ((format != previousFormat) || (frameCount != previous->mFrameCount)) {
217 // FIXME to avoid priority inversion, don't delete here
218 delete mixer;
219 mixer = NULL;
220 delete[] mixBuffer;
221 mixBuffer = NULL;
222 if (frameCount > 0 && sampleRate > 0) {
223 // FIXME new may block for unbounded time at internal mutex of the heap
224 // implementation; it would be better to have normal mixer allocate for us
225 // to avoid blocking here and to prevent possible priority inversion
226 mixer = new AudioMixer(frameCount, sampleRate, FastMixerState::kMaxFastTracks);
227 mixBuffer = new short[frameCount * 2];
228 periodNs = (frameCount * 1000000000LL) / sampleRate; // 1.00
229 underrunNs = (frameCount * 1750000000LL) / sampleRate; // 1.75
Glenn Kasten0d27c652012-08-07 10:38:59 -0700230 overrunNs = (frameCount * 500000000LL) / sampleRate; // 0.50
231 forceNs = (frameCount * 950000000LL) / sampleRate; // 0.95
Glenn Kasten288ed212012-04-25 17:52:27 -0700232 warmupNs = (frameCount * 500000000LL) / sampleRate; // 0.50
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700233 } else {
234 periodNs = 0;
235 underrunNs = 0;
236 overrunNs = 0;
Glenn Kasten972af222012-06-13 17:14:03 -0700237 forceNs = 0;
238 warmupNs = 0;
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700239 }
240 mixBufferState = UNDEFINED;
241#if !LOG_NDEBUG
242 for (i = 0; i < FastMixerState::kMaxFastTracks; ++i) {
243 fastTrackNames[i] = -1;
244 }
245#endif
246 // we need to reconfigure all active tracks
247 previousTrackMask = 0;
248 fastTracksGen = current->mFastTracksGen - 1;
Glenn Kasten21e8c502012-04-12 09:39:42 -0700249 dumpState->mFrameCount = frameCount;
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700250 } else {
251 previousTrackMask = previous->mTrackMask;
252 }
253
254 // check for change in active track set
255 unsigned currentTrackMask = current->mTrackMask;
Glenn Kasten1295bb4d2012-05-31 07:43:43 -0700256 dumpState->mTrackMask = currentTrackMask;
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700257 if (current->mFastTracksGen != fastTracksGen) {
258 ALOG_ASSERT(mixBuffer != NULL);
259 int name;
260
261 // process removed tracks first to avoid running out of track names
262 unsigned removedTracks = previousTrackMask & ~currentTrackMask;
263 while (removedTracks != 0) {
264 i = __builtin_ctz(removedTracks);
265 removedTracks &= ~(1 << i);
266 const FastTrack* fastTrack = &current->mFastTracks[i];
Glenn Kasten288ed212012-04-25 17:52:27 -0700267 ALOG_ASSERT(fastTrack->mBufferProvider == NULL);
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700268 if (mixer != NULL) {
269 name = fastTrackNames[i];
270 ALOG_ASSERT(name >= 0);
271 mixer->deleteTrackName(name);
272 }
273#if !LOG_NDEBUG
274 fastTrackNames[i] = -1;
275#endif
Glenn Kasten288ed212012-04-25 17:52:27 -0700276 // don't reset track dump state, since other side is ignoring it
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700277 generations[i] = fastTrack->mGeneration;
278 }
279
280 // now process added tracks
281 unsigned addedTracks = currentTrackMask & ~previousTrackMask;
282 while (addedTracks != 0) {
283 i = __builtin_ctz(addedTracks);
284 addedTracks &= ~(1 << i);
285 const FastTrack* fastTrack = &current->mFastTracks[i];
286 AudioBufferProvider *bufferProvider = fastTrack->mBufferProvider;
287 ALOG_ASSERT(bufferProvider != NULL && fastTrackNames[i] == -1);
288 if (mixer != NULL) {
Jean-Michel Trivicff71372012-09-10 18:58:27 -0700289 // calling getTrackName with default channel mask and a random invalid
290 // sessionId (no effects here)
291 name = mixer->getTrackName(AUDIO_CHANNEL_OUT_STEREO, -555);
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700292 ALOG_ASSERT(name >= 0);
293 fastTrackNames[i] = name;
294 mixer->setBufferProvider(name, bufferProvider);
295 mixer->setParameter(name, AudioMixer::TRACK, AudioMixer::MAIN_BUFFER,
296 (void *) mixBuffer);
297 // newly allocated track names default to full scale volume
Glenn Kasten21e8c502012-04-12 09:39:42 -0700298 if (fastTrack->mSampleRate != 0 && fastTrack->mSampleRate != sampleRate) {
299 mixer->setParameter(name, AudioMixer::RESAMPLE,
300 AudioMixer::SAMPLE_RATE, (void*) fastTrack->mSampleRate);
301 }
302 mixer->setParameter(name, AudioMixer::TRACK, AudioMixer::CHANNEL_MASK,
303 (void *) fastTrack->mChannelMask);
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700304 mixer->enable(name);
305 }
306 generations[i] = fastTrack->mGeneration;
307 }
308
309 // finally process modified tracks; these use the same slot
310 // but may have a different buffer provider or volume provider
311 unsigned modifiedTracks = currentTrackMask & previousTrackMask;
312 while (modifiedTracks != 0) {
313 i = __builtin_ctz(modifiedTracks);
314 modifiedTracks &= ~(1 << i);
315 const FastTrack* fastTrack = &current->mFastTracks[i];
316 if (fastTrack->mGeneration != generations[i]) {
317 AudioBufferProvider *bufferProvider = fastTrack->mBufferProvider;
318 ALOG_ASSERT(bufferProvider != NULL);
319 if (mixer != NULL) {
320 name = fastTrackNames[i];
321 ALOG_ASSERT(name >= 0);
322 mixer->setBufferProvider(name, bufferProvider);
323 if (fastTrack->mVolumeProvider == NULL) {
324 mixer->setParameter(name, AudioMixer::VOLUME, AudioMixer::VOLUME0,
325 (void *)0x1000);
326 mixer->setParameter(name, AudioMixer::VOLUME, AudioMixer::VOLUME1,
327 (void *)0x1000);
328 }
Glenn Kasten21e8c502012-04-12 09:39:42 -0700329 if (fastTrack->mSampleRate != 0 &&
330 fastTrack->mSampleRate != sampleRate) {
331 mixer->setParameter(name, AudioMixer::RESAMPLE,
332 AudioMixer::SAMPLE_RATE, (void*) fastTrack->mSampleRate);
333 } else {
334 mixer->setParameter(name, AudioMixer::RESAMPLE,
335 AudioMixer::REMOVE, NULL);
336 }
337 mixer->setParameter(name, AudioMixer::TRACK, AudioMixer::CHANNEL_MASK,
338 (void *) fastTrack->mChannelMask);
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700339 // already enabled
340 }
341 generations[i] = fastTrack->mGeneration;
342 }
343 }
344
345 fastTracksGen = current->mFastTracksGen;
346
347 dumpState->mNumTracks = popcount(currentTrackMask);
348 }
349
350#if 1 // FIXME shouldn't need this
351 // only process state change once
352 previous = current;
353#endif
354 }
355
356 // do work using current state here
Glenn Kasten288ed212012-04-25 17:52:27 -0700357 if ((command & FastMixerState::MIX) && (mixer != NULL) && isWarm) {
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700358 ALOG_ASSERT(mixBuffer != NULL);
Glenn Kasten288ed212012-04-25 17:52:27 -0700359 // for each track, update volume and check for underrun
360 unsigned currentTrackMask = current->mTrackMask;
361 while (currentTrackMask != 0) {
362 i = __builtin_ctz(currentTrackMask);
363 currentTrackMask &= ~(1 << i);
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700364 const FastTrack* fastTrack = &current->mFastTracks[i];
365 int name = fastTrackNames[i];
366 ALOG_ASSERT(name >= 0);
367 if (fastTrack->mVolumeProvider != NULL) {
368 uint32_t vlr = fastTrack->mVolumeProvider->getVolumeLR();
369 mixer->setParameter(name, AudioMixer::VOLUME, AudioMixer::VOLUME0,
370 (void *)(vlr & 0xFFFF));
371 mixer->setParameter(name, AudioMixer::VOLUME, AudioMixer::VOLUME1,
372 (void *)(vlr >> 16));
373 }
Glenn Kasten288ed212012-04-25 17:52:27 -0700374 // FIXME The current implementation of framesReady() for fast tracks
375 // takes a tryLock, which can block
376 // up to 1 ms. If enough active tracks all blocked in sequence, this would result
377 // in the overall fast mix cycle being delayed. Should use a non-blocking FIFO.
378 size_t framesReady = fastTrack->mBufferProvider->framesReady();
Glenn Kasten99c99d02012-05-14 16:37:13 -0700379#if defined(ATRACE_TAG) && (ATRACE_TAG != ATRACE_TAG_NEVER)
380 // I wish we had formatted trace names
381 char traceName[16];
382 strcpy(traceName, "framesReady");
383 traceName[11] = i + (i < 10 ? '0' : 'A' - 10);
384 traceName[12] = '\0';
385 ATRACE_INT(traceName, framesReady);
386#endif
Glenn Kasten288ed212012-04-25 17:52:27 -0700387 FastTrackDump *ftDump = &dumpState->mTracks[i];
Glenn Kasten09474df2012-05-10 14:48:07 -0700388 FastTrackUnderruns underruns = ftDump->mUnderruns;
Glenn Kasten288ed212012-04-25 17:52:27 -0700389 if (framesReady < frameCount) {
Glenn Kasten288ed212012-04-25 17:52:27 -0700390 if (framesReady == 0) {
Glenn Kasten09474df2012-05-10 14:48:07 -0700391 underruns.mBitFields.mEmpty++;
392 underruns.mBitFields.mMostRecent = UNDERRUN_EMPTY;
Glenn Kasten288ed212012-04-25 17:52:27 -0700393 mixer->disable(name);
394 } else {
395 // allow mixing partial buffer
Glenn Kasten09474df2012-05-10 14:48:07 -0700396 underruns.mBitFields.mPartial++;
397 underruns.mBitFields.mMostRecent = UNDERRUN_PARTIAL;
Glenn Kasten288ed212012-04-25 17:52:27 -0700398 mixer->enable(name);
399 }
Glenn Kasten09474df2012-05-10 14:48:07 -0700400 } else {
401 underruns.mBitFields.mFull++;
402 underruns.mBitFields.mMostRecent = UNDERRUN_FULL;
Glenn Kasten288ed212012-04-25 17:52:27 -0700403 mixer->enable(name);
404 }
Glenn Kasten09474df2012-05-10 14:48:07 -0700405 ftDump->mUnderruns = underruns;
Glenn Kasten1295bb4d2012-05-31 07:43:43 -0700406 ftDump->mFramesReady = framesReady;
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700407 }
John Grossman2c3b2da2012-08-02 17:08:54 -0700408
409 int64_t pts;
410 if (outputSink == NULL || (OK != outputSink->getNextWriteTimestamp(&pts)))
411 pts = AudioBufferProvider::kInvalidPTS;
412
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700413 // process() is CPU-bound
John Grossman2c3b2da2012-08-02 17:08:54 -0700414 mixer->process(pts);
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700415 mixBufferState = MIXED;
416 } else if (mixBufferState == MIXED) {
417 mixBufferState = UNDEFINED;
418 }
Glenn Kasten288ed212012-04-25 17:52:27 -0700419 bool attemptedWrite = false;
420 //bool didFullWrite = false; // dumpsys could display a count of partial writes
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700421 if ((command & FastMixerState::WRITE) && (outputSink != NULL) && (mixBuffer != NULL)) {
422 if (mixBufferState == UNDEFINED) {
423 memset(mixBuffer, 0, frameCount * 2 * sizeof(short));
424 mixBufferState = ZEROED;
425 }
Glenn Kastenfbae5da2012-05-21 09:17:20 -0700426 if (teeSink != NULL) {
427 (void) teeSink->write(mixBuffer, frameCount);
428 }
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700429 // FIXME write() is non-blocking and lock-free for a properly implemented NBAIO sink,
430 // but this code should be modified to handle both non-blocking and blocking sinks
431 dumpState->mWriteSequence++;
Glenn Kasten99c99d02012-05-14 16:37:13 -0700432#if defined(ATRACE_TAG) && (ATRACE_TAG != ATRACE_TAG_NEVER)
Simon Wilson7a90bc92012-11-29 15:18:50 -0800433 ATRACE_BEGIN("write");
Glenn Kasten99c99d02012-05-14 16:37:13 -0700434#endif
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700435 ssize_t framesWritten = outputSink->write(mixBuffer, frameCount);
Glenn Kasten99c99d02012-05-14 16:37:13 -0700436#if defined(ATRACE_TAG) && (ATRACE_TAG != ATRACE_TAG_NEVER)
Simon Wilson7a90bc92012-11-29 15:18:50 -0800437 ATRACE_END();
Glenn Kasten99c99d02012-05-14 16:37:13 -0700438#endif
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700439 dumpState->mWriteSequence++;
440 if (framesWritten >= 0) {
Glenn Kasten288ed212012-04-25 17:52:27 -0700441 ALOG_ASSERT(framesWritten <= frameCount);
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700442 dumpState->mFramesWritten += framesWritten;
Glenn Kasten288ed212012-04-25 17:52:27 -0700443 //if ((size_t) framesWritten == frameCount) {
444 // didFullWrite = true;
445 //}
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700446 } else {
447 dumpState->mWriteErrors++;
448 }
Glenn Kasten288ed212012-04-25 17:52:27 -0700449 attemptedWrite = true;
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700450 // FIXME count # of writes blocked excessively, CPU usage, etc. for dump
451 }
452
453 // To be exactly periodic, compute the next sleep time based on current time.
454 // This code doesn't have long-term stability when the sink is non-blocking.
455 // FIXME To avoid drift, use the local audio clock or watch the sink's fill status.
456 struct timespec newTs;
457 int rc = clock_gettime(CLOCK_MONOTONIC, &newTs);
458 if (rc == 0) {
459 if (oldTsValid) {
460 time_t sec = newTs.tv_sec - oldTs.tv_sec;
461 long nsec = newTs.tv_nsec - oldTs.tv_nsec;
Glenn Kasten99ae06b2012-09-24 11:29:00 -0700462 ALOGE_IF(sec < 0 || (sec == 0 && nsec < 0),
463 "clock_gettime(CLOCK_MONOTONIC) failed: was %ld.%09ld but now %ld.%09ld",
464 oldTs.tv_sec, oldTs.tv_nsec, newTs.tv_sec, newTs.tv_nsec);
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700465 if (nsec < 0) {
466 --sec;
467 nsec += 1000000000;
468 }
Glenn Kasten288ed212012-04-25 17:52:27 -0700469 // To avoid an initial underrun on fast tracks after exiting standby,
470 // do not start pulling data from tracks and mixing until warmup is complete.
471 // Warmup is considered complete after the earlier of:
Glenn Kasteneb157162012-06-13 14:59:07 -0700472 // MIN_WARMUP_CYCLES write() attempts and last one blocks for at least warmupNs
Glenn Kasten288ed212012-04-25 17:52:27 -0700473 // MAX_WARMUP_CYCLES write() attempts.
474 // This is overly conservative, but to get better accuracy requires a new HAL API.
475 if (!isWarm && attemptedWrite) {
476 measuredWarmupTs.tv_sec += sec;
477 measuredWarmupTs.tv_nsec += nsec;
478 if (measuredWarmupTs.tv_nsec >= 1000000000) {
479 measuredWarmupTs.tv_sec++;
480 measuredWarmupTs.tv_nsec -= 1000000000;
481 }
482 ++warmupCycles;
Glenn Kasteneb157162012-06-13 14:59:07 -0700483 if ((nsec > warmupNs && warmupCycles >= MIN_WARMUP_CYCLES) ||
Glenn Kasten288ed212012-04-25 17:52:27 -0700484 (warmupCycles >= MAX_WARMUP_CYCLES)) {
485 isWarm = true;
486 dumpState->mMeasuredWarmupTs = measuredWarmupTs;
487 dumpState->mWarmupCycles = warmupCycles;
488 }
489 }
Glenn Kasten972af222012-06-13 17:14:03 -0700490 sleepNs = -1;
491 if (isWarm) {
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700492 if (sec > 0 || nsec > underrunNs) {
Glenn Kasten99c99d02012-05-14 16:37:13 -0700493#if defined(ATRACE_TAG) && (ATRACE_TAG != ATRACE_TAG_NEVER)
Glenn Kastend8e6fd32012-05-07 11:07:57 -0700494 ScopedTrace st(ATRACE_TAG, "underrun");
Glenn Kasten99c99d02012-05-14 16:37:13 -0700495#endif
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700496 // FIXME only log occasionally
497 ALOGV("underrun: time since last cycle %d.%03ld sec",
498 (int) sec, nsec / 1000000L);
499 dumpState->mUnderruns++;
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700500 ignoreNextOverrun = true;
501 } else if (nsec < overrunNs) {
502 if (ignoreNextOverrun) {
503 ignoreNextOverrun = false;
504 } else {
505 // FIXME only log occasionally
506 ALOGV("overrun: time since last cycle %d.%03ld sec",
507 (int) sec, nsec / 1000000L);
508 dumpState->mOverruns++;
509 }
Glenn Kasten972af222012-06-13 17:14:03 -0700510 // This forces a minimum cycle time. It:
511 // - compensates for an audio HAL with jitter due to sample rate conversion
512 // - works with a variable buffer depth audio HAL that never pulls at a rate
513 // < than overrunNs per buffer.
514 // - recovers from overrun immediately after underrun
515 // It doesn't work with a non-blocking audio HAL.
516 sleepNs = forceNs - nsec;
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700517 } else {
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700518 ignoreNextOverrun = false;
519 }
Glenn Kasten972af222012-06-13 17:14:03 -0700520 }
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700521#ifdef FAST_MIXER_STATISTICS
Glenn Kasteneb157162012-06-13 14:59:07 -0700522 if (isWarm) {
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700523 // advance the FIFO queue bounds
524 size_t i = bounds & (FastMixerDumpState::kSamplingN - 1);
Glenn Kastene58ccce2012-05-11 15:19:24 -0700525 bounds = (bounds & 0xFFFF0000) | ((bounds + 1) & 0xFFFF);
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700526 if (full) {
527 bounds += 0x10000;
528 } else if (!(bounds & (FastMixerDumpState::kSamplingN - 1))) {
529 full = true;
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700530 }
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700531 // compute the delta value of clock_gettime(CLOCK_MONOTONIC)
532 uint32_t monotonicNs = nsec;
533 if (sec > 0 && sec < 4) {
534 monotonicNs += sec * 1000000000;
535 }
536 // compute the raw CPU load = delta value of clock_gettime(CLOCK_THREAD_CPUTIME_ID)
537 uint32_t loadNs = 0;
538 struct timespec newLoad;
539 rc = clock_gettime(CLOCK_THREAD_CPUTIME_ID, &newLoad);
540 if (rc == 0) {
541 if (oldLoadValid) {
542 sec = newLoad.tv_sec - oldLoad.tv_sec;
543 nsec = newLoad.tv_nsec - oldLoad.tv_nsec;
544 if (nsec < 0) {
545 --sec;
546 nsec += 1000000000;
547 }
548 loadNs = nsec;
549 if (sec > 0 && sec < 4) {
550 loadNs += sec * 1000000000;
551 }
552 } else {
553 // first time through the loop
554 oldLoadValid = true;
555 }
556 oldLoad = newLoad;
557 }
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700558#ifdef CPU_FREQUENCY_STATISTICS
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700559 // get the absolute value of CPU clock frequency in kHz
560 int cpuNum = sched_getcpu();
561 uint32_t kHz = tcu.getCpukHz(cpuNum);
Glenn Kastenc059bd42012-05-14 17:41:09 -0700562 kHz = (kHz << 4) | (cpuNum & 0xF);
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700563#endif
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700564 // save values in FIFO queues for dumpsys
565 // these stores #1, #2, #3 are not atomic with respect to each other,
566 // or with respect to store #4 below
567 dumpState->mMonotonicNs[i] = monotonicNs;
568 dumpState->mLoadNs[i] = loadNs;
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700569#ifdef CPU_FREQUENCY_STATISTICS
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700570 dumpState->mCpukHz[i] = kHz;
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700571#endif
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700572 // this store #4 is not atomic with respect to stores #1, #2, #3 above, but
573 // the newest open and oldest closed halves are atomic with respect to each other
574 dumpState->mBounds = bounds;
Glenn Kasten99c99d02012-05-14 16:37:13 -0700575#if defined(ATRACE_TAG) && (ATRACE_TAG != ATRACE_TAG_NEVER)
576 ATRACE_INT("cycle_ms", monotonicNs / 1000000);
577 ATRACE_INT("load_us", loadNs / 1000);
578#endif
Glenn Kasteneb157162012-06-13 14:59:07 -0700579 }
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700580#endif
581 } else {
582 // first time through the loop
583 oldTsValid = true;
584 sleepNs = periodNs;
585 ignoreNextOverrun = true;
586 }
587 oldTs = newTs;
588 } else {
589 // monotonic clock is broken
590 oldTsValid = false;
591 sleepNs = periodNs;
592 }
593
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700594
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700595 } // for (;;)
596
597 // never return 'true'; Thread::_threadLoop() locks mutex which can result in priority inversion
598}
599
600FastMixerDumpState::FastMixerDumpState() :
601 mCommand(FastMixerState::INITIAL), mWriteSequence(0), mFramesWritten(0),
Glenn Kasten21e8c502012-04-12 09:39:42 -0700602 mNumTracks(0), mWriteErrors(0), mUnderruns(0), mOverruns(0),
Glenn Kasten1295bb4d2012-05-31 07:43:43 -0700603 mSampleRate(0), mFrameCount(0), /* mMeasuredWarmupTs({0, 0}), */ mWarmupCycles(0),
604 mTrackMask(0)
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700605#ifdef FAST_MIXER_STATISTICS
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700606 , mBounds(0)
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700607#endif
608{
Glenn Kasten288ed212012-04-25 17:52:27 -0700609 mMeasuredWarmupTs.tv_sec = 0;
610 mMeasuredWarmupTs.tv_nsec = 0;
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700611 // sample arrays aren't accessed atomically with respect to the bounds,
612 // so clearing reduces chance for dumpsys to read random uninitialized samples
613 memset(&mMonotonicNs, 0, sizeof(mMonotonicNs));
614 memset(&mLoadNs, 0, sizeof(mLoadNs));
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700615#ifdef CPU_FREQUENCY_STATISTICS
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700616 memset(&mCpukHz, 0, sizeof(mCpukHz));
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700617#endif
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700618}
619
620FastMixerDumpState::~FastMixerDumpState()
621{
622}
623
Glenn Kastenba8a6162012-09-07 12:58:38 -0700624// helper function called by qsort()
625static int compare_uint32_t(const void *pa, const void *pb)
626{
627 uint32_t a = *(const uint32_t *)pa;
628 uint32_t b = *(const uint32_t *)pb;
629 if (a < b) {
630 return -1;
631 } else if (a > b) {
632 return 1;
633 } else {
634 return 0;
635 }
636}
637
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700638void FastMixerDumpState::dump(int fd)
639{
Glenn Kasten868c0ab2012-06-13 14:59:17 -0700640 if (mCommand == FastMixerState::INITIAL) {
641 fdprintf(fd, "FastMixer not initialized\n");
642 return;
643 }
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700644#define COMMAND_MAX 32
645 char string[COMMAND_MAX];
646 switch (mCommand) {
647 case FastMixerState::INITIAL:
648 strcpy(string, "INITIAL");
649 break;
650 case FastMixerState::HOT_IDLE:
651 strcpy(string, "HOT_IDLE");
652 break;
653 case FastMixerState::COLD_IDLE:
654 strcpy(string, "COLD_IDLE");
655 break;
656 case FastMixerState::EXIT:
657 strcpy(string, "EXIT");
658 break;
659 case FastMixerState::MIX:
660 strcpy(string, "MIX");
661 break;
662 case FastMixerState::WRITE:
663 strcpy(string, "WRITE");
664 break;
665 case FastMixerState::MIX_WRITE:
666 strcpy(string, "MIX_WRITE");
667 break;
668 default:
669 snprintf(string, COMMAND_MAX, "%d", mCommand);
670 break;
671 }
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700672 double measuredWarmupMs = (mMeasuredWarmupTs.tv_sec * 1000.0) +
Glenn Kasten288ed212012-04-25 17:52:27 -0700673 (mMeasuredWarmupTs.tv_nsec / 1000000.0);
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700674 double mixPeriodSec = (double) mFrameCount / (double) mSampleRate;
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700675 fdprintf(fd, "FastMixer command=%s writeSequence=%u framesWritten=%u\n"
Glenn Kasten21e8c502012-04-12 09:39:42 -0700676 " numTracks=%u writeErrors=%u underruns=%u overruns=%u\n"
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700677 " sampleRate=%u frameCount=%u measuredWarmup=%.3g ms, warmupCycles=%u\n"
678 " mixPeriod=%.2f ms\n",
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700679 string, mWriteSequence, mFramesWritten,
Glenn Kasten21e8c502012-04-12 09:39:42 -0700680 mNumTracks, mWriteErrors, mUnderruns, mOverruns,
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700681 mSampleRate, mFrameCount, measuredWarmupMs, mWarmupCycles,
682 mixPeriodSec * 1e3);
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700683#ifdef FAST_MIXER_STATISTICS
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700684 // find the interval of valid samples
685 uint32_t bounds = mBounds;
686 uint32_t newestOpen = bounds & 0xFFFF;
687 uint32_t oldestClosed = bounds >> 16;
688 uint32_t n = (newestOpen - oldestClosed) & 0xFFFF;
689 if (n > kSamplingN) {
690 ALOGE("too many samples %u", n);
691 n = kSamplingN;
692 }
693 // statistics for monotonic (wall clock) time, thread raw CPU load in time, CPU clock frequency,
694 // and adjusted CPU load in MHz normalized for CPU clock frequency
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700695 CentralTendencyStatistics wall, loadNs;
696#ifdef CPU_FREQUENCY_STATISTICS
697 CentralTendencyStatistics kHz, loadMHz;
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700698 uint32_t previousCpukHz = 0;
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700699#endif
Glenn Kastenba8a6162012-09-07 12:58:38 -0700700 // Assuming a normal distribution for cycle times, three standard deviations on either side of
701 // the mean account for 99.73% of the population. So if we take each tail to be 1/1000 of the
702 // sample set, we get 99.8% combined, or close to three standard deviations.
703 static const uint32_t kTailDenominator = 1000;
704 uint32_t *tail = n >= kTailDenominator ? new uint32_t[n] : NULL;
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700705 // loop over all the samples
Glenn Kastenba8a6162012-09-07 12:58:38 -0700706 for (uint32_t j = 0; j < n; ++j) {
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700707 size_t i = oldestClosed++ & (kSamplingN - 1);
708 uint32_t wallNs = mMonotonicNs[i];
Glenn Kastenba8a6162012-09-07 12:58:38 -0700709 if (tail != NULL) {
710 tail[j] = wallNs;
711 }
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700712 wall.sample(wallNs);
713 uint32_t sampleLoadNs = mLoadNs[i];
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700714 loadNs.sample(sampleLoadNs);
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700715#ifdef CPU_FREQUENCY_STATISTICS
716 uint32_t sampleCpukHz = mCpukHz[i];
Glenn Kastenc059bd42012-05-14 17:41:09 -0700717 // skip bad kHz samples
718 if ((sampleCpukHz & ~0xF) != 0) {
719 kHz.sample(sampleCpukHz >> 4);
720 if (sampleCpukHz == previousCpukHz) {
721 double megacycles = (double) sampleLoadNs * (double) (sampleCpukHz >> 4) * 1e-12;
722 double adjMHz = megacycles / mixPeriodSec; // _not_ wallNs * 1e9
723 loadMHz.sample(adjMHz);
724 }
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700725 }
726 previousCpukHz = sampleCpukHz;
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700727#endif
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700728 }
729 fdprintf(fd, "Simple moving statistics over last %.1f seconds:\n", wall.n() * mixPeriodSec);
730 fdprintf(fd, " wall clock time in ms per mix cycle:\n"
731 " mean=%.2f min=%.2f max=%.2f stddev=%.2f\n",
732 wall.mean()*1e-6, wall.minimum()*1e-6, wall.maximum()*1e-6, wall.stddev()*1e-6);
733 fdprintf(fd, " raw CPU load in us per mix cycle:\n"
734 " mean=%.0f min=%.0f max=%.0f stddev=%.0f\n",
735 loadNs.mean()*1e-3, loadNs.minimum()*1e-3, loadNs.maximum()*1e-3,
736 loadNs.stddev()*1e-3);
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700737#ifdef CPU_FREQUENCY_STATISTICS
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700738 fdprintf(fd, " CPU clock frequency in MHz:\n"
739 " mean=%.0f min=%.0f max=%.0f stddev=%.0f\n",
740 kHz.mean()*1e-3, kHz.minimum()*1e-3, kHz.maximum()*1e-3, kHz.stddev()*1e-3);
741 fdprintf(fd, " adjusted CPU load in MHz (i.e. normalized for CPU clock frequency):\n"
742 " mean=%.1f min=%.1f max=%.1f stddev=%.1f\n",
743 loadMHz.mean(), loadMHz.minimum(), loadMHz.maximum(), loadMHz.stddev());
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700744#endif
Glenn Kastenba8a6162012-09-07 12:58:38 -0700745 if (tail != NULL) {
746 qsort(tail, n, sizeof(uint32_t), compare_uint32_t);
747 // assume same number of tail samples on each side, left and right
748 uint32_t count = n / kTailDenominator;
749 CentralTendencyStatistics left, right;
750 for (uint32_t i = 0; i < count; ++i) {
751 left.sample(tail[i]);
752 right.sample(tail[n - (i + 1)]);
753 }
754 fdprintf(fd, "Distribution of mix cycle times in ms for the tails (> ~3 stddev outliers):\n"
755 " left tail: mean=%.2f min=%.2f max=%.2f stddev=%.2f\n"
756 " right tail: mean=%.2f min=%.2f max=%.2f stddev=%.2f\n",
757 left.mean()*1e-6, left.minimum()*1e-6, left.maximum()*1e-6, left.stddev()*1e-6,
758 right.mean()*1e-6, right.minimum()*1e-6, right.maximum()*1e-6,
759 right.stddev()*1e-6);
760 delete[] tail;
761 }
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700762#endif
Glenn Kasten1295bb4d2012-05-31 07:43:43 -0700763 // The active track mask and track states are updated non-atomically.
764 // So if we relied on isActive to decide whether to display,
765 // then we might display an obsolete track or omit an active track.
766 // Instead we always display all tracks, with an indication
767 // of whether we think the track is active.
768 uint32_t trackMask = mTrackMask;
769 fdprintf(fd, "Fast tracks: kMaxFastTracks=%u activeMask=%#x\n",
770 FastMixerState::kMaxFastTracks, trackMask);
771 fdprintf(fd, "Index Active Full Partial Empty Recent Ready\n");
772 for (uint32_t i = 0; i < FastMixerState::kMaxFastTracks; ++i, trackMask >>= 1) {
773 bool isActive = trackMask & 1;
774 const FastTrackDump *ftDump = &mTracks[i];
775 const FastTrackUnderruns& underruns = ftDump->mUnderruns;
776 const char *mostRecent;
777 switch (underruns.mBitFields.mMostRecent) {
778 case UNDERRUN_FULL:
779 mostRecent = "full";
780 break;
781 case UNDERRUN_PARTIAL:
782 mostRecent = "partial";
783 break;
784 case UNDERRUN_EMPTY:
785 mostRecent = "empty";
786 break;
787 default:
788 mostRecent = "?";
789 break;
790 }
791 fdprintf(fd, "%5u %6s %4u %7u %5u %7s %5u\n", i, isActive ? "yes" : "no",
792 (underruns.mBitFields.mFull) & UNDERRUN_MASK,
793 (underruns.mBitFields.mPartial) & UNDERRUN_MASK,
794 (underruns.mBitFields.mEmpty) & UNDERRUN_MASK,
795 mostRecent, ftDump->mFramesReady);
796 }
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700797}
798
799} // namespace android