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