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