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