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