Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 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> |
Glenn Kasten | d8e6fd3 | 2012-05-07 11:07:57 -0700 | [diff] [blame] | 23 | #include <utils/Trace.h> |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 24 | #include <system/audio.h> |
| 25 | #ifdef FAST_MIXER_STATISTICS |
| 26 | #include <cpustats/CentralTendencyStatistics.h> |
Glenn Kasten | 0a14c4c | 2012-06-13 14:58:49 -0700 | [diff] [blame] | 27 | #ifdef CPU_FREQUENCY_STATISTICS |
Glenn Kasten | 42d45cf | 2012-05-02 10:34:47 -0700 | [diff] [blame] | 28 | #include <cpustats/ThreadCpuUsage.h> |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 29 | #endif |
Glenn Kasten | 0a14c4c | 2012-06-13 14:58:49 -0700 | [diff] [blame] | 30 | #endif |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 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 |
Glenn Kasten | eb15716 | 2012-06-13 14:59:07 -0700 | [diff] [blame] | 36 | #define MIN_WARMUP_CYCLES 2 // minimum number of loop cycles to wait for warmup |
Glenn Kasten | 288ed21 | 2012-04-25 17:52:27 -0700 | [diff] [blame] | 37 | #define MAX_WARMUP_CYCLES 10 // maximum number of loop cycles to wait for warmup |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 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 |
Glenn Kasten | 288ed21 | 2012-04-25 17:52:27 -0700 | [diff] [blame] | 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 |
Glenn Kasten | 972af22 | 2012-06-13 17:14:03 -0700 | [diff] [blame] | 69 | long forceNs = 0; // if overrun detected, force the write cycle to take this much time |
Glenn Kasten | 288ed21 | 2012-04-25 17:52:27 -0700 | [diff] [blame] | 70 | long warmupNs = 0; // warmup complete when write cycle is greater than to this value |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 71 | FastMixerDumpState dummyDumpState, *dumpState = &dummyDumpState; |
| 72 | bool ignoreNextOverrun = true; // used to ignore initial overrun and first after an underrun |
| 73 | #ifdef FAST_MIXER_STATISTICS |
Glenn Kasten | 42d45cf | 2012-05-02 10:34:47 -0700 | [diff] [blame] | 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 |
Glenn Kasten | 0a14c4c | 2012-06-13 14:58:49 -0700 | [diff] [blame] | 78 | #ifdef CPU_FREQUENCY_STATISTICS |
Glenn Kasten | 42d45cf | 2012-05-02 10:34:47 -0700 | [diff] [blame] | 79 | ThreadCpuUsage tcu; // for reading the current CPU clock frequency in kHz |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 80 | #endif |
Glenn Kasten | 0a14c4c | 2012-06-13 14:58:49 -0700 | [diff] [blame] | 81 | #endif |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 82 | unsigned coldGen = 0; // last observed mColdGen |
Glenn Kasten | 288ed21 | 2012-04-25 17:52:27 -0700 | [diff] [blame] | 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 |
Glenn Kasten | fbae5da | 2012-05-21 09:17:20 -0700 | [diff] [blame] | 86 | NBAIO_Sink* teeSink = NULL; // if non-NULL, then duplicate write() to this non-blocking sink |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 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; |
Glenn Kasten | fbae5da | 2012-05-21 09:17:20 -0700 | [diff] [blame] | 116 | teeSink = next->mTeeSink; |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 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; |
Glenn Kasten | 42d45cf | 2012-05-02 10:34:47 -0700 | [diff] [blame] | 132 | oldLoadValid = false; |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 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 |
Glenn Kasten | 21e8c50 | 2012-04-12 09:39:42 -0700 | [diff] [blame] | 152 | // FIXME consider checking previous state and only perform if previous != COLD_IDLE |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 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 | } |
Glenn Kasten | 288ed21 | 2012-04-25 17:52:27 -0700 | [diff] [blame] | 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; |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 166 | sleepNs = -1; |
| 167 | coldGen = current->mColdGen; |
Glenn Kasten | 42d45cf | 2012-05-02 10:34:47 -0700 | [diff] [blame] | 168 | bounds = 0; |
| 169 | full = false; |
Glenn Kasten | 04a4ca4 | 2012-06-01 10:49:51 -0700 | [diff] [blame] | 170 | oldTsValid = !clock_gettime(CLOCK_MONOTONIC, &oldTs); |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 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 | } |
Glenn Kasten | 21e8c50 | 2012-04-12 09:39:42 -0700 | [diff] [blame] | 208 | dumpState->mSampleRate = sampleRate; |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 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 |
Glenn Kasten | 0d27c65 | 2012-08-07 10:38:59 -0700 | [diff] [blame^] | 225 | overrunNs = (frameCount * 500000000LL) / sampleRate; // 0.50 |
| 226 | forceNs = (frameCount * 950000000LL) / sampleRate; // 0.95 |
Glenn Kasten | 288ed21 | 2012-04-25 17:52:27 -0700 | [diff] [blame] | 227 | warmupNs = (frameCount * 500000000LL) / sampleRate; // 0.50 |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 228 | } else { |
| 229 | periodNs = 0; |
| 230 | underrunNs = 0; |
| 231 | overrunNs = 0; |
Glenn Kasten | 972af22 | 2012-06-13 17:14:03 -0700 | [diff] [blame] | 232 | forceNs = 0; |
| 233 | warmupNs = 0; |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 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; |
Glenn Kasten | 21e8c50 | 2012-04-12 09:39:42 -0700 | [diff] [blame] | 244 | dumpState->mFrameCount = frameCount; |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 245 | } else { |
| 246 | previousTrackMask = previous->mTrackMask; |
| 247 | } |
| 248 | |
| 249 | // check for change in active track set |
| 250 | unsigned currentTrackMask = current->mTrackMask; |
Glenn Kasten | 1295bb4d | 2012-05-31 07:43:43 -0700 | [diff] [blame] | 251 | dumpState->mTrackMask = currentTrackMask; |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 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 = ¤t->mFastTracks[i]; |
Glenn Kasten | 288ed21 | 2012-04-25 17:52:27 -0700 | [diff] [blame] | 262 | ALOG_ASSERT(fastTrack->mBufferProvider == NULL); |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 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 |
Glenn Kasten | 288ed21 | 2012-04-25 17:52:27 -0700 | [diff] [blame] | 271 | // don't reset track dump state, since other side is ignoring it |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 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 = ¤t->mFastTracks[i]; |
| 281 | AudioBufferProvider *bufferProvider = fastTrack->mBufferProvider; |
| 282 | ALOG_ASSERT(bufferProvider != NULL && fastTrackNames[i] == -1); |
| 283 | if (mixer != NULL) { |
Jean-Michel Trivi | 9bd2322 | 2012-04-16 13:43:48 -0700 | [diff] [blame] | 284 | // calling getTrackName with default channel mask |
| 285 | name = mixer->getTrackName(AUDIO_CHANNEL_OUT_STEREO); |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 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 |
Glenn Kasten | 21e8c50 | 2012-04-12 09:39:42 -0700 | [diff] [blame] | 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); |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 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 = ¤t->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 | } |
Glenn Kasten | 21e8c50 | 2012-04-12 09:39:42 -0700 | [diff] [blame] | 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); |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 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 |
Glenn Kasten | 288ed21 | 2012-04-25 17:52:27 -0700 | [diff] [blame] | 351 | if ((command & FastMixerState::MIX) && (mixer != NULL) && isWarm) { |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 352 | ALOG_ASSERT(mixBuffer != NULL); |
Glenn Kasten | 288ed21 | 2012-04-25 17:52:27 -0700 | [diff] [blame] | 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); |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 358 | const FastTrack* fastTrack = ¤t->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 | } |
Glenn Kasten | 288ed21 | 2012-04-25 17:52:27 -0700 | [diff] [blame] | 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(); |
Glenn Kasten | 99c99d0 | 2012-05-14 16:37:13 -0700 | [diff] [blame] | 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 |
Glenn Kasten | 288ed21 | 2012-04-25 17:52:27 -0700 | [diff] [blame] | 381 | FastTrackDump *ftDump = &dumpState->mTracks[i]; |
Glenn Kasten | 09474df | 2012-05-10 14:48:07 -0700 | [diff] [blame] | 382 | FastTrackUnderruns underruns = ftDump->mUnderruns; |
Glenn Kasten | 288ed21 | 2012-04-25 17:52:27 -0700 | [diff] [blame] | 383 | if (framesReady < frameCount) { |
Glenn Kasten | 288ed21 | 2012-04-25 17:52:27 -0700 | [diff] [blame] | 384 | if (framesReady == 0) { |
Glenn Kasten | 09474df | 2012-05-10 14:48:07 -0700 | [diff] [blame] | 385 | underruns.mBitFields.mEmpty++; |
| 386 | underruns.mBitFields.mMostRecent = UNDERRUN_EMPTY; |
Glenn Kasten | 288ed21 | 2012-04-25 17:52:27 -0700 | [diff] [blame] | 387 | mixer->disable(name); |
| 388 | } else { |
| 389 | // allow mixing partial buffer |
Glenn Kasten | 09474df | 2012-05-10 14:48:07 -0700 | [diff] [blame] | 390 | underruns.mBitFields.mPartial++; |
| 391 | underruns.mBitFields.mMostRecent = UNDERRUN_PARTIAL; |
Glenn Kasten | 288ed21 | 2012-04-25 17:52:27 -0700 | [diff] [blame] | 392 | mixer->enable(name); |
| 393 | } |
Glenn Kasten | 09474df | 2012-05-10 14:48:07 -0700 | [diff] [blame] | 394 | } else { |
| 395 | underruns.mBitFields.mFull++; |
| 396 | underruns.mBitFields.mMostRecent = UNDERRUN_FULL; |
Glenn Kasten | 288ed21 | 2012-04-25 17:52:27 -0700 | [diff] [blame] | 397 | mixer->enable(name); |
| 398 | } |
Glenn Kasten | 09474df | 2012-05-10 14:48:07 -0700 | [diff] [blame] | 399 | ftDump->mUnderruns = underruns; |
Glenn Kasten | 1295bb4d | 2012-05-31 07:43:43 -0700 | [diff] [blame] | 400 | ftDump->mFramesReady = framesReady; |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 401 | } |
John Grossman | 2c3b2da | 2012-08-02 17:08:54 -0700 | [diff] [blame] | 402 | |
| 403 | int64_t pts; |
| 404 | if (outputSink == NULL || (OK != outputSink->getNextWriteTimestamp(&pts))) |
| 405 | pts = AudioBufferProvider::kInvalidPTS; |
| 406 | |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 407 | // process() is CPU-bound |
John Grossman | 2c3b2da | 2012-08-02 17:08:54 -0700 | [diff] [blame] | 408 | mixer->process(pts); |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 409 | mixBufferState = MIXED; |
| 410 | } else if (mixBufferState == MIXED) { |
| 411 | mixBufferState = UNDEFINED; |
| 412 | } |
Glenn Kasten | 288ed21 | 2012-04-25 17:52:27 -0700 | [diff] [blame] | 413 | bool attemptedWrite = false; |
| 414 | //bool didFullWrite = false; // dumpsys could display a count of partial writes |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 415 | if ((command & FastMixerState::WRITE) && (outputSink != NULL) && (mixBuffer != NULL)) { |
| 416 | if (mixBufferState == UNDEFINED) { |
| 417 | memset(mixBuffer, 0, frameCount * 2 * sizeof(short)); |
| 418 | mixBufferState = ZEROED; |
| 419 | } |
Glenn Kasten | fbae5da | 2012-05-21 09:17:20 -0700 | [diff] [blame] | 420 | if (teeSink != NULL) { |
| 421 | (void) teeSink->write(mixBuffer, frameCount); |
| 422 | } |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 423 | // FIXME write() is non-blocking and lock-free for a properly implemented NBAIO sink, |
| 424 | // but this code should be modified to handle both non-blocking and blocking sinks |
| 425 | dumpState->mWriteSequence++; |
Glenn Kasten | 99c99d0 | 2012-05-14 16:37:13 -0700 | [diff] [blame] | 426 | #if defined(ATRACE_TAG) && (ATRACE_TAG != ATRACE_TAG_NEVER) |
Glenn Kasten | d8e6fd3 | 2012-05-07 11:07:57 -0700 | [diff] [blame] | 427 | Tracer::traceBegin(ATRACE_TAG, "write"); |
Glenn Kasten | 99c99d0 | 2012-05-14 16:37:13 -0700 | [diff] [blame] | 428 | #endif |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 429 | ssize_t framesWritten = outputSink->write(mixBuffer, frameCount); |
Glenn Kasten | 99c99d0 | 2012-05-14 16:37:13 -0700 | [diff] [blame] | 430 | #if defined(ATRACE_TAG) && (ATRACE_TAG != ATRACE_TAG_NEVER) |
Glenn Kasten | d8e6fd3 | 2012-05-07 11:07:57 -0700 | [diff] [blame] | 431 | Tracer::traceEnd(ATRACE_TAG); |
Glenn Kasten | 99c99d0 | 2012-05-14 16:37:13 -0700 | [diff] [blame] | 432 | #endif |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 433 | dumpState->mWriteSequence++; |
| 434 | if (framesWritten >= 0) { |
Glenn Kasten | 288ed21 | 2012-04-25 17:52:27 -0700 | [diff] [blame] | 435 | ALOG_ASSERT(framesWritten <= frameCount); |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 436 | dumpState->mFramesWritten += framesWritten; |
Glenn Kasten | 288ed21 | 2012-04-25 17:52:27 -0700 | [diff] [blame] | 437 | //if ((size_t) framesWritten == frameCount) { |
| 438 | // didFullWrite = true; |
| 439 | //} |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 440 | } else { |
| 441 | dumpState->mWriteErrors++; |
| 442 | } |
Glenn Kasten | 288ed21 | 2012-04-25 17:52:27 -0700 | [diff] [blame] | 443 | attemptedWrite = true; |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 444 | // FIXME count # of writes blocked excessively, CPU usage, etc. for dump |
| 445 | } |
| 446 | |
| 447 | // To be exactly periodic, compute the next sleep time based on current time. |
| 448 | // This code doesn't have long-term stability when the sink is non-blocking. |
| 449 | // FIXME To avoid drift, use the local audio clock or watch the sink's fill status. |
| 450 | struct timespec newTs; |
| 451 | int rc = clock_gettime(CLOCK_MONOTONIC, &newTs); |
| 452 | if (rc == 0) { |
| 453 | if (oldTsValid) { |
| 454 | time_t sec = newTs.tv_sec - oldTs.tv_sec; |
| 455 | long nsec = newTs.tv_nsec - oldTs.tv_nsec; |
| 456 | if (nsec < 0) { |
| 457 | --sec; |
| 458 | nsec += 1000000000; |
| 459 | } |
Glenn Kasten | 288ed21 | 2012-04-25 17:52:27 -0700 | [diff] [blame] | 460 | // To avoid an initial underrun on fast tracks after exiting standby, |
| 461 | // do not start pulling data from tracks and mixing until warmup is complete. |
| 462 | // Warmup is considered complete after the earlier of: |
Glenn Kasten | eb15716 | 2012-06-13 14:59:07 -0700 | [diff] [blame] | 463 | // MIN_WARMUP_CYCLES write() attempts and last one blocks for at least warmupNs |
Glenn Kasten | 288ed21 | 2012-04-25 17:52:27 -0700 | [diff] [blame] | 464 | // MAX_WARMUP_CYCLES write() attempts. |
| 465 | // This is overly conservative, but to get better accuracy requires a new HAL API. |
| 466 | if (!isWarm && attemptedWrite) { |
| 467 | measuredWarmupTs.tv_sec += sec; |
| 468 | measuredWarmupTs.tv_nsec += nsec; |
| 469 | if (measuredWarmupTs.tv_nsec >= 1000000000) { |
| 470 | measuredWarmupTs.tv_sec++; |
| 471 | measuredWarmupTs.tv_nsec -= 1000000000; |
| 472 | } |
| 473 | ++warmupCycles; |
Glenn Kasten | eb15716 | 2012-06-13 14:59:07 -0700 | [diff] [blame] | 474 | if ((nsec > warmupNs && warmupCycles >= MIN_WARMUP_CYCLES) || |
Glenn Kasten | 288ed21 | 2012-04-25 17:52:27 -0700 | [diff] [blame] | 475 | (warmupCycles >= MAX_WARMUP_CYCLES)) { |
| 476 | isWarm = true; |
| 477 | dumpState->mMeasuredWarmupTs = measuredWarmupTs; |
| 478 | dumpState->mWarmupCycles = warmupCycles; |
| 479 | } |
| 480 | } |
Glenn Kasten | 972af22 | 2012-06-13 17:14:03 -0700 | [diff] [blame] | 481 | sleepNs = -1; |
| 482 | if (isWarm) { |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 483 | if (sec > 0 || nsec > underrunNs) { |
Glenn Kasten | 99c99d0 | 2012-05-14 16:37:13 -0700 | [diff] [blame] | 484 | #if defined(ATRACE_TAG) && (ATRACE_TAG != ATRACE_TAG_NEVER) |
Glenn Kasten | d8e6fd3 | 2012-05-07 11:07:57 -0700 | [diff] [blame] | 485 | ScopedTrace st(ATRACE_TAG, "underrun"); |
Glenn Kasten | 99c99d0 | 2012-05-14 16:37:13 -0700 | [diff] [blame] | 486 | #endif |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 487 | // FIXME only log occasionally |
| 488 | ALOGV("underrun: time since last cycle %d.%03ld sec", |
| 489 | (int) sec, nsec / 1000000L); |
| 490 | dumpState->mUnderruns++; |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 491 | ignoreNextOverrun = true; |
| 492 | } else if (nsec < overrunNs) { |
| 493 | if (ignoreNextOverrun) { |
| 494 | ignoreNextOverrun = false; |
| 495 | } else { |
| 496 | // FIXME only log occasionally |
| 497 | ALOGV("overrun: time since last cycle %d.%03ld sec", |
| 498 | (int) sec, nsec / 1000000L); |
| 499 | dumpState->mOverruns++; |
| 500 | } |
Glenn Kasten | 972af22 | 2012-06-13 17:14:03 -0700 | [diff] [blame] | 501 | // This forces a minimum cycle time. It: |
| 502 | // - compensates for an audio HAL with jitter due to sample rate conversion |
| 503 | // - works with a variable buffer depth audio HAL that never pulls at a rate |
| 504 | // < than overrunNs per buffer. |
| 505 | // - recovers from overrun immediately after underrun |
| 506 | // It doesn't work with a non-blocking audio HAL. |
| 507 | sleepNs = forceNs - nsec; |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 508 | } else { |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 509 | ignoreNextOverrun = false; |
| 510 | } |
Glenn Kasten | 972af22 | 2012-06-13 17:14:03 -0700 | [diff] [blame] | 511 | } |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 512 | #ifdef FAST_MIXER_STATISTICS |
Glenn Kasten | eb15716 | 2012-06-13 14:59:07 -0700 | [diff] [blame] | 513 | if (isWarm) { |
Glenn Kasten | 42d45cf | 2012-05-02 10:34:47 -0700 | [diff] [blame] | 514 | // advance the FIFO queue bounds |
| 515 | size_t i = bounds & (FastMixerDumpState::kSamplingN - 1); |
Glenn Kasten | e58ccce | 2012-05-11 15:19:24 -0700 | [diff] [blame] | 516 | bounds = (bounds & 0xFFFF0000) | ((bounds + 1) & 0xFFFF); |
Glenn Kasten | 42d45cf | 2012-05-02 10:34:47 -0700 | [diff] [blame] | 517 | if (full) { |
| 518 | bounds += 0x10000; |
| 519 | } else if (!(bounds & (FastMixerDumpState::kSamplingN - 1))) { |
| 520 | full = true; |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 521 | } |
Glenn Kasten | 42d45cf | 2012-05-02 10:34:47 -0700 | [diff] [blame] | 522 | // compute the delta value of clock_gettime(CLOCK_MONOTONIC) |
| 523 | uint32_t monotonicNs = nsec; |
| 524 | if (sec > 0 && sec < 4) { |
| 525 | monotonicNs += sec * 1000000000; |
| 526 | } |
| 527 | // compute the raw CPU load = delta value of clock_gettime(CLOCK_THREAD_CPUTIME_ID) |
| 528 | uint32_t loadNs = 0; |
| 529 | struct timespec newLoad; |
| 530 | rc = clock_gettime(CLOCK_THREAD_CPUTIME_ID, &newLoad); |
| 531 | if (rc == 0) { |
| 532 | if (oldLoadValid) { |
| 533 | sec = newLoad.tv_sec - oldLoad.tv_sec; |
| 534 | nsec = newLoad.tv_nsec - oldLoad.tv_nsec; |
| 535 | if (nsec < 0) { |
| 536 | --sec; |
| 537 | nsec += 1000000000; |
| 538 | } |
| 539 | loadNs = nsec; |
| 540 | if (sec > 0 && sec < 4) { |
| 541 | loadNs += sec * 1000000000; |
| 542 | } |
| 543 | } else { |
| 544 | // first time through the loop |
| 545 | oldLoadValid = true; |
| 546 | } |
| 547 | oldLoad = newLoad; |
| 548 | } |
Glenn Kasten | 0a14c4c | 2012-06-13 14:58:49 -0700 | [diff] [blame] | 549 | #ifdef CPU_FREQUENCY_STATISTICS |
Glenn Kasten | 42d45cf | 2012-05-02 10:34:47 -0700 | [diff] [blame] | 550 | // get the absolute value of CPU clock frequency in kHz |
| 551 | int cpuNum = sched_getcpu(); |
| 552 | uint32_t kHz = tcu.getCpukHz(cpuNum); |
Glenn Kasten | c059bd4 | 2012-05-14 17:41:09 -0700 | [diff] [blame] | 553 | kHz = (kHz << 4) | (cpuNum & 0xF); |
Glenn Kasten | 0a14c4c | 2012-06-13 14:58:49 -0700 | [diff] [blame] | 554 | #endif |
Glenn Kasten | 42d45cf | 2012-05-02 10:34:47 -0700 | [diff] [blame] | 555 | // save values in FIFO queues for dumpsys |
| 556 | // these stores #1, #2, #3 are not atomic with respect to each other, |
| 557 | // or with respect to store #4 below |
| 558 | dumpState->mMonotonicNs[i] = monotonicNs; |
| 559 | dumpState->mLoadNs[i] = loadNs; |
Glenn Kasten | 0a14c4c | 2012-06-13 14:58:49 -0700 | [diff] [blame] | 560 | #ifdef CPU_FREQUENCY_STATISTICS |
Glenn Kasten | 42d45cf | 2012-05-02 10:34:47 -0700 | [diff] [blame] | 561 | dumpState->mCpukHz[i] = kHz; |
Glenn Kasten | 0a14c4c | 2012-06-13 14:58:49 -0700 | [diff] [blame] | 562 | #endif |
Glenn Kasten | 42d45cf | 2012-05-02 10:34:47 -0700 | [diff] [blame] | 563 | // this store #4 is not atomic with respect to stores #1, #2, #3 above, but |
| 564 | // the newest open and oldest closed halves are atomic with respect to each other |
| 565 | dumpState->mBounds = bounds; |
Glenn Kasten | 99c99d0 | 2012-05-14 16:37:13 -0700 | [diff] [blame] | 566 | #if defined(ATRACE_TAG) && (ATRACE_TAG != ATRACE_TAG_NEVER) |
| 567 | ATRACE_INT("cycle_ms", monotonicNs / 1000000); |
| 568 | ATRACE_INT("load_us", loadNs / 1000); |
| 569 | #endif |
Glenn Kasten | eb15716 | 2012-06-13 14:59:07 -0700 | [diff] [blame] | 570 | } |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 571 | #endif |
| 572 | } else { |
| 573 | // first time through the loop |
| 574 | oldTsValid = true; |
| 575 | sleepNs = periodNs; |
| 576 | ignoreNextOverrun = true; |
| 577 | } |
| 578 | oldTs = newTs; |
| 579 | } else { |
| 580 | // monotonic clock is broken |
| 581 | oldTsValid = false; |
| 582 | sleepNs = periodNs; |
| 583 | } |
| 584 | |
Glenn Kasten | 42d45cf | 2012-05-02 10:34:47 -0700 | [diff] [blame] | 585 | |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 586 | } // for (;;) |
| 587 | |
| 588 | // never return 'true'; Thread::_threadLoop() locks mutex which can result in priority inversion |
| 589 | } |
| 590 | |
| 591 | FastMixerDumpState::FastMixerDumpState() : |
| 592 | mCommand(FastMixerState::INITIAL), mWriteSequence(0), mFramesWritten(0), |
Glenn Kasten | 21e8c50 | 2012-04-12 09:39:42 -0700 | [diff] [blame] | 593 | mNumTracks(0), mWriteErrors(0), mUnderruns(0), mOverruns(0), |
Glenn Kasten | 1295bb4d | 2012-05-31 07:43:43 -0700 | [diff] [blame] | 594 | mSampleRate(0), mFrameCount(0), /* mMeasuredWarmupTs({0, 0}), */ mWarmupCycles(0), |
| 595 | mTrackMask(0) |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 596 | #ifdef FAST_MIXER_STATISTICS |
Glenn Kasten | 42d45cf | 2012-05-02 10:34:47 -0700 | [diff] [blame] | 597 | , mBounds(0) |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 598 | #endif |
| 599 | { |
Glenn Kasten | 288ed21 | 2012-04-25 17:52:27 -0700 | [diff] [blame] | 600 | mMeasuredWarmupTs.tv_sec = 0; |
| 601 | mMeasuredWarmupTs.tv_nsec = 0; |
Glenn Kasten | 42d45cf | 2012-05-02 10:34:47 -0700 | [diff] [blame] | 602 | // sample arrays aren't accessed atomically with respect to the bounds, |
| 603 | // so clearing reduces chance for dumpsys to read random uninitialized samples |
| 604 | memset(&mMonotonicNs, 0, sizeof(mMonotonicNs)); |
| 605 | memset(&mLoadNs, 0, sizeof(mLoadNs)); |
Glenn Kasten | 0a14c4c | 2012-06-13 14:58:49 -0700 | [diff] [blame] | 606 | #ifdef CPU_FREQUENCY_STATISTICS |
Glenn Kasten | 42d45cf | 2012-05-02 10:34:47 -0700 | [diff] [blame] | 607 | memset(&mCpukHz, 0, sizeof(mCpukHz)); |
Glenn Kasten | 0a14c4c | 2012-06-13 14:58:49 -0700 | [diff] [blame] | 608 | #endif |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 609 | } |
| 610 | |
| 611 | FastMixerDumpState::~FastMixerDumpState() |
| 612 | { |
| 613 | } |
| 614 | |
| 615 | void FastMixerDumpState::dump(int fd) |
| 616 | { |
Glenn Kasten | 868c0ab | 2012-06-13 14:59:17 -0700 | [diff] [blame] | 617 | if (mCommand == FastMixerState::INITIAL) { |
| 618 | fdprintf(fd, "FastMixer not initialized\n"); |
| 619 | return; |
| 620 | } |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 621 | #define COMMAND_MAX 32 |
| 622 | char string[COMMAND_MAX]; |
| 623 | switch (mCommand) { |
| 624 | case FastMixerState::INITIAL: |
| 625 | strcpy(string, "INITIAL"); |
| 626 | break; |
| 627 | case FastMixerState::HOT_IDLE: |
| 628 | strcpy(string, "HOT_IDLE"); |
| 629 | break; |
| 630 | case FastMixerState::COLD_IDLE: |
| 631 | strcpy(string, "COLD_IDLE"); |
| 632 | break; |
| 633 | case FastMixerState::EXIT: |
| 634 | strcpy(string, "EXIT"); |
| 635 | break; |
| 636 | case FastMixerState::MIX: |
| 637 | strcpy(string, "MIX"); |
| 638 | break; |
| 639 | case FastMixerState::WRITE: |
| 640 | strcpy(string, "WRITE"); |
| 641 | break; |
| 642 | case FastMixerState::MIX_WRITE: |
| 643 | strcpy(string, "MIX_WRITE"); |
| 644 | break; |
| 645 | default: |
| 646 | snprintf(string, COMMAND_MAX, "%d", mCommand); |
| 647 | break; |
| 648 | } |
Glenn Kasten | 42d45cf | 2012-05-02 10:34:47 -0700 | [diff] [blame] | 649 | double measuredWarmupMs = (mMeasuredWarmupTs.tv_sec * 1000.0) + |
Glenn Kasten | 288ed21 | 2012-04-25 17:52:27 -0700 | [diff] [blame] | 650 | (mMeasuredWarmupTs.tv_nsec / 1000000.0); |
Glenn Kasten | 42d45cf | 2012-05-02 10:34:47 -0700 | [diff] [blame] | 651 | double mixPeriodSec = (double) mFrameCount / (double) mSampleRate; |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 652 | fdprintf(fd, "FastMixer command=%s writeSequence=%u framesWritten=%u\n" |
Glenn Kasten | 21e8c50 | 2012-04-12 09:39:42 -0700 | [diff] [blame] | 653 | " numTracks=%u writeErrors=%u underruns=%u overruns=%u\n" |
Glenn Kasten | 42d45cf | 2012-05-02 10:34:47 -0700 | [diff] [blame] | 654 | " sampleRate=%u frameCount=%u measuredWarmup=%.3g ms, warmupCycles=%u\n" |
| 655 | " mixPeriod=%.2f ms\n", |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 656 | string, mWriteSequence, mFramesWritten, |
Glenn Kasten | 21e8c50 | 2012-04-12 09:39:42 -0700 | [diff] [blame] | 657 | mNumTracks, mWriteErrors, mUnderruns, mOverruns, |
Glenn Kasten | 42d45cf | 2012-05-02 10:34:47 -0700 | [diff] [blame] | 658 | mSampleRate, mFrameCount, measuredWarmupMs, mWarmupCycles, |
| 659 | mixPeriodSec * 1e3); |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 660 | #ifdef FAST_MIXER_STATISTICS |
Glenn Kasten | 42d45cf | 2012-05-02 10:34:47 -0700 | [diff] [blame] | 661 | // find the interval of valid samples |
| 662 | uint32_t bounds = mBounds; |
| 663 | uint32_t newestOpen = bounds & 0xFFFF; |
| 664 | uint32_t oldestClosed = bounds >> 16; |
| 665 | uint32_t n = (newestOpen - oldestClosed) & 0xFFFF; |
| 666 | if (n > kSamplingN) { |
| 667 | ALOGE("too many samples %u", n); |
| 668 | n = kSamplingN; |
| 669 | } |
| 670 | // statistics for monotonic (wall clock) time, thread raw CPU load in time, CPU clock frequency, |
| 671 | // and adjusted CPU load in MHz normalized for CPU clock frequency |
Glenn Kasten | 0a14c4c | 2012-06-13 14:58:49 -0700 | [diff] [blame] | 672 | CentralTendencyStatistics wall, loadNs; |
| 673 | #ifdef CPU_FREQUENCY_STATISTICS |
| 674 | CentralTendencyStatistics kHz, loadMHz; |
Glenn Kasten | 42d45cf | 2012-05-02 10:34:47 -0700 | [diff] [blame] | 675 | uint32_t previousCpukHz = 0; |
Glenn Kasten | 0a14c4c | 2012-06-13 14:58:49 -0700 | [diff] [blame] | 676 | #endif |
Glenn Kasten | 42d45cf | 2012-05-02 10:34:47 -0700 | [diff] [blame] | 677 | // loop over all the samples |
| 678 | for (; n > 0; --n) { |
| 679 | size_t i = oldestClosed++ & (kSamplingN - 1); |
| 680 | uint32_t wallNs = mMonotonicNs[i]; |
| 681 | wall.sample(wallNs); |
| 682 | uint32_t sampleLoadNs = mLoadNs[i]; |
Glenn Kasten | 42d45cf | 2012-05-02 10:34:47 -0700 | [diff] [blame] | 683 | loadNs.sample(sampleLoadNs); |
Glenn Kasten | 0a14c4c | 2012-06-13 14:58:49 -0700 | [diff] [blame] | 684 | #ifdef CPU_FREQUENCY_STATISTICS |
| 685 | uint32_t sampleCpukHz = mCpukHz[i]; |
Glenn Kasten | c059bd4 | 2012-05-14 17:41:09 -0700 | [diff] [blame] | 686 | // skip bad kHz samples |
| 687 | if ((sampleCpukHz & ~0xF) != 0) { |
| 688 | kHz.sample(sampleCpukHz >> 4); |
| 689 | if (sampleCpukHz == previousCpukHz) { |
| 690 | double megacycles = (double) sampleLoadNs * (double) (sampleCpukHz >> 4) * 1e-12; |
| 691 | double adjMHz = megacycles / mixPeriodSec; // _not_ wallNs * 1e9 |
| 692 | loadMHz.sample(adjMHz); |
| 693 | } |
Glenn Kasten | 42d45cf | 2012-05-02 10:34:47 -0700 | [diff] [blame] | 694 | } |
| 695 | previousCpukHz = sampleCpukHz; |
Glenn Kasten | 0a14c4c | 2012-06-13 14:58:49 -0700 | [diff] [blame] | 696 | #endif |
Glenn Kasten | 42d45cf | 2012-05-02 10:34:47 -0700 | [diff] [blame] | 697 | } |
| 698 | fdprintf(fd, "Simple moving statistics over last %.1f seconds:\n", wall.n() * mixPeriodSec); |
| 699 | fdprintf(fd, " wall clock time in ms per mix cycle:\n" |
| 700 | " mean=%.2f min=%.2f max=%.2f stddev=%.2f\n", |
| 701 | wall.mean()*1e-6, wall.minimum()*1e-6, wall.maximum()*1e-6, wall.stddev()*1e-6); |
| 702 | fdprintf(fd, " raw CPU load in us per mix cycle:\n" |
| 703 | " mean=%.0f min=%.0f max=%.0f stddev=%.0f\n", |
| 704 | loadNs.mean()*1e-3, loadNs.minimum()*1e-3, loadNs.maximum()*1e-3, |
| 705 | loadNs.stddev()*1e-3); |
Glenn Kasten | 0a14c4c | 2012-06-13 14:58:49 -0700 | [diff] [blame] | 706 | #ifdef CPU_FREQUENCY_STATISTICS |
Glenn Kasten | 42d45cf | 2012-05-02 10:34:47 -0700 | [diff] [blame] | 707 | fdprintf(fd, " CPU clock frequency in MHz:\n" |
| 708 | " mean=%.0f min=%.0f max=%.0f stddev=%.0f\n", |
| 709 | kHz.mean()*1e-3, kHz.minimum()*1e-3, kHz.maximum()*1e-3, kHz.stddev()*1e-3); |
| 710 | fdprintf(fd, " adjusted CPU load in MHz (i.e. normalized for CPU clock frequency):\n" |
| 711 | " mean=%.1f min=%.1f max=%.1f stddev=%.1f\n", |
| 712 | loadMHz.mean(), loadMHz.minimum(), loadMHz.maximum(), loadMHz.stddev()); |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 713 | #endif |
Glenn Kasten | 0a14c4c | 2012-06-13 14:58:49 -0700 | [diff] [blame] | 714 | #endif |
Glenn Kasten | 1295bb4d | 2012-05-31 07:43:43 -0700 | [diff] [blame] | 715 | // The active track mask and track states are updated non-atomically. |
| 716 | // So if we relied on isActive to decide whether to display, |
| 717 | // then we might display an obsolete track or omit an active track. |
| 718 | // Instead we always display all tracks, with an indication |
| 719 | // of whether we think the track is active. |
| 720 | uint32_t trackMask = mTrackMask; |
| 721 | fdprintf(fd, "Fast tracks: kMaxFastTracks=%u activeMask=%#x\n", |
| 722 | FastMixerState::kMaxFastTracks, trackMask); |
| 723 | fdprintf(fd, "Index Active Full Partial Empty Recent Ready\n"); |
| 724 | for (uint32_t i = 0; i < FastMixerState::kMaxFastTracks; ++i, trackMask >>= 1) { |
| 725 | bool isActive = trackMask & 1; |
| 726 | const FastTrackDump *ftDump = &mTracks[i]; |
| 727 | const FastTrackUnderruns& underruns = ftDump->mUnderruns; |
| 728 | const char *mostRecent; |
| 729 | switch (underruns.mBitFields.mMostRecent) { |
| 730 | case UNDERRUN_FULL: |
| 731 | mostRecent = "full"; |
| 732 | break; |
| 733 | case UNDERRUN_PARTIAL: |
| 734 | mostRecent = "partial"; |
| 735 | break; |
| 736 | case UNDERRUN_EMPTY: |
| 737 | mostRecent = "empty"; |
| 738 | break; |
| 739 | default: |
| 740 | mostRecent = "?"; |
| 741 | break; |
| 742 | } |
| 743 | fdprintf(fd, "%5u %6s %4u %7u %5u %7s %5u\n", i, isActive ? "yes" : "no", |
| 744 | (underruns.mBitFields.mFull) & UNDERRUN_MASK, |
| 745 | (underruns.mBitFields.mPartial) & UNDERRUN_MASK, |
| 746 | (underruns.mBitFields.mEmpty) & UNDERRUN_MASK, |
| 747 | mostRecent, ftDump->mFramesReady); |
| 748 | } |
Glenn Kasten | 97b5d0d | 2012-03-23 18:54:19 -0700 | [diff] [blame] | 749 | } |
| 750 | |
| 751 | } // namespace android |