blob: 5cb42cc33f21b1debc4c27efe5cb5f91ad8e4cd5 [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) {
227 // calling getTrackName with default channel mask and a random invalid
228 // sessionId (no effects here)
229 name = mixer->getTrackName(AUDIO_CHANNEL_OUT_STEREO, -555);
230 ALOG_ASSERT(name >= 0);
231 fastTrackNames[i] = name;
232 mixer->setBufferProvider(name, bufferProvider);
233 mixer->setParameter(name, AudioMixer::TRACK, AudioMixer::MAIN_BUFFER,
234 (void *) mixBuffer);
235 // newly allocated track names default to full scale volume
236 mixer->setParameter(name, AudioMixer::TRACK, AudioMixer::CHANNEL_MASK,
237 (void *)(uintptr_t)fastTrack->mChannelMask);
238 mixer->enable(name);
239 }
240 generations[i] = fastTrack->mGeneration;
241 }
242
243 // finally process (potentially) modified tracks; these use the same slot
244 // but may have a different buffer provider or volume provider
245 unsigned modifiedTracks = currentTrackMask & previousTrackMask;
246 while (modifiedTracks != 0) {
247 int i = __builtin_ctz(modifiedTracks);
248 modifiedTracks &= ~(1 << i);
249 const FastTrack* fastTrack = &current->mFastTracks[i];
250 if (fastTrack->mGeneration != generations[i]) {
251 // this track was actually modified
252 AudioBufferProvider *bufferProvider = fastTrack->mBufferProvider;
253 ALOG_ASSERT(bufferProvider != NULL);
254 if (mixer != NULL) {
255 name = fastTrackNames[i];
256 ALOG_ASSERT(name >= 0);
257 mixer->setBufferProvider(name, bufferProvider);
258 if (fastTrack->mVolumeProvider == NULL) {
259 mixer->setParameter(name, AudioMixer::VOLUME, AudioMixer::VOLUME0,
260 (void *)0x1000);
261 mixer->setParameter(name, AudioMixer::VOLUME, AudioMixer::VOLUME1,
262 (void *)0x1000);
Glenn Kasten288ed212012-04-25 17:52:27 -0700263 }
Glenn Kasten22340022014-04-07 12:04:41 -0700264 mixer->setParameter(name, AudioMixer::RESAMPLE,
265 AudioMixer::REMOVE, NULL);
266 mixer->setParameter(name, AudioMixer::TRACK, AudioMixer::CHANNEL_MASK,
267 (void *)(uintptr_t) fastTrack->mChannelMask);
268 // already enabled
269 }
270 generations[i] = fastTrack->mGeneration;
271 }
272 }
273
274 fastTracksGen = current->mFastTracksGen;
275
276 dumpState->mNumTracks = popcount(currentTrackMask);
277 }
278}
279
280void FastMixer::onWork()
281{
282 const FastMixerState * const current = (const FastMixerState *) this->current;
283 FastMixerDumpState * const dumpState = (FastMixerDumpState *) this->dumpState;
284 const FastMixerState::Command command = this->command;
285 const size_t frameCount = current->mFrameCount;
286
287 if ((command & FastMixerState::MIX) && (mixer != NULL) && isWarm) {
288 ALOG_ASSERT(mixBuffer != NULL);
289 // for each track, update volume and check for underrun
290 unsigned currentTrackMask = current->mTrackMask;
291 while (currentTrackMask != 0) {
292 int i = __builtin_ctz(currentTrackMask);
293 currentTrackMask &= ~(1 << i);
294 const FastTrack* fastTrack = &current->mFastTracks[i];
295
296 // Refresh the per-track timestamp
297 if (timestampStatus == NO_ERROR) {
298 uint32_t trackFramesWrittenButNotPresented =
299 nativeFramesWrittenButNotPresented;
300 uint32_t trackFramesWritten = fastTrack->mBufferProvider->framesReleased();
301 // Can't provide an AudioTimestamp before first frame presented,
302 // or during the brief 32-bit wraparound window
303 if (trackFramesWritten >= trackFramesWrittenButNotPresented) {
304 AudioTimestamp perTrackTimestamp;
305 perTrackTimestamp.mPosition =
306 trackFramesWritten - trackFramesWrittenButNotPresented;
307 perTrackTimestamp.mTime = timestamp.mTime;
308 fastTrack->mBufferProvider->onTimestamp(perTrackTimestamp);
309 }
310 }
311
312 int name = fastTrackNames[i];
313 ALOG_ASSERT(name >= 0);
314 if (fastTrack->mVolumeProvider != NULL) {
315 uint32_t vlr = fastTrack->mVolumeProvider->getVolumeLR();
316 mixer->setParameter(name, AudioMixer::VOLUME, AudioMixer::VOLUME0,
317 (void *)(uintptr_t)(vlr & 0xFFFF));
318 mixer->setParameter(name, AudioMixer::VOLUME, AudioMixer::VOLUME1,
319 (void *)(uintptr_t)(vlr >> 16));
320 }
321 // FIXME The current implementation of framesReady() for fast tracks
322 // takes a tryLock, which can block
323 // up to 1 ms. If enough active tracks all blocked in sequence, this would result
324 // in the overall fast mix cycle being delayed. Should use a non-blocking FIFO.
325 size_t framesReady = fastTrack->mBufferProvider->framesReady();
326 if (ATRACE_ENABLED()) {
327 // I wish we had formatted trace names
328 char traceName[16];
329 strcpy(traceName, "fRdy");
330 traceName[4] = i + (i < 10 ? '0' : 'A' - 10);
331 traceName[5] = '\0';
332 ATRACE_INT(traceName, framesReady);
333 }
334 FastTrackDump *ftDump = &dumpState->mTracks[i];
335 FastTrackUnderruns underruns = ftDump->mUnderruns;
336 if (framesReady < frameCount) {
337 if (framesReady == 0) {
338 underruns.mBitFields.mEmpty++;
339 underruns.mBitFields.mMostRecent = UNDERRUN_EMPTY;
340 mixer->disable(name);
Glenn Kasten09474df2012-05-10 14:48:07 -0700341 } else {
Glenn Kasten22340022014-04-07 12:04:41 -0700342 // allow mixing partial buffer
343 underruns.mBitFields.mPartial++;
344 underruns.mBitFields.mMostRecent = UNDERRUN_PARTIAL;
Glenn Kasten288ed212012-04-25 17:52:27 -0700345 mixer->enable(name);
346 }
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700347 } else {
Glenn Kasten22340022014-04-07 12:04:41 -0700348 underruns.mBitFields.mFull++;
349 underruns.mBitFields.mMostRecent = UNDERRUN_FULL;
350 mixer->enable(name);
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700351 }
Glenn Kasten22340022014-04-07 12:04:41 -0700352 ftDump->mUnderruns = underruns;
353 ftDump->mFramesReady = framesReady;
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700354 }
355
Glenn Kasten22340022014-04-07 12:04:41 -0700356 int64_t pts;
357 if (outputSink == NULL || (OK != outputSink->getNextWriteTimestamp(&pts))) {
358 pts = AudioBufferProvider::kInvalidPTS;
359 }
360
361 // process() is CPU-bound
362 mixer->process(pts);
363 mixBufferState = MIXED;
364 } else if (mixBufferState == MIXED) {
365 mixBufferState = UNDEFINED;
366 }
367 //bool didFullWrite = false; // dumpsys could display a count of partial writes
368 if ((command & FastMixerState::WRITE) && (outputSink != NULL) && (mixBuffer != NULL)) {
369 if (mixBufferState == UNDEFINED) {
370 memset(mixBuffer, 0, frameCount * FCC_2 * sizeof(short));
371 mixBufferState = ZEROED;
372 }
373 // if non-NULL, then duplicate write() to this non-blocking sink
374 NBAIO_Sink* teeSink;
375 if ((teeSink = current->mTeeSink) != NULL) {
376 (void) teeSink->write(mixBuffer, frameCount);
377 }
378 // FIXME write() is non-blocking and lock-free for a properly implemented NBAIO sink,
379 // but this code should be modified to handle both non-blocking and blocking sinks
380 dumpState->mWriteSequence++;
381 ATRACE_BEGIN("write");
382 ssize_t framesWritten = outputSink->write(mixBuffer, frameCount);
383 ATRACE_END();
384 dumpState->mWriteSequence++;
385 if (framesWritten >= 0) {
386 ALOG_ASSERT((size_t) framesWritten <= frameCount);
387 totalNativeFramesWritten += framesWritten;
388 dumpState->mFramesWritten = totalNativeFramesWritten;
389 //if ((size_t) framesWritten == frameCount) {
390 // didFullWrite = true;
391 //}
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700392 } else {
Glenn Kasten22340022014-04-07 12:04:41 -0700393 dumpState->mWriteErrors++;
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700394 }
Glenn Kasten22340022014-04-07 12:04:41 -0700395 attemptedWrite = true;
396 // FIXME count # of writes blocked excessively, CPU usage, etc. for dump
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700397
Glenn Kasten22340022014-04-07 12:04:41 -0700398 timestampStatus = outputSink->getTimestamp(timestamp);
399 if (timestampStatus == NO_ERROR) {
400 uint32_t totalNativeFramesPresented = timestamp.mPosition;
401 if (totalNativeFramesPresented <= totalNativeFramesWritten) {
402 nativeFramesWrittenButNotPresented =
403 totalNativeFramesWritten - totalNativeFramesPresented;
404 } else {
405 // HAL reported that more frames were presented than were written
406 timestampStatus = INVALID_OPERATION;
407 }
408 }
409 }
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700410}
411
Glenn Kasten4182c4e2013-07-15 14:45:07 -0700412FastMixerDumpState::FastMixerDumpState(
413#ifdef FAST_MIXER_STATISTICS
414 uint32_t samplingN
415#endif
Glenn Kasten22340022014-04-07 12:04:41 -0700416 ) : FastThreadDumpState(),
417 mWriteSequence(0), mFramesWritten(0),
418 mNumTracks(0), mWriteErrors(0),
419 mSampleRate(0), mFrameCount(0),
Glenn Kasten1295bb4d2012-05-31 07:43:43 -0700420 mTrackMask(0)
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700421{
Glenn Kasten153b9fe2013-07-15 11:23:36 -0700422#ifdef FAST_MIXER_STATISTICS
Glenn Kasten4182c4e2013-07-15 14:45:07 -0700423 increaseSamplingN(samplingN);
Glenn Kasten153b9fe2013-07-15 11:23:36 -0700424#endif
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700425}
426
Glenn Kasten4182c4e2013-07-15 14:45:07 -0700427#ifdef FAST_MIXER_STATISTICS
428void FastMixerDumpState::increaseSamplingN(uint32_t samplingN)
429{
430 if (samplingN <= mSamplingN || samplingN > kSamplingN || roundup(samplingN) != samplingN) {
431 return;
432 }
433 uint32_t additional = samplingN - mSamplingN;
434 // sample arrays aren't accessed atomically with respect to the bounds,
435 // so clearing reduces chance for dumpsys to read random uninitialized samples
436 memset(&mMonotonicNs[mSamplingN], 0, sizeof(mMonotonicNs[0]) * additional);
437 memset(&mLoadNs[mSamplingN], 0, sizeof(mLoadNs[0]) * additional);
438#ifdef CPU_FREQUENCY_STATISTICS
439 memset(&mCpukHz[mSamplingN], 0, sizeof(mCpukHz[0]) * additional);
440#endif
441 mSamplingN = samplingN;
442}
443#endif
444
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700445FastMixerDumpState::~FastMixerDumpState()
446{
447}
448
Glenn Kasten1ab212cf2012-09-07 12:58:38 -0700449// helper function called by qsort()
450static int compare_uint32_t(const void *pa, const void *pb)
451{
452 uint32_t a = *(const uint32_t *)pa;
453 uint32_t b = *(const uint32_t *)pb;
454 if (a < b) {
455 return -1;
456 } else if (a > b) {
457 return 1;
458 } else {
459 return 0;
460 }
461}
462
Glenn Kasten4182c4e2013-07-15 14:45:07 -0700463void FastMixerDumpState::dump(int fd) const
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700464{
Glenn Kasten868c0ab2012-06-13 14:59:17 -0700465 if (mCommand == FastMixerState::INITIAL) {
Marco Nelissenb2208842014-02-07 14:00:50 -0800466 fdprintf(fd, " FastMixer not initialized\n");
Glenn Kasten868c0ab2012-06-13 14:59:17 -0700467 return;
468 }
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700469#define COMMAND_MAX 32
470 char string[COMMAND_MAX];
471 switch (mCommand) {
472 case FastMixerState::INITIAL:
473 strcpy(string, "INITIAL");
474 break;
475 case FastMixerState::HOT_IDLE:
476 strcpy(string, "HOT_IDLE");
477 break;
478 case FastMixerState::COLD_IDLE:
479 strcpy(string, "COLD_IDLE");
480 break;
481 case FastMixerState::EXIT:
482 strcpy(string, "EXIT");
483 break;
484 case FastMixerState::MIX:
485 strcpy(string, "MIX");
486 break;
487 case FastMixerState::WRITE:
488 strcpy(string, "WRITE");
489 break;
490 case FastMixerState::MIX_WRITE:
491 strcpy(string, "MIX_WRITE");
492 break;
493 default:
494 snprintf(string, COMMAND_MAX, "%d", mCommand);
495 break;
496 }
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700497 double measuredWarmupMs = (mMeasuredWarmupTs.tv_sec * 1000.0) +
Glenn Kasten288ed212012-04-25 17:52:27 -0700498 (mMeasuredWarmupTs.tv_nsec / 1000000.0);
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700499 double mixPeriodSec = (double) mFrameCount / (double) mSampleRate;
Marco Nelissenb2208842014-02-07 14:00:50 -0800500 fdprintf(fd, " FastMixer command=%s writeSequence=%u framesWritten=%u\n"
501 " numTracks=%u writeErrors=%u underruns=%u overruns=%u\n"
Narayan Kamath1d6fa7a2014-02-11 13:47:53 +0000502 " sampleRate=%u frameCount=%zu measuredWarmup=%.3g ms, warmupCycles=%u\n"
Marco Nelissenb2208842014-02-07 14:00:50 -0800503 " mixPeriod=%.2f ms\n",
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700504 string, mWriteSequence, mFramesWritten,
Glenn Kasten21e8c502012-04-12 09:39:42 -0700505 mNumTracks, mWriteErrors, mUnderruns, mOverruns,
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700506 mSampleRate, mFrameCount, measuredWarmupMs, mWarmupCycles,
507 mixPeriodSec * 1e3);
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700508#ifdef FAST_MIXER_STATISTICS
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700509 // find the interval of valid samples
510 uint32_t bounds = mBounds;
511 uint32_t newestOpen = bounds & 0xFFFF;
512 uint32_t oldestClosed = bounds >> 16;
513 uint32_t n = (newestOpen - oldestClosed) & 0xFFFF;
Glenn Kasten4182c4e2013-07-15 14:45:07 -0700514 if (n > mSamplingN) {
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700515 ALOGE("too many samples %u", n);
Glenn Kasten4182c4e2013-07-15 14:45:07 -0700516 n = mSamplingN;
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700517 }
518 // statistics for monotonic (wall clock) time, thread raw CPU load in time, CPU clock frequency,
519 // and adjusted CPU load in MHz normalized for CPU clock frequency
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700520 CentralTendencyStatistics wall, loadNs;
521#ifdef CPU_FREQUENCY_STATISTICS
522 CentralTendencyStatistics kHz, loadMHz;
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700523 uint32_t previousCpukHz = 0;
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700524#endif
Glenn Kasten1ab212cf2012-09-07 12:58:38 -0700525 // Assuming a normal distribution for cycle times, three standard deviations on either side of
526 // the mean account for 99.73% of the population. So if we take each tail to be 1/1000 of the
527 // sample set, we get 99.8% combined, or close to three standard deviations.
528 static const uint32_t kTailDenominator = 1000;
529 uint32_t *tail = n >= kTailDenominator ? new uint32_t[n] : NULL;
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700530 // loop over all the samples
Glenn Kasten1ab212cf2012-09-07 12:58:38 -0700531 for (uint32_t j = 0; j < n; ++j) {
Glenn Kasten4182c4e2013-07-15 14:45:07 -0700532 size_t i = oldestClosed++ & (mSamplingN - 1);
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700533 uint32_t wallNs = mMonotonicNs[i];
Glenn Kasten1ab212cf2012-09-07 12:58:38 -0700534 if (tail != NULL) {
535 tail[j] = wallNs;
536 }
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700537 wall.sample(wallNs);
538 uint32_t sampleLoadNs = mLoadNs[i];
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700539 loadNs.sample(sampleLoadNs);
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700540#ifdef CPU_FREQUENCY_STATISTICS
541 uint32_t sampleCpukHz = mCpukHz[i];
Glenn Kastenc059bd42012-05-14 17:41:09 -0700542 // skip bad kHz samples
543 if ((sampleCpukHz & ~0xF) != 0) {
544 kHz.sample(sampleCpukHz >> 4);
545 if (sampleCpukHz == previousCpukHz) {
546 double megacycles = (double) sampleLoadNs * (double) (sampleCpukHz >> 4) * 1e-12;
547 double adjMHz = megacycles / mixPeriodSec; // _not_ wallNs * 1e9
548 loadMHz.sample(adjMHz);
549 }
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700550 }
551 previousCpukHz = sampleCpukHz;
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700552#endif
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700553 }
Marco Nelissenb2208842014-02-07 14:00:50 -0800554 if (n) {
555 fdprintf(fd, " Simple moving statistics over last %.1f seconds:\n",
556 wall.n() * mixPeriodSec);
557 fdprintf(fd, " wall clock time in ms per mix cycle:\n"
558 " mean=%.2f min=%.2f max=%.2f stddev=%.2f\n",
559 wall.mean()*1e-6, wall.minimum()*1e-6, wall.maximum()*1e-6,
560 wall.stddev()*1e-6);
561 fdprintf(fd, " raw CPU load in us per mix cycle:\n"
562 " mean=%.0f min=%.0f max=%.0f stddev=%.0f\n",
563 loadNs.mean()*1e-3, loadNs.minimum()*1e-3, loadNs.maximum()*1e-3,
564 loadNs.stddev()*1e-3);
565 } else {
566 fdprintf(fd, " No FastMixer statistics available currently\n");
567 }
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700568#ifdef CPU_FREQUENCY_STATISTICS
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700569 fdprintf(fd, " CPU clock frequency in MHz:\n"
570 " mean=%.0f min=%.0f max=%.0f stddev=%.0f\n",
571 kHz.mean()*1e-3, kHz.minimum()*1e-3, kHz.maximum()*1e-3, kHz.stddev()*1e-3);
572 fdprintf(fd, " adjusted CPU load in MHz (i.e. normalized for CPU clock frequency):\n"
573 " mean=%.1f min=%.1f max=%.1f stddev=%.1f\n",
574 loadMHz.mean(), loadMHz.minimum(), loadMHz.maximum(), loadMHz.stddev());
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700575#endif
Glenn Kasten1ab212cf2012-09-07 12:58:38 -0700576 if (tail != NULL) {
577 qsort(tail, n, sizeof(uint32_t), compare_uint32_t);
578 // assume same number of tail samples on each side, left and right
579 uint32_t count = n / kTailDenominator;
580 CentralTendencyStatistics left, right;
581 for (uint32_t i = 0; i < count; ++i) {
582 left.sample(tail[i]);
583 right.sample(tail[n - (i + 1)]);
584 }
Marco Nelissenb2208842014-02-07 14:00:50 -0800585 fdprintf(fd, " Distribution of mix cycle times in ms for the tails (> ~3 stddev outliers):\n"
586 " left tail: mean=%.2f min=%.2f max=%.2f stddev=%.2f\n"
587 " right tail: mean=%.2f min=%.2f max=%.2f stddev=%.2f\n",
Glenn Kasten1ab212cf2012-09-07 12:58:38 -0700588 left.mean()*1e-6, left.minimum()*1e-6, left.maximum()*1e-6, left.stddev()*1e-6,
589 right.mean()*1e-6, right.minimum()*1e-6, right.maximum()*1e-6,
590 right.stddev()*1e-6);
591 delete[] tail;
592 }
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700593#endif
Glenn Kasten1295bb4d2012-05-31 07:43:43 -0700594 // The active track mask and track states are updated non-atomically.
595 // So if we relied on isActive to decide whether to display,
596 // then we might display an obsolete track or omit an active track.
597 // Instead we always display all tracks, with an indication
598 // of whether we think the track is active.
599 uint32_t trackMask = mTrackMask;
Marco Nelissenb2208842014-02-07 14:00:50 -0800600 fdprintf(fd, " Fast tracks: kMaxFastTracks=%u activeMask=%#x\n",
Glenn Kasten1295bb4d2012-05-31 07:43:43 -0700601 FastMixerState::kMaxFastTracks, trackMask);
Marco Nelissenb2208842014-02-07 14:00:50 -0800602 fdprintf(fd, " Index Active Full Partial Empty Recent Ready\n");
Glenn Kasten1295bb4d2012-05-31 07:43:43 -0700603 for (uint32_t i = 0; i < FastMixerState::kMaxFastTracks; ++i, trackMask >>= 1) {
604 bool isActive = trackMask & 1;
605 const FastTrackDump *ftDump = &mTracks[i];
606 const FastTrackUnderruns& underruns = ftDump->mUnderruns;
607 const char *mostRecent;
608 switch (underruns.mBitFields.mMostRecent) {
609 case UNDERRUN_FULL:
610 mostRecent = "full";
611 break;
612 case UNDERRUN_PARTIAL:
613 mostRecent = "partial";
614 break;
615 case UNDERRUN_EMPTY:
616 mostRecent = "empty";
617 break;
618 default:
619 mostRecent = "?";
620 break;
621 }
Narayan Kamath1d6fa7a2014-02-11 13:47:53 +0000622 fdprintf(fd, " %5u %6s %4u %7u %5u %7s %5zu\n", i, isActive ? "yes" : "no",
Glenn Kasten1295bb4d2012-05-31 07:43:43 -0700623 (underruns.mBitFields.mFull) & UNDERRUN_MASK,
624 (underruns.mBitFields.mPartial) & UNDERRUN_MASK,
625 (underruns.mBitFields.mEmpty) & UNDERRUN_MASK,
626 mostRecent, ftDump->mFramesReady);
627 }
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700628}
629
630} // namespace android