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