blob: 6f347eee0f57529f7bfe6c2518f1f3733a842434 [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 Hung68112fc2014-05-14 14:13:23 -0700227 name = mixer->getTrackName(fastTrack->mChannelMask, AUDIO_SESSION_OUTPUT_MIX);
Glenn Kasten22340022014-04-07 12:04:41 -0700228 ALOG_ASSERT(name >= 0);
229 fastTrackNames[i] = name;
230 mixer->setBufferProvider(name, bufferProvider);
231 mixer->setParameter(name, AudioMixer::TRACK, AudioMixer::MAIN_BUFFER,
232 (void *) mixBuffer);
233 // newly allocated track names default to full scale volume
Glenn Kasten22340022014-04-07 12:04:41 -0700234 mixer->enable(name);
235 }
236 generations[i] = fastTrack->mGeneration;
237 }
238
239 // finally process (potentially) modified tracks; these use the same slot
240 // but may have a different buffer provider or volume provider
241 unsigned modifiedTracks = currentTrackMask & previousTrackMask;
242 while (modifiedTracks != 0) {
243 int i = __builtin_ctz(modifiedTracks);
244 modifiedTracks &= ~(1 << i);
245 const FastTrack* fastTrack = &current->mFastTracks[i];
246 if (fastTrack->mGeneration != generations[i]) {
247 // this track was actually modified
248 AudioBufferProvider *bufferProvider = fastTrack->mBufferProvider;
249 ALOG_ASSERT(bufferProvider != NULL);
250 if (mixer != NULL) {
251 name = fastTrackNames[i];
252 ALOG_ASSERT(name >= 0);
253 mixer->setBufferProvider(name, bufferProvider);
254 if (fastTrack->mVolumeProvider == NULL) {
255 mixer->setParameter(name, AudioMixer::VOLUME, AudioMixer::VOLUME0,
Glenn Kastenc56f3422014-03-21 17:53:17 -0700256 (void *) MAX_GAIN_INT);
Glenn Kasten22340022014-04-07 12:04:41 -0700257 mixer->setParameter(name, AudioMixer::VOLUME, AudioMixer::VOLUME1,
Glenn Kastenc56f3422014-03-21 17:53:17 -0700258 (void *) MAX_GAIN_INT);
Glenn Kasten288ed212012-04-25 17:52:27 -0700259 }
Glenn Kasten22340022014-04-07 12:04:41 -0700260 mixer->setParameter(name, AudioMixer::RESAMPLE,
261 AudioMixer::REMOVE, NULL);
262 mixer->setParameter(name, AudioMixer::TRACK, AudioMixer::CHANNEL_MASK,
263 (void *)(uintptr_t) fastTrack->mChannelMask);
264 // already enabled
265 }
266 generations[i] = fastTrack->mGeneration;
267 }
268 }
269
270 fastTracksGen = current->mFastTracksGen;
271
272 dumpState->mNumTracks = popcount(currentTrackMask);
273 }
274}
275
276void FastMixer::onWork()
277{
278 const FastMixerState * const current = (const FastMixerState *) this->current;
279 FastMixerDumpState * const dumpState = (FastMixerDumpState *) this->dumpState;
280 const FastMixerState::Command command = this->command;
281 const size_t frameCount = current->mFrameCount;
282
283 if ((command & FastMixerState::MIX) && (mixer != NULL) && isWarm) {
284 ALOG_ASSERT(mixBuffer != NULL);
285 // for each track, update volume and check for underrun
286 unsigned currentTrackMask = current->mTrackMask;
287 while (currentTrackMask != 0) {
288 int i = __builtin_ctz(currentTrackMask);
289 currentTrackMask &= ~(1 << i);
290 const FastTrack* fastTrack = &current->mFastTracks[i];
291
292 // Refresh the per-track timestamp
293 if (timestampStatus == NO_ERROR) {
294 uint32_t trackFramesWrittenButNotPresented =
295 nativeFramesWrittenButNotPresented;
296 uint32_t trackFramesWritten = fastTrack->mBufferProvider->framesReleased();
297 // Can't provide an AudioTimestamp before first frame presented,
298 // or during the brief 32-bit wraparound window
299 if (trackFramesWritten >= trackFramesWrittenButNotPresented) {
300 AudioTimestamp perTrackTimestamp;
301 perTrackTimestamp.mPosition =
302 trackFramesWritten - trackFramesWrittenButNotPresented;
303 perTrackTimestamp.mTime = timestamp.mTime;
304 fastTrack->mBufferProvider->onTimestamp(perTrackTimestamp);
305 }
306 }
307
308 int name = fastTrackNames[i];
309 ALOG_ASSERT(name >= 0);
310 if (fastTrack->mVolumeProvider != NULL) {
Glenn Kastenc56f3422014-03-21 17:53:17 -0700311 gain_minifloat_packed_t vlr = fastTrack->mVolumeProvider->getVolumeLR();
Glenn Kasten22340022014-04-07 12:04:41 -0700312 mixer->setParameter(name, AudioMixer::VOLUME, AudioMixer::VOLUME0,
Glenn Kastenc56f3422014-03-21 17:53:17 -0700313 (void *) (uintptr_t)
314 (float_from_gain(gain_minifloat_unpack_left(vlr)) * MAX_GAIN_INT));
Glenn Kasten22340022014-04-07 12:04:41 -0700315 mixer->setParameter(name, AudioMixer::VOLUME, AudioMixer::VOLUME1,
Glenn Kastenc56f3422014-03-21 17:53:17 -0700316 (void *) (uintptr_t)
317 (float_from_gain(gain_minifloat_unpack_right(vlr)) * MAX_GAIN_INT));
Glenn Kasten22340022014-04-07 12:04:41 -0700318 }
319 // FIXME The current implementation of framesReady() for fast tracks
320 // takes a tryLock, which can block
321 // up to 1 ms. If enough active tracks all blocked in sequence, this would result
322 // in the overall fast mix cycle being delayed. Should use a non-blocking FIFO.
323 size_t framesReady = fastTrack->mBufferProvider->framesReady();
324 if (ATRACE_ENABLED()) {
325 // I wish we had formatted trace names
326 char traceName[16];
327 strcpy(traceName, "fRdy");
328 traceName[4] = i + (i < 10 ? '0' : 'A' - 10);
329 traceName[5] = '\0';
330 ATRACE_INT(traceName, framesReady);
331 }
332 FastTrackDump *ftDump = &dumpState->mTracks[i];
333 FastTrackUnderruns underruns = ftDump->mUnderruns;
334 if (framesReady < frameCount) {
335 if (framesReady == 0) {
336 underruns.mBitFields.mEmpty++;
337 underruns.mBitFields.mMostRecent = UNDERRUN_EMPTY;
338 mixer->disable(name);
Glenn Kasten09474df2012-05-10 14:48:07 -0700339 } else {
Glenn Kasten22340022014-04-07 12:04:41 -0700340 // allow mixing partial buffer
341 underruns.mBitFields.mPartial++;
342 underruns.mBitFields.mMostRecent = UNDERRUN_PARTIAL;
Glenn Kasten288ed212012-04-25 17:52:27 -0700343 mixer->enable(name);
344 }
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700345 } else {
Glenn Kasten22340022014-04-07 12:04:41 -0700346 underruns.mBitFields.mFull++;
347 underruns.mBitFields.mMostRecent = UNDERRUN_FULL;
348 mixer->enable(name);
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700349 }
Glenn Kasten22340022014-04-07 12:04:41 -0700350 ftDump->mUnderruns = underruns;
351 ftDump->mFramesReady = framesReady;
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700352 }
353
Glenn Kasten22340022014-04-07 12:04:41 -0700354 int64_t pts;
355 if (outputSink == NULL || (OK != outputSink->getNextWriteTimestamp(&pts))) {
356 pts = AudioBufferProvider::kInvalidPTS;
357 }
358
359 // process() is CPU-bound
360 mixer->process(pts);
361 mixBufferState = MIXED;
362 } else if (mixBufferState == MIXED) {
363 mixBufferState = UNDEFINED;
364 }
365 //bool didFullWrite = false; // dumpsys could display a count of partial writes
366 if ((command & FastMixerState::WRITE) && (outputSink != NULL) && (mixBuffer != NULL)) {
367 if (mixBufferState == UNDEFINED) {
368 memset(mixBuffer, 0, frameCount * FCC_2 * sizeof(short));
369 mixBufferState = ZEROED;
370 }
371 // if non-NULL, then duplicate write() to this non-blocking sink
372 NBAIO_Sink* teeSink;
373 if ((teeSink = current->mTeeSink) != NULL) {
374 (void) teeSink->write(mixBuffer, frameCount);
375 }
376 // FIXME write() is non-blocking and lock-free for a properly implemented NBAIO sink,
377 // but this code should be modified to handle both non-blocking and blocking sinks
378 dumpState->mWriteSequence++;
379 ATRACE_BEGIN("write");
380 ssize_t framesWritten = outputSink->write(mixBuffer, frameCount);
381 ATRACE_END();
382 dumpState->mWriteSequence++;
383 if (framesWritten >= 0) {
384 ALOG_ASSERT((size_t) framesWritten <= frameCount);
385 totalNativeFramesWritten += framesWritten;
386 dumpState->mFramesWritten = totalNativeFramesWritten;
387 //if ((size_t) framesWritten == frameCount) {
388 // didFullWrite = true;
389 //}
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700390 } else {
Glenn Kasten22340022014-04-07 12:04:41 -0700391 dumpState->mWriteErrors++;
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700392 }
Glenn Kasten22340022014-04-07 12:04:41 -0700393 attemptedWrite = true;
394 // FIXME count # of writes blocked excessively, CPU usage, etc. for dump
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700395
Glenn Kasten22340022014-04-07 12:04:41 -0700396 timestampStatus = outputSink->getTimestamp(timestamp);
397 if (timestampStatus == NO_ERROR) {
398 uint32_t totalNativeFramesPresented = timestamp.mPosition;
399 if (totalNativeFramesPresented <= totalNativeFramesWritten) {
400 nativeFramesWrittenButNotPresented =
401 totalNativeFramesWritten - totalNativeFramesPresented;
402 } else {
403 // HAL reported that more frames were presented than were written
404 timestampStatus = INVALID_OPERATION;
405 }
406 }
407 }
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700408}
409
Glenn Kasten4182c4e2013-07-15 14:45:07 -0700410FastMixerDumpState::FastMixerDumpState(
411#ifdef FAST_MIXER_STATISTICS
412 uint32_t samplingN
413#endif
Glenn Kasten22340022014-04-07 12:04:41 -0700414 ) : FastThreadDumpState(),
415 mWriteSequence(0), mFramesWritten(0),
416 mNumTracks(0), mWriteErrors(0),
417 mSampleRate(0), mFrameCount(0),
Glenn Kasten1295bb4d2012-05-31 07:43:43 -0700418 mTrackMask(0)
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700419{
Glenn Kasten153b9fe2013-07-15 11:23:36 -0700420#ifdef FAST_MIXER_STATISTICS
Glenn Kasten4182c4e2013-07-15 14:45:07 -0700421 increaseSamplingN(samplingN);
Glenn Kasten153b9fe2013-07-15 11:23:36 -0700422#endif
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700423}
424
Glenn Kasten4182c4e2013-07-15 14:45:07 -0700425#ifdef FAST_MIXER_STATISTICS
426void FastMixerDumpState::increaseSamplingN(uint32_t samplingN)
427{
428 if (samplingN <= mSamplingN || samplingN > kSamplingN || roundup(samplingN) != samplingN) {
429 return;
430 }
431 uint32_t additional = samplingN - mSamplingN;
432 // sample arrays aren't accessed atomically with respect to the bounds,
433 // so clearing reduces chance for dumpsys to read random uninitialized samples
434 memset(&mMonotonicNs[mSamplingN], 0, sizeof(mMonotonicNs[0]) * additional);
435 memset(&mLoadNs[mSamplingN], 0, sizeof(mLoadNs[0]) * additional);
436#ifdef CPU_FREQUENCY_STATISTICS
437 memset(&mCpukHz[mSamplingN], 0, sizeof(mCpukHz[0]) * additional);
438#endif
439 mSamplingN = samplingN;
440}
441#endif
442
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700443FastMixerDumpState::~FastMixerDumpState()
444{
445}
446
Glenn Kasten1ab212cf2012-09-07 12:58:38 -0700447// helper function called by qsort()
448static int compare_uint32_t(const void *pa, const void *pb)
449{
450 uint32_t a = *(const uint32_t *)pa;
451 uint32_t b = *(const uint32_t *)pb;
452 if (a < b) {
453 return -1;
454 } else if (a > b) {
455 return 1;
456 } else {
457 return 0;
458 }
459}
460
Glenn Kasten4182c4e2013-07-15 14:45:07 -0700461void FastMixerDumpState::dump(int fd) const
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700462{
Glenn Kasten868c0ab2012-06-13 14:59:17 -0700463 if (mCommand == FastMixerState::INITIAL) {
Elliott Hughes87cebad2014-05-22 10:14:43 -0700464 dprintf(fd, " FastMixer not initialized\n");
Glenn Kasten868c0ab2012-06-13 14:59:17 -0700465 return;
466 }
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700467#define COMMAND_MAX 32
468 char string[COMMAND_MAX];
469 switch (mCommand) {
470 case FastMixerState::INITIAL:
471 strcpy(string, "INITIAL");
472 break;
473 case FastMixerState::HOT_IDLE:
474 strcpy(string, "HOT_IDLE");
475 break;
476 case FastMixerState::COLD_IDLE:
477 strcpy(string, "COLD_IDLE");
478 break;
479 case FastMixerState::EXIT:
480 strcpy(string, "EXIT");
481 break;
482 case FastMixerState::MIX:
483 strcpy(string, "MIX");
484 break;
485 case FastMixerState::WRITE:
486 strcpy(string, "WRITE");
487 break;
488 case FastMixerState::MIX_WRITE:
489 strcpy(string, "MIX_WRITE");
490 break;
491 default:
492 snprintf(string, COMMAND_MAX, "%d", mCommand);
493 break;
494 }
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700495 double measuredWarmupMs = (mMeasuredWarmupTs.tv_sec * 1000.0) +
Glenn Kasten288ed212012-04-25 17:52:27 -0700496 (mMeasuredWarmupTs.tv_nsec / 1000000.0);
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700497 double mixPeriodSec = (double) mFrameCount / (double) mSampleRate;
Elliott Hughes87cebad2014-05-22 10:14:43 -0700498 dprintf(fd, " FastMixer command=%s writeSequence=%u framesWritten=%u\n"
499 " numTracks=%u writeErrors=%u underruns=%u overruns=%u\n"
500 " sampleRate=%u frameCount=%zu measuredWarmup=%.3g ms, warmupCycles=%u\n"
501 " mixPeriod=%.2f ms\n",
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700502 string, mWriteSequence, mFramesWritten,
Glenn Kasten21e8c502012-04-12 09:39:42 -0700503 mNumTracks, mWriteErrors, mUnderruns, mOverruns,
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700504 mSampleRate, mFrameCount, measuredWarmupMs, mWarmupCycles,
505 mixPeriodSec * 1e3);
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700506#ifdef FAST_MIXER_STATISTICS
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700507 // find the interval of valid samples
508 uint32_t bounds = mBounds;
509 uint32_t newestOpen = bounds & 0xFFFF;
510 uint32_t oldestClosed = bounds >> 16;
511 uint32_t n = (newestOpen - oldestClosed) & 0xFFFF;
Glenn Kasten4182c4e2013-07-15 14:45:07 -0700512 if (n > mSamplingN) {
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700513 ALOGE("too many samples %u", n);
Glenn Kasten4182c4e2013-07-15 14:45:07 -0700514 n = mSamplingN;
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700515 }
516 // statistics for monotonic (wall clock) time, thread raw CPU load in time, CPU clock frequency,
517 // and adjusted CPU load in MHz normalized for CPU clock frequency
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700518 CentralTendencyStatistics wall, loadNs;
519#ifdef CPU_FREQUENCY_STATISTICS
520 CentralTendencyStatistics kHz, loadMHz;
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700521 uint32_t previousCpukHz = 0;
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700522#endif
Glenn Kasten1ab212cf2012-09-07 12:58:38 -0700523 // Assuming a normal distribution for cycle times, three standard deviations on either side of
524 // the mean account for 99.73% of the population. So if we take each tail to be 1/1000 of the
525 // sample set, we get 99.8% combined, or close to three standard deviations.
526 static const uint32_t kTailDenominator = 1000;
527 uint32_t *tail = n >= kTailDenominator ? new uint32_t[n] : NULL;
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700528 // loop over all the samples
Glenn Kasten1ab212cf2012-09-07 12:58:38 -0700529 for (uint32_t j = 0; j < n; ++j) {
Glenn Kasten4182c4e2013-07-15 14:45:07 -0700530 size_t i = oldestClosed++ & (mSamplingN - 1);
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700531 uint32_t wallNs = mMonotonicNs[i];
Glenn Kasten1ab212cf2012-09-07 12:58:38 -0700532 if (tail != NULL) {
533 tail[j] = wallNs;
534 }
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700535 wall.sample(wallNs);
536 uint32_t sampleLoadNs = mLoadNs[i];
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700537 loadNs.sample(sampleLoadNs);
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700538#ifdef CPU_FREQUENCY_STATISTICS
539 uint32_t sampleCpukHz = mCpukHz[i];
Glenn Kastenc059bd42012-05-14 17:41:09 -0700540 // skip bad kHz samples
541 if ((sampleCpukHz & ~0xF) != 0) {
542 kHz.sample(sampleCpukHz >> 4);
543 if (sampleCpukHz == previousCpukHz) {
544 double megacycles = (double) sampleLoadNs * (double) (sampleCpukHz >> 4) * 1e-12;
545 double adjMHz = megacycles / mixPeriodSec; // _not_ wallNs * 1e9
546 loadMHz.sample(adjMHz);
547 }
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700548 }
549 previousCpukHz = sampleCpukHz;
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700550#endif
Glenn Kasten42d45cf2012-05-02 10:34:47 -0700551 }
Marco Nelissenb2208842014-02-07 14:00:50 -0800552 if (n) {
Elliott Hughes87cebad2014-05-22 10:14:43 -0700553 dprintf(fd, " Simple moving statistics over last %.1f seconds:\n",
554 wall.n() * mixPeriodSec);
555 dprintf(fd, " wall clock time in ms per mix cycle:\n"
556 " mean=%.2f min=%.2f max=%.2f stddev=%.2f\n",
557 wall.mean()*1e-6, wall.minimum()*1e-6, wall.maximum()*1e-6,
558 wall.stddev()*1e-6);
559 dprintf(fd, " raw CPU load in us per mix cycle:\n"
560 " mean=%.0f min=%.0f max=%.0f stddev=%.0f\n",
561 loadNs.mean()*1e-3, loadNs.minimum()*1e-3, loadNs.maximum()*1e-3,
562 loadNs.stddev()*1e-3);
Marco Nelissenb2208842014-02-07 14:00:50 -0800563 } else {
Elliott Hughes87cebad2014-05-22 10:14:43 -0700564 dprintf(fd, " No FastMixer statistics available currently\n");
Marco Nelissenb2208842014-02-07 14:00:50 -0800565 }
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700566#ifdef CPU_FREQUENCY_STATISTICS
Elliott Hughes8b5f6422014-05-22 01:22:06 -0700567 dprintf(fd, " CPU clock frequency in MHz:\n"
568 " mean=%.0f min=%.0f max=%.0f stddev=%.0f\n",
569 kHz.mean()*1e-3, kHz.minimum()*1e-3, kHz.maximum()*1e-3, kHz.stddev()*1e-3);
570 dprintf(fd, " adjusted CPU load in MHz (i.e. normalized for CPU clock frequency):\n"
571 " mean=%.1f min=%.1f max=%.1f stddev=%.1f\n",
572 loadMHz.mean(), loadMHz.minimum(), loadMHz.maximum(), loadMHz.stddev());
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700573#endif
Glenn Kasten1ab212cf2012-09-07 12:58:38 -0700574 if (tail != NULL) {
575 qsort(tail, n, sizeof(uint32_t), compare_uint32_t);
576 // assume same number of tail samples on each side, left and right
577 uint32_t count = n / kTailDenominator;
578 CentralTendencyStatistics left, right;
579 for (uint32_t i = 0; i < count; ++i) {
580 left.sample(tail[i]);
581 right.sample(tail[n - (i + 1)]);
582 }
Elliott Hughes87cebad2014-05-22 10:14:43 -0700583 dprintf(fd, " Distribution of mix cycle times in ms for the tails (> ~3 stddev outliers):\n"
584 " left tail: mean=%.2f min=%.2f max=%.2f stddev=%.2f\n"
585 " right tail: mean=%.2f min=%.2f max=%.2f stddev=%.2f\n",
Elliott Hughes8b5f6422014-05-22 01:22:06 -0700586 left.mean()*1e-6, left.minimum()*1e-6, left.maximum()*1e-6, left.stddev()*1e-6,
587 right.mean()*1e-6, right.minimum()*1e-6, right.maximum()*1e-6,
588 right.stddev()*1e-6);
Glenn Kasten1ab212cf2012-09-07 12:58:38 -0700589 delete[] tail;
590 }
Glenn Kasten0a14c4c2012-06-13 14:58:49 -0700591#endif
Glenn Kasten1295bb4d2012-05-31 07:43:43 -0700592 // The active track mask and track states are updated non-atomically.
593 // So if we relied on isActive to decide whether to display,
594 // then we might display an obsolete track or omit an active track.
595 // Instead we always display all tracks, with an indication
596 // of whether we think the track is active.
597 uint32_t trackMask = mTrackMask;
Elliott Hughes87cebad2014-05-22 10:14:43 -0700598 dprintf(fd, " Fast tracks: kMaxFastTracks=%u activeMask=%#x\n",
Glenn Kasten1295bb4d2012-05-31 07:43:43 -0700599 FastMixerState::kMaxFastTracks, trackMask);
Elliott Hughes87cebad2014-05-22 10:14:43 -0700600 dprintf(fd, " Index Active Full Partial Empty Recent Ready\n");
Glenn Kasten1295bb4d2012-05-31 07:43:43 -0700601 for (uint32_t i = 0; i < FastMixerState::kMaxFastTracks; ++i, trackMask >>= 1) {
602 bool isActive = trackMask & 1;
603 const FastTrackDump *ftDump = &mTracks[i];
604 const FastTrackUnderruns& underruns = ftDump->mUnderruns;
605 const char *mostRecent;
606 switch (underruns.mBitFields.mMostRecent) {
607 case UNDERRUN_FULL:
608 mostRecent = "full";
609 break;
610 case UNDERRUN_PARTIAL:
611 mostRecent = "partial";
612 break;
613 case UNDERRUN_EMPTY:
614 mostRecent = "empty";
615 break;
616 default:
617 mostRecent = "?";
618 break;
619 }
Elliott Hughes87cebad2014-05-22 10:14:43 -0700620 dprintf(fd, " %5u %6s %4u %7u %5u %7s %5zu\n", i, isActive ? "yes" : "no",
Glenn Kasten1295bb4d2012-05-31 07:43:43 -0700621 (underruns.mBitFields.mFull) & UNDERRUN_MASK,
622 (underruns.mBitFields.mPartial) & UNDERRUN_MASK,
623 (underruns.mBitFields.mEmpty) & UNDERRUN_MASK,
624 mostRecent, ftDump->mFramesReady);
625 }
Glenn Kasten97b5d0d2012-03-23 18:54:19 -0700626}
627
628} // namespace android