FastMixer.cpp revision 972af221ae7253e406e0e1ea853e56a3010ed6b1
1/* 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 20#include <sys/atomics.h> 21#include <time.h> 22#include <utils/Log.h> 23#include <utils/Trace.h> 24#include <system/audio.h> 25#ifdef FAST_MIXER_STATISTICS 26#include <cpustats/CentralTendencyStatistics.h> 27#ifdef CPU_FREQUENCY_STATISTICS 28#include <cpustats/ThreadCpuUsage.h> 29#endif 30#endif 31#include "AudioMixer.h" 32#include "FastMixer.h" 33 34#define FAST_HOT_IDLE_NS 1000000L // 1 ms: time to sleep while hot idling 35#define FAST_DEFAULT_NS 999999999L // ~1 sec: default time to sleep 36#define MAX_WARMUP_CYCLES 10 // maximum number of loop cycles to wait for warmup 37 38namespace android { 39 40// Fast mixer thread 41bool FastMixer::threadLoop() 42{ 43 static const FastMixerState initial; 44 const FastMixerState *previous = &initial, *current = &initial; 45 FastMixerState preIdle; // copy of state before we went into idle 46 struct timespec oldTs = {0, 0}; 47 bool oldTsValid = false; 48 long slopNs = 0; // accumulated time we've woken up too early (> 0) or too late (< 0) 49 long sleepNs = -1; // -1: busy wait, 0: sched_yield, > 0: nanosleep 50 int fastTrackNames[FastMixerState::kMaxFastTracks]; // handles used by mixer to identify tracks 51 int generations[FastMixerState::kMaxFastTracks]; // last observed mFastTracks[i].mGeneration 52 unsigned i; 53 for (i = 0; i < FastMixerState::kMaxFastTracks; ++i) { 54 fastTrackNames[i] = -1; 55 generations[i] = 0; 56 } 57 NBAIO_Sink *outputSink = NULL; 58 int outputSinkGen = 0; 59 AudioMixer* mixer = NULL; 60 short *mixBuffer = NULL; 61 enum {UNDEFINED, MIXED, ZEROED} mixBufferState = UNDEFINED; 62 NBAIO_Format format = Format_Invalid; 63 unsigned sampleRate = 0; 64 int fastTracksGen = 0; 65 long periodNs = 0; // expected period; the time required to render one mix buffer 66 long underrunNs = 0; // underrun likely when write cycle is greater than this value 67 long overrunNs = 0; // overrun likely when write cycle is less than this value 68 long forceNs = 0; // if overrun detected, force the write cycle to take this much time 69 long warmupNs = 0; // warmup complete when write cycle is greater than to this value 70 FastMixerDumpState dummyDumpState, *dumpState = &dummyDumpState; 71 bool ignoreNextOverrun = true; // used to ignore initial overrun and first after an underrun 72#ifdef FAST_MIXER_STATISTICS 73 struct timespec oldLoad = {0, 0}; // previous value of clock_gettime(CLOCK_THREAD_CPUTIME_ID) 74 bool oldLoadValid = false; // whether oldLoad is valid 75 uint32_t bounds = 0; 76 bool full = false; // whether we have collected at least kSamplingN samples 77#ifdef CPU_FREQUENCY_STATISTICS 78 ThreadCpuUsage tcu; // for reading the current CPU clock frequency in kHz 79#endif 80#endif 81 unsigned coldGen = 0; // last observed mColdGen 82 bool isWarm = false; // true means ready to mix, false means wait for warmup before mixing 83 struct timespec measuredWarmupTs = {0, 0}; // how long did it take for warmup to complete 84 uint32_t warmupCycles = 0; // counter of number of loop cycles required to warmup 85 NBAIO_Sink* teeSink = NULL; // if non-NULL, then duplicate write() to this non-blocking sink 86 87 for (;;) { 88 89 // either nanosleep, sched_yield, or busy wait 90 if (sleepNs >= 0) { 91 if (sleepNs > 0) { 92 ALOG_ASSERT(sleepNs < 1000000000); 93 const struct timespec req = {0, sleepNs}; 94 nanosleep(&req, NULL); 95 } else { 96 sched_yield(); 97 } 98 } 99 // default to long sleep for next cycle 100 sleepNs = FAST_DEFAULT_NS; 101 102 // poll for state change 103 const FastMixerState *next = mSQ.poll(); 104 if (next == NULL) { 105 // continue to use the default initial state until a real state is available 106 ALOG_ASSERT(current == &initial && previous == &initial); 107 next = current; 108 } 109 110 FastMixerState::Command command = next->mCommand; 111 if (next != current) { 112 113 // As soon as possible of learning of a new dump area, start using it 114 dumpState = next->mDumpState != NULL ? next->mDumpState : &dummyDumpState; 115 teeSink = next->mTeeSink; 116 117 // We want to always have a valid reference to the previous (non-idle) state. 118 // However, the state queue only guarantees access to current and previous states. 119 // So when there is a transition from a non-idle state into an idle state, we make a 120 // copy of the last known non-idle state so it is still available on return from idle. 121 // The possible transitions are: 122 // non-idle -> non-idle update previous from current in-place 123 // non-idle -> idle update previous from copy of current 124 // idle -> idle don't update previous 125 // idle -> non-idle don't update previous 126 if (!(current->mCommand & FastMixerState::IDLE)) { 127 if (command & FastMixerState::IDLE) { 128 preIdle = *current; 129 current = &preIdle; 130 oldTsValid = false; 131 oldLoadValid = false; 132 ignoreNextOverrun = true; 133 } 134 previous = current; 135 } 136 current = next; 137 } 138#if !LOG_NDEBUG 139 next = NULL; // not referenced again 140#endif 141 142 dumpState->mCommand = command; 143 144 switch (command) { 145 case FastMixerState::INITIAL: 146 case FastMixerState::HOT_IDLE: 147 sleepNs = FAST_HOT_IDLE_NS; 148 continue; 149 case FastMixerState::COLD_IDLE: 150 // only perform a cold idle command once 151 // FIXME consider checking previous state and only perform if previous != COLD_IDLE 152 if (current->mColdGen != coldGen) { 153 int32_t *coldFutexAddr = current->mColdFutexAddr; 154 ALOG_ASSERT(coldFutexAddr != NULL); 155 int32_t old = android_atomic_dec(coldFutexAddr); 156 if (old <= 0) { 157 __futex_syscall4(coldFutexAddr, FUTEX_WAIT_PRIVATE, old - 1, NULL); 158 } 159 // This may be overly conservative; there could be times that the normal mixer 160 // requests such a brief cold idle that it doesn't require resetting this flag. 161 isWarm = false; 162 measuredWarmupTs.tv_sec = 0; 163 measuredWarmupTs.tv_nsec = 0; 164 warmupCycles = 0; 165 sleepNs = -1; 166 coldGen = current->mColdGen; 167 bounds = 0; 168 full = false; 169 oldTsValid = !clock_gettime(CLOCK_MONOTONIC, &oldTs); 170 } else { 171 sleepNs = FAST_HOT_IDLE_NS; 172 } 173 continue; 174 case FastMixerState::EXIT: 175 delete mixer; 176 delete[] mixBuffer; 177 return false; 178 case FastMixerState::MIX: 179 case FastMixerState::WRITE: 180 case FastMixerState::MIX_WRITE: 181 break; 182 default: 183 LOG_FATAL("bad command %d", command); 184 } 185 186 // there is a non-idle state available to us; did the state change? 187 size_t frameCount = current->mFrameCount; 188 if (current != previous) { 189 190 // handle state change here, but since we want to diff the state, 191 // we're prepared for previous == &initial the first time through 192 unsigned previousTrackMask; 193 194 // check for change in output HAL configuration 195 NBAIO_Format previousFormat = format; 196 if (current->mOutputSinkGen != outputSinkGen) { 197 outputSink = current->mOutputSink; 198 outputSinkGen = current->mOutputSinkGen; 199 if (outputSink == NULL) { 200 format = Format_Invalid; 201 sampleRate = 0; 202 } else { 203 format = outputSink->format(); 204 sampleRate = Format_sampleRate(format); 205 ALOG_ASSERT(Format_channelCount(format) == 2); 206 } 207 dumpState->mSampleRate = sampleRate; 208 } 209 210 if ((format != previousFormat) || (frameCount != previous->mFrameCount)) { 211 // FIXME to avoid priority inversion, don't delete here 212 delete mixer; 213 mixer = NULL; 214 delete[] mixBuffer; 215 mixBuffer = NULL; 216 if (frameCount > 0 && sampleRate > 0) { 217 // FIXME new may block for unbounded time at internal mutex of the heap 218 // implementation; it would be better to have normal mixer allocate for us 219 // to avoid blocking here and to prevent possible priority inversion 220 mixer = new AudioMixer(frameCount, sampleRate, FastMixerState::kMaxFastTracks); 221 mixBuffer = new short[frameCount * 2]; 222 periodNs = (frameCount * 1000000000LL) / sampleRate; // 1.00 223 underrunNs = (frameCount * 1750000000LL) / sampleRate; // 1.75 224 overrunNs = (frameCount * 250000000LL) / sampleRate; // 0.25 225 forceNs = (frameCount * 750000000LL) / sampleRate; // 0.75 226 warmupNs = (frameCount * 500000000LL) / sampleRate; // 0.50 227 } else { 228 periodNs = 0; 229 underrunNs = 0; 230 overrunNs = 0; 231 forceNs = 0; 232 warmupNs = 0; 233 } 234 mixBufferState = UNDEFINED; 235#if !LOG_NDEBUG 236 for (i = 0; i < FastMixerState::kMaxFastTracks; ++i) { 237 fastTrackNames[i] = -1; 238 } 239#endif 240 // we need to reconfigure all active tracks 241 previousTrackMask = 0; 242 fastTracksGen = current->mFastTracksGen - 1; 243 dumpState->mFrameCount = frameCount; 244 } else { 245 previousTrackMask = previous->mTrackMask; 246 } 247 248 // check for change in active track set 249 unsigned currentTrackMask = current->mTrackMask; 250 dumpState->mTrackMask = currentTrackMask; 251 if (current->mFastTracksGen != fastTracksGen) { 252 ALOG_ASSERT(mixBuffer != NULL); 253 int name; 254 255 // process removed tracks first to avoid running out of track names 256 unsigned removedTracks = previousTrackMask & ~currentTrackMask; 257 while (removedTracks != 0) { 258 i = __builtin_ctz(removedTracks); 259 removedTracks &= ~(1 << i); 260 const FastTrack* fastTrack = ¤t->mFastTracks[i]; 261 ALOG_ASSERT(fastTrack->mBufferProvider == NULL); 262 if (mixer != NULL) { 263 name = fastTrackNames[i]; 264 ALOG_ASSERT(name >= 0); 265 mixer->deleteTrackName(name); 266 } 267#if !LOG_NDEBUG 268 fastTrackNames[i] = -1; 269#endif 270 // don't reset track dump state, since other side is ignoring it 271 generations[i] = fastTrack->mGeneration; 272 } 273 274 // now process added tracks 275 unsigned addedTracks = currentTrackMask & ~previousTrackMask; 276 while (addedTracks != 0) { 277 i = __builtin_ctz(addedTracks); 278 addedTracks &= ~(1 << i); 279 const FastTrack* fastTrack = ¤t->mFastTracks[i]; 280 AudioBufferProvider *bufferProvider = fastTrack->mBufferProvider; 281 ALOG_ASSERT(bufferProvider != NULL && fastTrackNames[i] == -1); 282 if (mixer != NULL) { 283 // calling getTrackName with default channel mask 284 name = mixer->getTrackName(AUDIO_CHANNEL_OUT_STEREO); 285 ALOG_ASSERT(name >= 0); 286 fastTrackNames[i] = name; 287 mixer->setBufferProvider(name, bufferProvider); 288 mixer->setParameter(name, AudioMixer::TRACK, AudioMixer::MAIN_BUFFER, 289 (void *) mixBuffer); 290 // newly allocated track names default to full scale volume 291 if (fastTrack->mSampleRate != 0 && fastTrack->mSampleRate != sampleRate) { 292 mixer->setParameter(name, AudioMixer::RESAMPLE, 293 AudioMixer::SAMPLE_RATE, (void*) fastTrack->mSampleRate); 294 } 295 mixer->setParameter(name, AudioMixer::TRACK, AudioMixer::CHANNEL_MASK, 296 (void *) fastTrack->mChannelMask); 297 mixer->enable(name); 298 } 299 generations[i] = fastTrack->mGeneration; 300 } 301 302 // finally process modified tracks; these use the same slot 303 // but may have a different buffer provider or volume provider 304 unsigned modifiedTracks = currentTrackMask & previousTrackMask; 305 while (modifiedTracks != 0) { 306 i = __builtin_ctz(modifiedTracks); 307 modifiedTracks &= ~(1 << i); 308 const FastTrack* fastTrack = ¤t->mFastTracks[i]; 309 if (fastTrack->mGeneration != generations[i]) { 310 AudioBufferProvider *bufferProvider = fastTrack->mBufferProvider; 311 ALOG_ASSERT(bufferProvider != NULL); 312 if (mixer != NULL) { 313 name = fastTrackNames[i]; 314 ALOG_ASSERT(name >= 0); 315 mixer->setBufferProvider(name, bufferProvider); 316 if (fastTrack->mVolumeProvider == NULL) { 317 mixer->setParameter(name, AudioMixer::VOLUME, AudioMixer::VOLUME0, 318 (void *)0x1000); 319 mixer->setParameter(name, AudioMixer::VOLUME, AudioMixer::VOLUME1, 320 (void *)0x1000); 321 } 322 if (fastTrack->mSampleRate != 0 && 323 fastTrack->mSampleRate != sampleRate) { 324 mixer->setParameter(name, AudioMixer::RESAMPLE, 325 AudioMixer::SAMPLE_RATE, (void*) fastTrack->mSampleRate); 326 } else { 327 mixer->setParameter(name, AudioMixer::RESAMPLE, 328 AudioMixer::REMOVE, NULL); 329 } 330 mixer->setParameter(name, AudioMixer::TRACK, AudioMixer::CHANNEL_MASK, 331 (void *) fastTrack->mChannelMask); 332 // already enabled 333 } 334 generations[i] = fastTrack->mGeneration; 335 } 336 } 337 338 fastTracksGen = current->mFastTracksGen; 339 340 dumpState->mNumTracks = popcount(currentTrackMask); 341 } 342 343#if 1 // FIXME shouldn't need this 344 // only process state change once 345 previous = current; 346#endif 347 } 348 349 // do work using current state here 350 if ((command & FastMixerState::MIX) && (mixer != NULL) && isWarm) { 351 ALOG_ASSERT(mixBuffer != NULL); 352 // for each track, update volume and check for underrun 353 unsigned currentTrackMask = current->mTrackMask; 354 while (currentTrackMask != 0) { 355 i = __builtin_ctz(currentTrackMask); 356 currentTrackMask &= ~(1 << i); 357 const FastTrack* fastTrack = ¤t->mFastTracks[i]; 358 int name = fastTrackNames[i]; 359 ALOG_ASSERT(name >= 0); 360 if (fastTrack->mVolumeProvider != NULL) { 361 uint32_t vlr = fastTrack->mVolumeProvider->getVolumeLR(); 362 mixer->setParameter(name, AudioMixer::VOLUME, AudioMixer::VOLUME0, 363 (void *)(vlr & 0xFFFF)); 364 mixer->setParameter(name, AudioMixer::VOLUME, AudioMixer::VOLUME1, 365 (void *)(vlr >> 16)); 366 } 367 // FIXME The current implementation of framesReady() for fast tracks 368 // takes a tryLock, which can block 369 // up to 1 ms. If enough active tracks all blocked in sequence, this would result 370 // in the overall fast mix cycle being delayed. Should use a non-blocking FIFO. 371 size_t framesReady = fastTrack->mBufferProvider->framesReady(); 372#if defined(ATRACE_TAG) && (ATRACE_TAG != ATRACE_TAG_NEVER) 373 // I wish we had formatted trace names 374 char traceName[16]; 375 strcpy(traceName, "framesReady"); 376 traceName[11] = i + (i < 10 ? '0' : 'A' - 10); 377 traceName[12] = '\0'; 378 ATRACE_INT(traceName, framesReady); 379#endif 380 FastTrackDump *ftDump = &dumpState->mTracks[i]; 381 FastTrackUnderruns underruns = ftDump->mUnderruns; 382 if (framesReady < frameCount) { 383 if (framesReady == 0) { 384 underruns.mBitFields.mEmpty++; 385 underruns.mBitFields.mMostRecent = UNDERRUN_EMPTY; 386 mixer->disable(name); 387 } else { 388 // allow mixing partial buffer 389 underruns.mBitFields.mPartial++; 390 underruns.mBitFields.mMostRecent = UNDERRUN_PARTIAL; 391 mixer->enable(name); 392 } 393 } else { 394 underruns.mBitFields.mFull++; 395 underruns.mBitFields.mMostRecent = UNDERRUN_FULL; 396 mixer->enable(name); 397 } 398 ftDump->mUnderruns = underruns; 399 ftDump->mFramesReady = framesReady; 400 } 401 // process() is CPU-bound 402 mixer->process(AudioBufferProvider::kInvalidPTS); 403 mixBufferState = MIXED; 404 } else if (mixBufferState == MIXED) { 405 mixBufferState = UNDEFINED; 406 } 407 bool attemptedWrite = false; 408 //bool didFullWrite = false; // dumpsys could display a count of partial writes 409 if ((command & FastMixerState::WRITE) && (outputSink != NULL) && (mixBuffer != NULL)) { 410 if (mixBufferState == UNDEFINED) { 411 memset(mixBuffer, 0, frameCount * 2 * sizeof(short)); 412 mixBufferState = ZEROED; 413 } 414 if (teeSink != NULL) { 415 (void) teeSink->write(mixBuffer, frameCount); 416 } 417 // FIXME write() is non-blocking and lock-free for a properly implemented NBAIO sink, 418 // but this code should be modified to handle both non-blocking and blocking sinks 419 dumpState->mWriteSequence++; 420#if defined(ATRACE_TAG) && (ATRACE_TAG != ATRACE_TAG_NEVER) 421 Tracer::traceBegin(ATRACE_TAG, "write"); 422#endif 423 ssize_t framesWritten = outputSink->write(mixBuffer, frameCount); 424#if defined(ATRACE_TAG) && (ATRACE_TAG != ATRACE_TAG_NEVER) 425 Tracer::traceEnd(ATRACE_TAG); 426#endif 427 dumpState->mWriteSequence++; 428 if (framesWritten >= 0) { 429 ALOG_ASSERT(framesWritten <= frameCount); 430 dumpState->mFramesWritten += framesWritten; 431 //if ((size_t) framesWritten == frameCount) { 432 // didFullWrite = true; 433 //} 434 } else { 435 dumpState->mWriteErrors++; 436 } 437 attemptedWrite = true; 438 // FIXME count # of writes blocked excessively, CPU usage, etc. for dump 439 } 440 441 // To be exactly periodic, compute the next sleep time based on current time. 442 // This code doesn't have long-term stability when the sink is non-blocking. 443 // FIXME To avoid drift, use the local audio clock or watch the sink's fill status. 444 struct timespec newTs; 445 int rc = clock_gettime(CLOCK_MONOTONIC, &newTs); 446 if (rc == 0) { 447 if (oldTsValid) { 448 time_t sec = newTs.tv_sec - oldTs.tv_sec; 449 long nsec = newTs.tv_nsec - oldTs.tv_nsec; 450 if (nsec < 0) { 451 --sec; 452 nsec += 1000000000; 453 } 454 // To avoid an initial underrun on fast tracks after exiting standby, 455 // do not start pulling data from tracks and mixing until warmup is complete. 456 // Warmup is considered complete after the earlier of: 457 // first successful single write() that blocks for more than warmupNs 458 // MAX_WARMUP_CYCLES write() attempts. 459 // This is overly conservative, but to get better accuracy requires a new HAL API. 460 if (!isWarm && attemptedWrite) { 461 measuredWarmupTs.tv_sec += sec; 462 measuredWarmupTs.tv_nsec += nsec; 463 if (measuredWarmupTs.tv_nsec >= 1000000000) { 464 measuredWarmupTs.tv_sec++; 465 measuredWarmupTs.tv_nsec -= 1000000000; 466 } 467 ++warmupCycles; 468 if ((attemptedWrite && nsec > warmupNs) || 469 (warmupCycles >= MAX_WARMUP_CYCLES)) { 470 isWarm = true; 471 dumpState->mMeasuredWarmupTs = measuredWarmupTs; 472 dumpState->mWarmupCycles = warmupCycles; 473 } 474 } 475 sleepNs = -1; 476 if (isWarm) { 477 if (sec > 0 || nsec > underrunNs) { 478#if defined(ATRACE_TAG) && (ATRACE_TAG != ATRACE_TAG_NEVER) 479 ScopedTrace st(ATRACE_TAG, "underrun"); 480#endif 481 // FIXME only log occasionally 482 ALOGV("underrun: time since last cycle %d.%03ld sec", 483 (int) sec, nsec / 1000000L); 484 dumpState->mUnderruns++; 485 ignoreNextOverrun = true; 486 } else if (nsec < overrunNs) { 487 if (ignoreNextOverrun) { 488 ignoreNextOverrun = false; 489 } else { 490 // FIXME only log occasionally 491 ALOGV("overrun: time since last cycle %d.%03ld sec", 492 (int) sec, nsec / 1000000L); 493 dumpState->mOverruns++; 494 } 495 // This forces a minimum cycle time. It: 496 // - compensates for an audio HAL with jitter due to sample rate conversion 497 // - works with a variable buffer depth audio HAL that never pulls at a rate 498 // < than overrunNs per buffer. 499 // - recovers from overrun immediately after underrun 500 // It doesn't work with a non-blocking audio HAL. 501 sleepNs = forceNs - nsec; 502 } else { 503 ignoreNextOverrun = false; 504 } 505 } 506#ifdef FAST_MIXER_STATISTICS 507 // advance the FIFO queue bounds 508 size_t i = bounds & (FastMixerDumpState::kSamplingN - 1); 509 bounds = (bounds & 0xFFFF0000) | ((bounds + 1) & 0xFFFF); 510 if (full) { 511 bounds += 0x10000; 512 } else if (!(bounds & (FastMixerDumpState::kSamplingN - 1))) { 513 full = true; 514 } 515 // compute the delta value of clock_gettime(CLOCK_MONOTONIC) 516 uint32_t monotonicNs = nsec; 517 if (sec > 0 && sec < 4) { 518 monotonicNs += sec * 1000000000; 519 } 520 // compute the raw CPU load = delta value of clock_gettime(CLOCK_THREAD_CPUTIME_ID) 521 uint32_t loadNs = 0; 522 struct timespec newLoad; 523 rc = clock_gettime(CLOCK_THREAD_CPUTIME_ID, &newLoad); 524 if (rc == 0) { 525 if (oldLoadValid) { 526 sec = newLoad.tv_sec - oldLoad.tv_sec; 527 nsec = newLoad.tv_nsec - oldLoad.tv_nsec; 528 if (nsec < 0) { 529 --sec; 530 nsec += 1000000000; 531 } 532 loadNs = nsec; 533 if (sec > 0 && sec < 4) { 534 loadNs += sec * 1000000000; 535 } 536 } else { 537 // first time through the loop 538 oldLoadValid = true; 539 } 540 oldLoad = newLoad; 541 } 542#ifdef CPU_FREQUENCY_STATISTICS 543 // get the absolute value of CPU clock frequency in kHz 544 int cpuNum = sched_getcpu(); 545 uint32_t kHz = tcu.getCpukHz(cpuNum); 546 kHz = (kHz << 4) | (cpuNum & 0xF); 547#endif 548 // save values in FIFO queues for dumpsys 549 // these stores #1, #2, #3 are not atomic with respect to each other, 550 // or with respect to store #4 below 551 dumpState->mMonotonicNs[i] = monotonicNs; 552 dumpState->mLoadNs[i] = loadNs; 553#ifdef CPU_FREQUENCY_STATISTICS 554 dumpState->mCpukHz[i] = kHz; 555#endif 556 // this store #4 is not atomic with respect to stores #1, #2, #3 above, but 557 // the newest open and oldest closed halves are atomic with respect to each other 558 dumpState->mBounds = bounds; 559#if defined(ATRACE_TAG) && (ATRACE_TAG != ATRACE_TAG_NEVER) 560 ATRACE_INT("cycle_ms", monotonicNs / 1000000); 561 ATRACE_INT("load_us", loadNs / 1000); 562#endif 563#endif 564 } else { 565 // first time through the loop 566 oldTsValid = true; 567 sleepNs = periodNs; 568 ignoreNextOverrun = true; 569 } 570 oldTs = newTs; 571 } else { 572 // monotonic clock is broken 573 oldTsValid = false; 574 sleepNs = periodNs; 575 } 576 577 578 } // for (;;) 579 580 // never return 'true'; Thread::_threadLoop() locks mutex which can result in priority inversion 581} 582 583FastMixerDumpState::FastMixerDumpState() : 584 mCommand(FastMixerState::INITIAL), mWriteSequence(0), mFramesWritten(0), 585 mNumTracks(0), mWriteErrors(0), mUnderruns(0), mOverruns(0), 586 mSampleRate(0), mFrameCount(0), /* mMeasuredWarmupTs({0, 0}), */ mWarmupCycles(0), 587 mTrackMask(0) 588#ifdef FAST_MIXER_STATISTICS 589 , mBounds(0) 590#endif 591{ 592 mMeasuredWarmupTs.tv_sec = 0; 593 mMeasuredWarmupTs.tv_nsec = 0; 594 // sample arrays aren't accessed atomically with respect to the bounds, 595 // so clearing reduces chance for dumpsys to read random uninitialized samples 596 memset(&mMonotonicNs, 0, sizeof(mMonotonicNs)); 597 memset(&mLoadNs, 0, sizeof(mLoadNs)); 598#ifdef CPU_FREQUENCY_STATISTICS 599 memset(&mCpukHz, 0, sizeof(mCpukHz)); 600#endif 601} 602 603FastMixerDumpState::~FastMixerDumpState() 604{ 605} 606 607void FastMixerDumpState::dump(int fd) 608{ 609 if (mCommand == FastMixerState::INITIAL) { 610 fdprintf(fd, "FastMixer not initialized\n"); 611 return; 612 } 613#define COMMAND_MAX 32 614 char string[COMMAND_MAX]; 615 switch (mCommand) { 616 case FastMixerState::INITIAL: 617 strcpy(string, "INITIAL"); 618 break; 619 case FastMixerState::HOT_IDLE: 620 strcpy(string, "HOT_IDLE"); 621 break; 622 case FastMixerState::COLD_IDLE: 623 strcpy(string, "COLD_IDLE"); 624 break; 625 case FastMixerState::EXIT: 626 strcpy(string, "EXIT"); 627 break; 628 case FastMixerState::MIX: 629 strcpy(string, "MIX"); 630 break; 631 case FastMixerState::WRITE: 632 strcpy(string, "WRITE"); 633 break; 634 case FastMixerState::MIX_WRITE: 635 strcpy(string, "MIX_WRITE"); 636 break; 637 default: 638 snprintf(string, COMMAND_MAX, "%d", mCommand); 639 break; 640 } 641 double measuredWarmupMs = (mMeasuredWarmupTs.tv_sec * 1000.0) + 642 (mMeasuredWarmupTs.tv_nsec / 1000000.0); 643 double mixPeriodSec = (double) mFrameCount / (double) mSampleRate; 644 fdprintf(fd, "FastMixer command=%s writeSequence=%u framesWritten=%u\n" 645 " numTracks=%u writeErrors=%u underruns=%u overruns=%u\n" 646 " sampleRate=%u frameCount=%u measuredWarmup=%.3g ms, warmupCycles=%u\n" 647 " mixPeriod=%.2f ms\n", 648 string, mWriteSequence, mFramesWritten, 649 mNumTracks, mWriteErrors, mUnderruns, mOverruns, 650 mSampleRate, mFrameCount, measuredWarmupMs, mWarmupCycles, 651 mixPeriodSec * 1e3); 652#ifdef FAST_MIXER_STATISTICS 653 // find the interval of valid samples 654 uint32_t bounds = mBounds; 655 uint32_t newestOpen = bounds & 0xFFFF; 656 uint32_t oldestClosed = bounds >> 16; 657 uint32_t n = (newestOpen - oldestClosed) & 0xFFFF; 658 if (n > kSamplingN) { 659 ALOGE("too many samples %u", n); 660 n = kSamplingN; 661 } 662 // statistics for monotonic (wall clock) time, thread raw CPU load in time, CPU clock frequency, 663 // and adjusted CPU load in MHz normalized for CPU clock frequency 664 CentralTendencyStatistics wall, loadNs; 665#ifdef CPU_FREQUENCY_STATISTICS 666 CentralTendencyStatistics kHz, loadMHz; 667 uint32_t previousCpukHz = 0; 668#endif 669 // loop over all the samples 670 for (; n > 0; --n) { 671 size_t i = oldestClosed++ & (kSamplingN - 1); 672 uint32_t wallNs = mMonotonicNs[i]; 673 wall.sample(wallNs); 674 uint32_t sampleLoadNs = mLoadNs[i]; 675 loadNs.sample(sampleLoadNs); 676#ifdef CPU_FREQUENCY_STATISTICS 677 uint32_t sampleCpukHz = mCpukHz[i]; 678 // skip bad kHz samples 679 if ((sampleCpukHz & ~0xF) != 0) { 680 kHz.sample(sampleCpukHz >> 4); 681 if (sampleCpukHz == previousCpukHz) { 682 double megacycles = (double) sampleLoadNs * (double) (sampleCpukHz >> 4) * 1e-12; 683 double adjMHz = megacycles / mixPeriodSec; // _not_ wallNs * 1e9 684 loadMHz.sample(adjMHz); 685 } 686 } 687 previousCpukHz = sampleCpukHz; 688#endif 689 } 690 fdprintf(fd, "Simple moving statistics over last %.1f seconds:\n", wall.n() * mixPeriodSec); 691 fdprintf(fd, " wall clock time in ms per mix cycle:\n" 692 " mean=%.2f min=%.2f max=%.2f stddev=%.2f\n", 693 wall.mean()*1e-6, wall.minimum()*1e-6, wall.maximum()*1e-6, wall.stddev()*1e-6); 694 fdprintf(fd, " raw CPU load in us per mix cycle:\n" 695 " mean=%.0f min=%.0f max=%.0f stddev=%.0f\n", 696 loadNs.mean()*1e-3, loadNs.minimum()*1e-3, loadNs.maximum()*1e-3, 697 loadNs.stddev()*1e-3); 698#ifdef CPU_FREQUENCY_STATISTICS 699 fdprintf(fd, " CPU clock frequency in MHz:\n" 700 " mean=%.0f min=%.0f max=%.0f stddev=%.0f\n", 701 kHz.mean()*1e-3, kHz.minimum()*1e-3, kHz.maximum()*1e-3, kHz.stddev()*1e-3); 702 fdprintf(fd, " adjusted CPU load in MHz (i.e. normalized for CPU clock frequency):\n" 703 " mean=%.1f min=%.1f max=%.1f stddev=%.1f\n", 704 loadMHz.mean(), loadMHz.minimum(), loadMHz.maximum(), loadMHz.stddev()); 705#endif 706#endif 707 // The active track mask and track states are updated non-atomically. 708 // So if we relied on isActive to decide whether to display, 709 // then we might display an obsolete track or omit an active track. 710 // Instead we always display all tracks, with an indication 711 // of whether we think the track is active. 712 uint32_t trackMask = mTrackMask; 713 fdprintf(fd, "Fast tracks: kMaxFastTracks=%u activeMask=%#x\n", 714 FastMixerState::kMaxFastTracks, trackMask); 715 fdprintf(fd, "Index Active Full Partial Empty Recent Ready\n"); 716 for (uint32_t i = 0; i < FastMixerState::kMaxFastTracks; ++i, trackMask >>= 1) { 717 bool isActive = trackMask & 1; 718 const FastTrackDump *ftDump = &mTracks[i]; 719 const FastTrackUnderruns& underruns = ftDump->mUnderruns; 720 const char *mostRecent; 721 switch (underruns.mBitFields.mMostRecent) { 722 case UNDERRUN_FULL: 723 mostRecent = "full"; 724 break; 725 case UNDERRUN_PARTIAL: 726 mostRecent = "partial"; 727 break; 728 case UNDERRUN_EMPTY: 729 mostRecent = "empty"; 730 break; 731 default: 732 mostRecent = "?"; 733 break; 734 } 735 fdprintf(fd, "%5u %6s %4u %7u %5u %7s %5u\n", i, isActive ? "yes" : "no", 736 (underruns.mBitFields.mFull) & UNDERRUN_MASK, 737 (underruns.mBitFields.mPartial) & UNDERRUN_MASK, 738 (underruns.mBitFields.mEmpty) & UNDERRUN_MASK, 739 mostRecent, ftDump->mFramesReady); 740 } 741} 742 743} // namespace android 744