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