blob: 9e9f20d1ad8f5df0c7e71ae0450993d72b1937b6 [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 Kasten153b9fe2013-07-15 11:23:36 -070028#include "Configuration.h"
Glenn Kasten97b5d0d2012-03-23 18:54:19 -070029#include <sys/atomics.h>
30#include <time.h>
31#include <utils/Log.h>
Glenn Kastend8e6fd32012-05-07 11:07:57 -070032#include <utils/Trace.h>
Glenn Kasten97b5d0d2012-03-23 18:54:19 -070033#include <system/audio.h>
34#ifdef FAST_MIXER_STATISTICS
35#include <cpustats/CentralTendencyStatistics.h>
Glenn Kasten0a14c4c2012-06-13 14:58:49 -070036#ifdef CPU_FREQUENCY_STATISTICS
Glenn Kasten42d45cf2012-05-02 10:34:47 -070037#include <cpustats/ThreadCpuUsage.h>
Glenn Kasten97b5d0d2012-03-23 18:54:19 -070038#endif
Glenn Kasten0a14c4c2012-06-13 14:58:49 -070039#endif
Glenn Kasten97b5d0d2012-03-23 18:54:19 -070040#include "AudioMixer.h"
41#include "FastMixer.h"
42
Glenn Kasten7fc97ba2013-07-16 17:18:58 -070043#define FCC_2 2 // fixed channel count assumption
44
Glenn Kasten97b5d0d2012-03-23 18:54:19 -070045namespace android {
46
Glenn Kasten22340022014-04-07 12:04:41 -070047/*static*/ const FastMixerState FastMixer::initial;
48
49FastMixer::FastMixer() : FastThread(),
50 slopNs(0),
51 // fastTrackNames
52 // generations
53 outputSink(NULL),
54 outputSinkGen(0),
55 mixer(NULL),
56 mixBuffer(NULL),
57 mixBufferState(UNDEFINED),
58 format(Format_Invalid),
59 sampleRate(0),
60 fastTracksGen(0),
61 totalNativeFramesWritten(0),
62 // timestamp
63 nativeFramesWrittenButNotPresented(0) // the = 0 is to silence the compiler
Glenn Kasten97b5d0d2012-03-23 18:54:19 -070064{
Glenn Kasten22340022014-04-07 12:04:41 -070065 // FIXME pass initial as parameter to base class constructor, and make it static local
66 previous = &initial;
67 current = &initial;
68
69 mDummyDumpState = &dummyDumpState;
70
Glenn Kasten97b5d0d2012-03-23 18:54:19 -070071 unsigned i;
72 for (i = 0; i < FastMixerState::kMaxFastTracks; ++i) {
73 fastTrackNames[i] = -1;
74 generations[i] = 0;
75 }
Glenn Kasten97b5d0d2012-03-23 18:54:19 -070076#ifdef FAST_MIXER_STATISTICS
Glenn Kasten22340022014-04-07 12:04:41 -070077 oldLoad.tv_sec = 0;
78 oldLoad.tv_nsec = 0;
Glenn Kasten97b5d0d2012-03-23 18:54:19 -070079#endif
Glenn Kasten22340022014-04-07 12:04:41 -070080}
81
82FastMixer::~FastMixer()
83{
84}
85
86FastMixerStateQueue* FastMixer::sq()
87{
88 return &mSQ;
89}
90
91const FastThreadState *FastMixer::poll()
92{
93 return mSQ.poll();
94}
95
96void FastMixer::setLog(NBLog::Writer *logWriter)
97{
98 if (mixer != NULL) {
99 mixer->setLog(logWriter);
100 }
101}
102
103void FastMixer::onIdle()
104{
105 preIdle = *(const FastMixerState *)current;
106 current = &preIdle;
107}
108
109void FastMixer::onExit()
110{
111 delete mixer;
112 delete[] mixBuffer;
113}
114
115bool FastMixer::isSubClassCommand(FastThreadState::Command command)
116{
117 switch ((FastMixerState::Command) command) {
118 case FastMixerState::MIX:
119 case FastMixerState::WRITE:
120 case FastMixerState::MIX_WRITE:
121 return true;
122 default:
123 return false;
124 }
125}
126
127void FastMixer::onStateChange()
128{
129 const FastMixerState * const current = (const FastMixerState *) this->current;
130 const FastMixerState * const previous = (const FastMixerState *) this->previous;
131 FastMixerDumpState * const dumpState = (FastMixerDumpState *) this->dumpState;
132 const size_t frameCount = current->mFrameCount;
133
134 // handle state change here, but since we want to diff the state,
135 // we're prepared for previous == &initial the first time through
136 unsigned previousTrackMask;
137
138 // check for change in output HAL configuration
139 NBAIO_Format previousFormat = format;
140 if (current->mOutputSinkGen != outputSinkGen) {
141 outputSink = current->mOutputSink;
142 outputSinkGen = current->mOutputSinkGen;
143 if (outputSink == NULL) {
144 format = Format_Invalid;
145 sampleRate = 0;
146 } else {
147 format = outputSink->format();
148 sampleRate = Format_sampleRate(format);
149 ALOG_ASSERT(Format_channelCount(format) == FCC_2);
150 }
151 dumpState->mSampleRate = sampleRate;
152 }
153
154 if ((!Format_isEqual(format, previousFormat)) || (frameCount != previous->mFrameCount)) {
155 // FIXME to avoid priority inversion, don't delete here
156 delete mixer;
157 mixer = NULL;
158 delete[] mixBuffer;
159 mixBuffer = NULL;
160 if (frameCount > 0 && sampleRate > 0) {
161 // FIXME new may block for unbounded time at internal mutex of the heap
162 // implementation; it would be better to have normal mixer allocate for us
163 // to avoid blocking here and to prevent possible priority inversion
164 mixer = new AudioMixer(frameCount, sampleRate, FastMixerState::kMaxFastTracks);
165 mixBuffer = new short[frameCount * FCC_2];
166 periodNs = (frameCount * 1000000000LL) / sampleRate; // 1.00
167 underrunNs = (frameCount * 1750000000LL) / sampleRate; // 1.75
168 overrunNs = (frameCount * 500000000LL) / sampleRate; // 0.50
169 forceNs = (frameCount * 950000000LL) / sampleRate; // 0.95
170 warmupNs = (frameCount * 500000000LL) / sampleRate; // 0.50
171 } else {
172 periodNs = 0;
173 underrunNs = 0;
174 overrunNs = 0;
175 forceNs = 0;
176 warmupNs = 0;
177 }
178 mixBufferState = UNDEFINED;
179#if !LOG_NDEBUG
180 for (unsigned i = 0; i < FastMixerState::kMaxFastTracks; ++i) {
181 fastTrackNames[i] = -1;
182 }
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700183#endif
Glenn Kasten22340022014-04-07 12:04:41 -0700184 // we need to reconfigure all active tracks
185 previousTrackMask = 0;
186 fastTracksGen = current->mFastTracksGen - 1;
187 dumpState->mFrameCount = frameCount;
188 } else {
189 previousTrackMask = previous->mTrackMask;
190 }
Glenn Kasten732845c2013-08-23 09:26:31 -0700191
Glenn Kasten22340022014-04-07 12:04:41 -0700192 // check for change in active track set
193 const unsigned currentTrackMask = current->mTrackMask;
194 dumpState->mTrackMask = currentTrackMask;
195 if (current->mFastTracksGen != fastTracksGen) {
196 ALOG_ASSERT(mixBuffer != NULL);
197 int name;
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700198
Glenn Kasten22340022014-04-07 12:04:41 -0700199 // process removed tracks first to avoid running out of track names
200 unsigned removedTracks = previousTrackMask & ~currentTrackMask;
201 while (removedTracks != 0) {
202 int i = __builtin_ctz(removedTracks);
203 removedTracks &= ~(1 << i);
204 const FastTrack* fastTrack = &current->mFastTracks[i];
205 ALOG_ASSERT(fastTrack->mBufferProvider == NULL);
Glenn Kastenab7d72f2013-02-27 09:05:28 -0800206 if (mixer != NULL) {
Glenn Kasten22340022014-04-07 12:04:41 -0700207 name = fastTrackNames[i];
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700208 ALOG_ASSERT(name >= 0);
Glenn Kasten22340022014-04-07 12:04:41 -0700209 mixer->deleteTrackName(name);
210 }
211#if !LOG_NDEBUG
212 fastTrackNames[i] = -1;
213#endif
214 // don't reset track dump state, since other side is ignoring it
215 generations[i] = fastTrack->mGeneration;
216 }
217
218 // now process added tracks
219 unsigned addedTracks = currentTrackMask & ~previousTrackMask;
220 while (addedTracks != 0) {
221 int i = __builtin_ctz(addedTracks);
222 addedTracks &= ~(1 << i);
223 const FastTrack* fastTrack = &current->mFastTracks[i];
224 AudioBufferProvider *bufferProvider = fastTrack->mBufferProvider;
225 ALOG_ASSERT(bufferProvider != NULL && fastTrackNames[i] == -1);
226 if (mixer != NULL) {
Andy Hunge8a1ced2014-05-09 15:02:21 -0700227 name = mixer->getTrackName(fastTrack->mChannelMask,
228 fastTrack->mFormat, AUDIO_SESSION_OUTPUT_MIX);
Glenn Kasten22340022014-04-07 12:04:41 -0700229 ALOG_ASSERT(name >= 0);
230 fastTrackNames[i] = name;
231 mixer->setBufferProvider(name, bufferProvider);
232 mixer->setParameter(name, AudioMixer::TRACK, AudioMixer::MAIN_BUFFER,
233 (void *) mixBuffer);
234 // newly allocated track names default to full scale volume
Glenn Kasten22340022014-04-07 12:04:41 -0700235 mixer->enable(name);
236 }
237 generations[i] = fastTrack->mGeneration;
238 }
239
240 // finally process (potentially) modified tracks; these use the same slot
241 // but may have a different buffer provider or volume provider
242 unsigned modifiedTracks = currentTrackMask & previousTrackMask;
243 while (modifiedTracks != 0) {
244 int i = __builtin_ctz(modifiedTracks);
245 modifiedTracks &= ~(1 << i);
246 const FastTrack* fastTrack = &current->mFastTracks[i];
247 if (fastTrack->mGeneration != generations[i]) {
248 // this track was actually modified
249 AudioBufferProvider *bufferProvider = fastTrack->mBufferProvider;
250 ALOG_ASSERT(bufferProvider != NULL);
251 if (mixer != NULL) {
252 name = fastTrackNames[i];
253 ALOG_ASSERT(name >= 0);
254 mixer->setBufferProvider(name, bufferProvider);
255 if (fastTrack->mVolumeProvider == NULL) {
256 mixer->setParameter(name, AudioMixer::VOLUME, AudioMixer::VOLUME0,
257 (void *)0x1000);
258 mixer->setParameter(name, AudioMixer::VOLUME, AudioMixer::VOLUME1,
259 (void *)0x1000);
Glenn Kasten288ed212012-04-25 17:52:27 -0700260 }
Glenn Kasten22340022014-04-07 12:04:41 -0700261 mixer->setParameter(name, AudioMixer::RESAMPLE,
262 AudioMixer::REMOVE, NULL);
263 mixer->setParameter(name, AudioMixer::TRACK, AudioMixer::CHANNEL_MASK,
264 (void *)(uintptr_t) fastTrack->mChannelMask);
265 // already enabled
266 }
267 generations[i] = fastTrack->mGeneration;
268 }
269 }
270
271 fastTracksGen = current->mFastTracksGen;
272
273 dumpState->mNumTracks = popcount(currentTrackMask);
274 }
275}
276
277void FastMixer::onWork()
278{
279 const FastMixerState * const current = (const FastMixerState *) this->current;
280 FastMixerDumpState * const dumpState = (FastMixerDumpState *) this->dumpState;
281 const FastMixerState::Command command = this->command;
282 const size_t frameCount = current->mFrameCount;
283
284 if ((command & FastMixerState::MIX) && (mixer != NULL) && isWarm) {
285 ALOG_ASSERT(mixBuffer != NULL);
286 // for each track, update volume and check for underrun
287 unsigned currentTrackMask = current->mTrackMask;
288 while (currentTrackMask != 0) {
289 int i = __builtin_ctz(currentTrackMask);
290 currentTrackMask &= ~(1 << i);
291 const FastTrack* fastTrack = &current->mFastTracks[i];
292
293 // Refresh the per-track timestamp
294 if (timestampStatus == NO_ERROR) {
295 uint32_t trackFramesWrittenButNotPresented =
296 nativeFramesWrittenButNotPresented;
297 uint32_t trackFramesWritten = fastTrack->mBufferProvider->framesReleased();
298 // Can't provide an AudioTimestamp before first frame presented,
299 // or during the brief 32-bit wraparound window
300 if (trackFramesWritten >= trackFramesWrittenButNotPresented) {
301 AudioTimestamp perTrackTimestamp;
302 perTrackTimestamp.mPosition =
303 trackFramesWritten - trackFramesWrittenButNotPresented;
304 perTrackTimestamp.mTime = timestamp.mTime;
305 fastTrack->mBufferProvider->onTimestamp(perTrackTimestamp);
306 }
307 }
308
309 int name = fastTrackNames[i];
310 ALOG_ASSERT(name >= 0);
311 if (fastTrack->mVolumeProvider != NULL) {
312 uint32_t vlr = fastTrack->mVolumeProvider->getVolumeLR();
313 mixer->setParameter(name, AudioMixer::VOLUME, AudioMixer::VOLUME0,
314 (void *)(uintptr_t)(vlr & 0xFFFF));
315 mixer->setParameter(name, AudioMixer::VOLUME, AudioMixer::VOLUME1,
316 (void *)(uintptr_t)(vlr >> 16));
317 }
318 // FIXME The current implementation of framesReady() for fast tracks
319 // takes a tryLock, which can block
320 // up to 1 ms. If enough active tracks all blocked in sequence, this would result
321 // in the overall fast mix cycle being delayed. Should use a non-blocking FIFO.
322 size_t framesReady = fastTrack->mBufferProvider->framesReady();
323 if (ATRACE_ENABLED()) {
324 // I wish we had formatted trace names
325 char traceName[16];
326 strcpy(traceName, "fRdy");
327 traceName[4] = i + (i < 10 ? '0' : 'A' - 10);
328 traceName[5] = '\0';
329 ATRACE_INT(traceName, framesReady);
330 }
331 FastTrackDump *ftDump = &dumpState->mTracks[i];
332 FastTrackUnderruns underruns = ftDump->mUnderruns;
333 if (framesReady < frameCount) {
334 if (framesReady == 0) {
335 underruns.mBitFields.mEmpty++;
336 underruns.mBitFields.mMostRecent = UNDERRUN_EMPTY;
337 mixer->disable(name);
Glenn Kasten09474df2012-05-10 14:48:07 -0700338 } else {
Glenn Kasten22340022014-04-07 12:04:41 -0700339 // allow mixing partial buffer
340 underruns.mBitFields.mPartial++;
341 underruns.mBitFields.mMostRecent = UNDERRUN_PARTIAL;
Glenn Kasten288ed212012-04-25 17:52:27 -0700342 mixer->enable(name);
343 }
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700344 } else {
Glenn Kasten22340022014-04-07 12:04:41 -0700345 underruns.mBitFields.mFull++;
346 underruns.mBitFields.mMostRecent = UNDERRUN_FULL;
347 mixer->enable(name);
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700348 }
Glenn Kasten22340022014-04-07 12:04:41 -0700349 ftDump->mUnderruns = underruns;
350 ftDump->mFramesReady = framesReady;
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700351 }
352
Glenn Kasten22340022014-04-07 12:04:41 -0700353 int64_t pts;
354 if (outputSink == NULL || (OK != outputSink->getNextWriteTimestamp(&pts))) {
355 pts = AudioBufferProvider::kInvalidPTS;
356 }
357
358 // process() is CPU-bound
359 mixer->process(pts);
360 mixBufferState = MIXED;
361 } else if (mixBufferState == MIXED) {
362 mixBufferState = UNDEFINED;
363 }
364 //bool didFullWrite = false; // dumpsys could display a count of partial writes
365 if ((command & FastMixerState::WRITE) && (outputSink != NULL) && (mixBuffer != NULL)) {
366 if (mixBufferState == UNDEFINED) {
367 memset(mixBuffer, 0, frameCount * FCC_2 * sizeof(short));
368 mixBufferState = ZEROED;
369 }
370 // if non-NULL, then duplicate write() to this non-blocking sink
371 NBAIO_Sink* teeSink;
372 if ((teeSink = current->mTeeSink) != NULL) {
373 (void) teeSink->write(mixBuffer, frameCount);
374 }
375 // FIXME write() is non-blocking and lock-free for a properly implemented NBAIO sink,
376 // but this code should be modified to handle both non-blocking and blocking sinks
377 dumpState->mWriteSequence++;
378 ATRACE_BEGIN("write");
379 ssize_t framesWritten = outputSink->write(mixBuffer, frameCount);
380 ATRACE_END();
381 dumpState->mWriteSequence++;
382 if (framesWritten >= 0) {
383 ALOG_ASSERT((size_t) framesWritten <= frameCount);
384 totalNativeFramesWritten += framesWritten;
385 dumpState->mFramesWritten = totalNativeFramesWritten;
386 //if ((size_t) framesWritten == frameCount) {
387 // didFullWrite = true;
388 //}
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700389 } else {
Glenn Kasten22340022014-04-07 12:04:41 -0700390 dumpState->mWriteErrors++;
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700391 }
Glenn Kasten22340022014-04-07 12:04:41 -0700392 attemptedWrite = true;
393 // FIXME count # of writes blocked excessively, CPU usage, etc. for dump
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700394
Glenn Kasten22340022014-04-07 12:04:41 -0700395 timestampStatus = outputSink->getTimestamp(timestamp);
396 if (timestampStatus == NO_ERROR) {
397 uint32_t totalNativeFramesPresented = timestamp.mPosition;
398 if (totalNativeFramesPresented <= totalNativeFramesWritten) {
399 nativeFramesWrittenButNotPresented =
400 totalNativeFramesWritten - totalNativeFramesPresented;
401 } else {
402 // HAL reported that more frames were presented than were written
403 timestampStatus = INVALID_OPERATION;
404 }
405 }
406 }
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700407}
408
Glenn Kasten4182c4e2013-07-15 14:45:07 -0700409FastMixerDumpState::FastMixerDumpState(
410#ifdef FAST_MIXER_STATISTICS
411 uint32_t samplingN
412#endif
Glenn Kasten22340022014-04-07 12:04:41 -0700413 ) : FastThreadDumpState(),
414 mWriteSequence(0), mFramesWritten(0),
415 mNumTracks(0), mWriteErrors(0),
416 mSampleRate(0), mFrameCount(0),
Glenn Kasten1295bb4d2012-05-31 07:43:43 -0700417 mTrackMask(0)
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700418{
Glenn Kasten153b9fe2013-07-15 11:23:36 -0700419#ifdef FAST_MIXER_STATISTICS
Glenn Kasten4182c4e2013-07-15 14:45:07 -0700420 increaseSamplingN(samplingN);
Glenn Kasten153b9fe2013-07-15 11:23:36 -0700421#endif
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700422}
423
Glenn Kasten4182c4e2013-07-15 14:45:07 -0700424#ifdef FAST_MIXER_STATISTICS
425void FastMixerDumpState::increaseSamplingN(uint32_t samplingN)
426{
427 if (samplingN <= mSamplingN || samplingN > kSamplingN || roundup(samplingN) != samplingN) {
428 return;
429 }
430 uint32_t additional = samplingN - mSamplingN;
431 // sample arrays aren't accessed atomically with respect to the bounds,
432 // so clearing reduces chance for dumpsys to read random uninitialized samples
433 memset(&mMonotonicNs[mSamplingN], 0, sizeof(mMonotonicNs[0]) * additional);
434 memset(&mLoadNs[mSamplingN], 0, sizeof(mLoadNs[0]) * additional);
435#ifdef CPU_FREQUENCY_STATISTICS
436 memset(&mCpukHz[mSamplingN], 0, sizeof(mCpukHz[0]) * additional);
437#endif
438 mSamplingN = samplingN;
439}
440#endif
441
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700442FastMixerDumpState::~FastMixerDumpState()
443{
444}
445
Glenn Kasten1ab212cf2012-09-07 12:58:38 -0700446// helper function called by qsort()
447static int compare_uint32_t(const void *pa, const void *pb)
448{
449 uint32_t a = *(const uint32_t *)pa;
450 uint32_t b = *(const uint32_t *)pb;
451 if (a < b) {
452 return -1;
453 } else if (a > b) {
454 return 1;
455 } else {
456 return 0;
457 }
458}
459
Glenn Kasten4182c4e2013-07-15 14:45:07 -0700460void FastMixerDumpState::dump(int fd) const
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700461{
Glenn Kasten868c0ab2012-06-13 14:59:17 -0700462 if (mCommand == FastMixerState::INITIAL) {
Marco Nelissenb2208842014-02-07 14:00:50 -0800463 fdprintf(fd, " FastMixer not initialized\n");
Glenn Kasten868c0ab2012-06-13 14:59:17 -0700464 return;
465 }
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700466#define COMMAND_MAX 32
467 char string[COMMAND_MAX];
468 switch (mCommand) {
469 case FastMixerState::INITIAL:
470 strcpy(string, "INITIAL");
471 break;
472 case FastMixerState::HOT_IDLE:
473 strcpy(string, "HOT_IDLE");
474 break;
475 case FastMixerState::COLD_IDLE:
476 strcpy(string, "COLD_IDLE");
477 break;
478 case FastMixerState::EXIT:
479 strcpy(string, "EXIT");
480 break;
481 case FastMixerState::MIX:
482 strcpy(string, "MIX");
483 break;
484 case FastMixerState::WRITE:
485 strcpy(string, "WRITE");
486 break;
487 case FastMixerState::MIX_WRITE:
488 strcpy(string, "MIX_WRITE");
489 break;
490 default:
491 snprintf(string, COMMAND_MAX, "%d", mCommand);
492 break;
493 }
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700494 double measuredWarmupMs = (mMeasuredWarmupTs.tv_sec * 1000.0) +
Glenn Kasten288ed212012-04-25 17:52:27 -0700495 (mMeasuredWarmupTs.tv_nsec / 1000000.0);
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700496 double mixPeriodSec = (double) mFrameCount / (double) mSampleRate;
Marco Nelissenb2208842014-02-07 14:00:50 -0800497 fdprintf(fd, " FastMixer command=%s writeSequence=%u framesWritten=%u\n"
498 " numTracks=%u writeErrors=%u underruns=%u overruns=%u\n"
Narayan Kamath1d6fa7a2014-02-11 13:47:53 +0000499 " sampleRate=%u frameCount=%zu measuredWarmup=%.3g ms, warmupCycles=%u\n"
Marco Nelissenb2208842014-02-07 14:00:50 -0800500 " mixPeriod=%.2f ms\n",
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700501 string, mWriteSequence, mFramesWritten,
Glenn Kasten21e8c502012-04-12 09:39:42 -0700502 mNumTracks, mWriteErrors, mUnderruns, mOverruns,
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700503 mSampleRate, mFrameCount, measuredWarmupMs, mWarmupCycles,
504 mixPeriodSec * 1e3);
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700505#ifdef FAST_MIXER_STATISTICS
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700506 // find the interval of valid samples
507 uint32_t bounds = mBounds;
508 uint32_t newestOpen = bounds & 0xFFFF;
509 uint32_t oldestClosed = bounds >> 16;
510 uint32_t n = (newestOpen - oldestClosed) & 0xFFFF;
Glenn Kasten4182c4e2013-07-15 14:45:07 -0700511 if (n > mSamplingN) {
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700512 ALOGE("too many samples %u", n);
Glenn Kasten4182c4e2013-07-15 14:45:07 -0700513 n = mSamplingN;
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700514 }
515 // statistics for monotonic (wall clock) time, thread raw CPU load in time, CPU clock frequency,
516 // and adjusted CPU load in MHz normalized for CPU clock frequency
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700517 CentralTendencyStatistics wall, loadNs;
518#ifdef CPU_FREQUENCY_STATISTICS
519 CentralTendencyStatistics kHz, loadMHz;
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700520 uint32_t previousCpukHz = 0;
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700521#endif
Glenn Kasten1ab212cf2012-09-07 12:58:38 -0700522 // Assuming a normal distribution for cycle times, three standard deviations on either side of
523 // the mean account for 99.73% of the population. So if we take each tail to be 1/1000 of the
524 // sample set, we get 99.8% combined, or close to three standard deviations.
525 static const uint32_t kTailDenominator = 1000;
526 uint32_t *tail = n >= kTailDenominator ? new uint32_t[n] : NULL;
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700527 // loop over all the samples
Glenn Kasten1ab212cf2012-09-07 12:58:38 -0700528 for (uint32_t j = 0; j < n; ++j) {
Glenn Kasten4182c4e2013-07-15 14:45:07 -0700529 size_t i = oldestClosed++ & (mSamplingN - 1);
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700530 uint32_t wallNs = mMonotonicNs[i];
Glenn Kasten1ab212cf2012-09-07 12:58:38 -0700531 if (tail != NULL) {
532 tail[j] = wallNs;
533 }
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700534 wall.sample(wallNs);
535 uint32_t sampleLoadNs = mLoadNs[i];
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700536 loadNs.sample(sampleLoadNs);
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700537#ifdef CPU_FREQUENCY_STATISTICS
538 uint32_t sampleCpukHz = mCpukHz[i];
Glenn Kastenc059bd42012-05-14 17:41:09 -0700539 // skip bad kHz samples
540 if ((sampleCpukHz & ~0xF) != 0) {
541 kHz.sample(sampleCpukHz >> 4);
542 if (sampleCpukHz == previousCpukHz) {
543 double megacycles = (double) sampleLoadNs * (double) (sampleCpukHz >> 4) * 1e-12;
544 double adjMHz = megacycles / mixPeriodSec; // _not_ wallNs * 1e9
545 loadMHz.sample(adjMHz);
546 }
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700547 }
548 previousCpukHz = sampleCpukHz;
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700549#endif
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700550 }
Marco Nelissenb2208842014-02-07 14:00:50 -0800551 if (n) {
552 fdprintf(fd, " Simple moving statistics over last %.1f seconds:\n",
553 wall.n() * mixPeriodSec);
554 fdprintf(fd, " wall clock time in ms per mix cycle:\n"
555 " mean=%.2f min=%.2f max=%.2f stddev=%.2f\n",
556 wall.mean()*1e-6, wall.minimum()*1e-6, wall.maximum()*1e-6,
557 wall.stddev()*1e-6);
558 fdprintf(fd, " raw CPU load in us per mix cycle:\n"
559 " mean=%.0f min=%.0f max=%.0f stddev=%.0f\n",
560 loadNs.mean()*1e-3, loadNs.minimum()*1e-3, loadNs.maximum()*1e-3,
561 loadNs.stddev()*1e-3);
562 } else {
563 fdprintf(fd, " No FastMixer statistics available currently\n");
564 }
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700565#ifdef CPU_FREQUENCY_STATISTICS
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700566 fdprintf(fd, " CPU clock frequency in MHz:\n"
567 " mean=%.0f min=%.0f max=%.0f stddev=%.0f\n",
568 kHz.mean()*1e-3, kHz.minimum()*1e-3, kHz.maximum()*1e-3, kHz.stddev()*1e-3);
569 fdprintf(fd, " adjusted CPU load in MHz (i.e. normalized for CPU clock frequency):\n"
570 " mean=%.1f min=%.1f max=%.1f stddev=%.1f\n",
571 loadMHz.mean(), loadMHz.minimum(), loadMHz.maximum(), loadMHz.stddev());
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700572#endif
Glenn Kasten1ab212cf2012-09-07 12:58:38 -0700573 if (tail != NULL) {
574 qsort(tail, n, sizeof(uint32_t), compare_uint32_t);
575 // assume same number of tail samples on each side, left and right
576 uint32_t count = n / kTailDenominator;
577 CentralTendencyStatistics left, right;
578 for (uint32_t i = 0; i < count; ++i) {
579 left.sample(tail[i]);
580 right.sample(tail[n - (i + 1)]);
581 }
Marco Nelissenb2208842014-02-07 14:00:50 -0800582 fdprintf(fd, " Distribution of mix cycle times in ms for the tails (> ~3 stddev outliers):\n"
583 " left tail: mean=%.2f min=%.2f max=%.2f stddev=%.2f\n"
584 " right tail: mean=%.2f min=%.2f max=%.2f stddev=%.2f\n",
Glenn Kasten1ab212cf2012-09-07 12:58:38 -0700585 left.mean()*1e-6, left.minimum()*1e-6, left.maximum()*1e-6, left.stddev()*1e-6,
586 right.mean()*1e-6, right.minimum()*1e-6, right.maximum()*1e-6,
587 right.stddev()*1e-6);
588 delete[] tail;
589 }
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700590#endif
Glenn Kasten1295bb4d2012-05-31 07:43:43 -0700591 // The active track mask and track states are updated non-atomically.
592 // So if we relied on isActive to decide whether to display,
593 // then we might display an obsolete track or omit an active track.
594 // Instead we always display all tracks, with an indication
595 // of whether we think the track is active.
596 uint32_t trackMask = mTrackMask;
Marco Nelissenb2208842014-02-07 14:00:50 -0800597 fdprintf(fd, " Fast tracks: kMaxFastTracks=%u activeMask=%#x\n",
Glenn Kasten1295bb4d2012-05-31 07:43:43 -0700598 FastMixerState::kMaxFastTracks, trackMask);
Marco Nelissenb2208842014-02-07 14:00:50 -0800599 fdprintf(fd, " Index Active Full Partial Empty Recent Ready\n");
Glenn Kasten1295bb4d2012-05-31 07:43:43 -0700600 for (uint32_t i = 0; i < FastMixerState::kMaxFastTracks; ++i, trackMask >>= 1) {
601 bool isActive = trackMask & 1;
602 const FastTrackDump *ftDump = &mTracks[i];
603 const FastTrackUnderruns& underruns = ftDump->mUnderruns;
604 const char *mostRecent;
605 switch (underruns.mBitFields.mMostRecent) {
606 case UNDERRUN_FULL:
607 mostRecent = "full";
608 break;
609 case UNDERRUN_PARTIAL:
610 mostRecent = "partial";
611 break;
612 case UNDERRUN_EMPTY:
613 mostRecent = "empty";
614 break;
615 default:
616 mostRecent = "?";
617 break;
618 }
Narayan Kamath1d6fa7a2014-02-11 13:47:53 +0000619 fdprintf(fd, " %5u %6s %4u %7u %5u %7s %5zu\n", i, isActive ? "yes" : "no",
Glenn Kasten1295bb4d2012-05-31 07:43:43 -0700620 (underruns.mBitFields.mFull) & UNDERRUN_MASK,
621 (underruns.mBitFields.mPartial) & UNDERRUN_MASK,
622 (underruns.mBitFields.mEmpty) & UNDERRUN_MASK,
623 mostRecent, ftDump->mFramesReady);
624 }
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700625}
626
627} // namespace android