1 /*
2 * Copyright (C) 2014 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 "FastMixerDumpState"
18 //#define LOG_NDEBUG 0
19
20 #include "Configuration.h"
21 #ifdef FAST_THREAD_STATISTICS
22 #include <audio_utils/Statistics.h>
23 #ifdef CPU_FREQUENCY_STATISTICS
24 #include <cpustats/ThreadCpuUsage.h>
25 #endif
26 #endif
27 #include <utils/Log.h>
28 #include "FastMixerDumpState.h"
29
30 namespace android {
31
32 // helper function called by qsort()
compare_uint32_t(const void * pa,const void * pb)33 static int compare_uint32_t(const void *pa, const void *pb)
34 {
35 const uint32_t a = *(const uint32_t *)pa;
36 const uint32_t b = *(const uint32_t *)pb;
37 if (a < b) {
38 return -1;
39 } else if (a > b) {
40 return 1;
41 } else {
42 return 0;
43 }
44 }
45
dump(int fd) const46 void FastMixerDumpState::dump(int fd) const
47 {
48 if (mCommand == FastMixerState::INITIAL) {
49 dprintf(fd, " FastMixer not initialized\n");
50 return;
51 }
52 const double measuredWarmupMs = (mMeasuredWarmupTs.tv_sec * 1000.0) +
53 (mMeasuredWarmupTs.tv_nsec / 1000000.0);
54 const double mixPeriodSec = (double) mFrameCount / mSampleRate;
55 dprintf(fd, " FastMixer command=%s writeSequence=%u framesWritten=%u\n"
56 " numTracks=%u writeErrors=%u underruns=%u overruns=%u\n"
57 " sampleRate=%u frameCount=%zu measuredWarmup=%.3g ms, warmupCycles=%u\n"
58 " mixPeriod=%.2f ms latency=%.2f ms\n",
59 FastMixerState::commandToString(mCommand), mWriteSequence, mFramesWritten,
60 mNumTracks, mWriteErrors, mUnderruns, mOverruns,
61 mSampleRate, mFrameCount, measuredWarmupMs, mWarmupCycles,
62 mixPeriodSec * 1e3, mLatencyMs);
63 dprintf(fd, " FastMixer Timestamp stats: %s\n", mTimestampVerifier.toString().c_str());
64 #ifdef FAST_THREAD_STATISTICS
65 // find the interval of valid samples
66 const uint32_t bounds = mBounds;
67 const uint32_t newestOpen = bounds & 0xFFFF;
68 uint32_t oldestClosed = bounds >> 16;
69
70 //uint32_t n = (newestOpen - oldestClosed) & 0xFFFF;
71 uint32_t n;
72 __builtin_sub_overflow(newestOpen, oldestClosed, &n);
73 n &= 0xFFFF;
74
75 if (n > mSamplingN) {
76 ALOGE("too many samples %u", n);
77 n = mSamplingN;
78 }
79 // statistics for monotonic (wall clock) time, thread raw CPU load in time, CPU clock frequency,
80 // and adjusted CPU load in MHz normalized for CPU clock frequency
81 audio_utils::Statistics<double> wall, loadNs;
82 #ifdef CPU_FREQUENCY_STATISTICS
83 audio_utils::Statistics<double> kHz, loadMHz;
84 uint32_t previousCpukHz = 0;
85 #endif
86 // Assuming a normal distribution for cycle times, three standard deviations on either side of
87 // the mean account for 99.73% of the population. So if we take each tail to be 1/1000 of the
88 // sample set, we get 99.8% combined, or close to three standard deviations.
89 static const uint32_t kTailDenominator = 1000;
90 uint32_t *tail = n >= kTailDenominator ? new uint32_t[n] : nullptr;
91 // loop over all the samples
92 for (uint32_t j = 0; j < n; ++j) {
93 const size_t i = oldestClosed++ & (mSamplingN - 1);
94 const uint32_t wallNs = mMonotonicNs[i];
95 if (tail != nullptr) {
96 tail[j] = wallNs;
97 }
98 wall.add(wallNs);
99 const uint32_t sampleLoadNs = mLoadNs[i];
100 loadNs.add(sampleLoadNs);
101 #ifdef CPU_FREQUENCY_STATISTICS
102 uint32_t sampleCpukHz = mCpukHz[i];
103 // skip bad kHz samples
104 if ((sampleCpukHz & ~0xF) != 0) {
105 kHz.add(sampleCpukHz >> 4);
106 if (sampleCpukHz == previousCpukHz) {
107 double megacycles = (double) sampleLoadNs * (double) (sampleCpukHz >> 4) * 1e-12;
108 double adjMHz = megacycles / mixPeriodSec; // _not_ wallNs * 1e9
109 loadMHz.add(adjMHz);
110 }
111 }
112 previousCpukHz = sampleCpukHz;
113 #endif
114 }
115 if (n) {
116 dprintf(fd, " Simple moving statistics over last %.1f seconds:\n",
117 wall.getN() * mixPeriodSec);
118 dprintf(fd, " wall clock time in ms per mix cycle:\n"
119 " mean=%.2f min=%.2f max=%.2f stddev=%.2f\n",
120 wall.getMean()*1e-6, wall.getMin()*1e-6, wall.getMax()*1e-6,
121 wall.getStdDev()*1e-6);
122 dprintf(fd, " raw CPU load in us per mix cycle:\n"
123 " mean=%.0f min=%.0f max=%.0f stddev=%.0f\n",
124 loadNs.getMean()*1e-3, loadNs.getMin()*1e-3, loadNs.getMax()*1e-3,
125 loadNs.getStdDev()*1e-3);
126 } else {
127 dprintf(fd, " No FastMixer statistics available currently\n");
128 }
129 #ifdef CPU_FREQUENCY_STATISTICS
130 dprintf(fd, " CPU clock frequency in MHz:\n"
131 " mean=%.0f min=%.0f max=%.0f stddev=%.0f\n",
132 kHz.getMean()*1e-3, kHz.getMin()*1e-3, kHz.getMax()*1e-3, kHz.getStdDev()*1e-3);
133 dprintf(fd, " adjusted CPU load in MHz (i.e. normalized for CPU clock frequency):\n"
134 " mean=%.1f min=%.1f max=%.1f stddev=%.1f\n",
135 loadMHz.getMean(), loadMHz.getMin(), loadMHz.getMax(), loadMHz.getStdDev());
136 #endif
137 if (tail != nullptr) {
138 qsort(tail, n, sizeof(uint32_t), compare_uint32_t);
139 // assume same number of tail samples on each side, left and right
140 const uint32_t count = n / kTailDenominator;
141 audio_utils::Statistics<double> left, right;
142 for (uint32_t i = 0; i < count; ++i) {
143 left.add(tail[i]);
144 right.add(tail[n - (i + 1)]);
145 }
146 dprintf(fd, " Distribution of mix cycle times in ms for the tails "
147 "(> ~3 stddev outliers):\n"
148 " left tail: mean=%.2f min=%.2f max=%.2f stddev=%.2f\n"
149 " right tail: mean=%.2f min=%.2f max=%.2f stddev=%.2f\n",
150 left.getMean()*1e-6, left.getMin()*1e-6, left.getMax()*1e-6, left.getStdDev()*1e-6,
151 right.getMean()*1e-6, right.getMin()*1e-6, right.getMax()*1e-6,
152 right.getStdDev()*1e-6);
153 delete[] tail;
154 }
155 #endif
156 // The active track mask and track states are updated non-atomically.
157 // So if we relied on isActive to decide whether to display,
158 // then we might display an obsolete track or omit an active track.
159 // Instead we always display all tracks, with an indication
160 // of whether we think the track is active.
161 uint32_t trackMask = mTrackMask;
162 dprintf(fd, " Fast tracks: sMaxFastTracks=%u activeMask=%#x\n",
163 FastMixerState::sMaxFastTracks, trackMask);
164 dprintf(fd, " Index Active Full Partial Empty Recent Ready Written\n");
165 for (uint32_t i = 0; i < FastMixerState::sMaxFastTracks; ++i, trackMask >>= 1) {
166 const bool isActive = trackMask & 1;
167 const FastTrackDump *ftDump = &mTracks[i];
168 const FastTrackUnderruns& underruns = ftDump->mUnderruns;
169 const char *mostRecent;
170 switch (underruns.mBitFields.mMostRecent) {
171 case UNDERRUN_FULL:
172 mostRecent = "full";
173 break;
174 case UNDERRUN_PARTIAL:
175 mostRecent = "partial";
176 break;
177 case UNDERRUN_EMPTY:
178 mostRecent = "empty";
179 break;
180 default:
181 mostRecent = "?";
182 break;
183 }
184 dprintf(fd, " %5u %6s %4u %7u %5u %7s %5zu %10lld\n",
185 i, isActive ? "yes" : "no",
186 (underruns.mBitFields.mFull) & UNDERRUN_MASK,
187 (underruns.mBitFields.mPartial) & UNDERRUN_MASK,
188 (underruns.mBitFields.mEmpty) & UNDERRUN_MASK,
189 mostRecent, ftDump->mFramesReady,
190 (long long)ftDump->mFramesWritten);
191 }
192 }
193
194 } // namespace android
195