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