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