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 "FastThread"
18 //#define LOG_NDEBUG 0
19
20 #define ATRACE_TAG ATRACE_TAG_AUDIO
21
22 #include "Configuration.h"
23 #include <linux/futex.h>
24 #include <sys/syscall.h>
25 #include <audio_utils/clock.h>
26 #include <cutils/atomic.h>
27 #include <utils/Log.h>
28 #include <utils/Trace.h>
29 #include "FastThread.h"
30 #include "FastThreadDumpState.h"
31 #include <afutils/TypedLogger.h>
32
33 #define FAST_DEFAULT_NS 999999999L // ~1 sec: default time to sleep
34 #define FAST_HOT_IDLE_NS 1000000L // 1 ms: time to sleep while hot idling
35 #define MIN_WARMUP_CYCLES 2 // minimum number of consecutive in-range loop cycles
36 // to wait for warmup
37 #define MAX_WARMUP_CYCLES 10 // maximum number of loop cycles to wait for warmup
38
39 namespace android {
40
FastThread(const char * cycleMs,const char * loadUs)41 FastThread::FastThread(const char *cycleMs, const char *loadUs) : Thread(false /*canCallJava*/)
42 {
43 strlcpy(mCycleMs, cycleMs, sizeof(mCycleMs));
44 strlcpy(mLoadUs, loadUs, sizeof(mLoadUs));
45 }
46
threadLoop()47 bool FastThread::threadLoop()
48 {
49 // LOGT now works even if tlNBLogWriter is nullptr, but we're considering changing that,
50 // so this initialization permits a future change to remove the check for nullptr.
51 aflog::setThreadWriter(mDummyNBLogWriter.get());
52 for (;;) {
53
54 // either nanosleep, sched_yield, or busy wait
55 if (mSleepNs >= 0) {
56 if (mSleepNs > 0) {
57 if (mOldTsValid) {
58 mOldTs.tv_nsec += mSleepNs;
59 if (mOldTs.tv_nsec >= 1000000000) {
60 mOldTs.tv_sec++;
61 mOldTs.tv_nsec -= 1000000000;
62 }
63 }
64 ALOG_ASSERT(mSleepNs < 1000000000);
65 const struct timespec req = {
66 0, // tv_sec
67 static_cast<long>(mSleepNs) // NOLINT(google-runtime-int)
68 };
69 nanosleep(&req, nullptr);
70 } else {
71 sched_yield();
72 }
73 }
74 // default to long sleep for next cycle
75 mSleepNs = FAST_DEFAULT_NS;
76
77 // poll for state change
78 const FastThreadState *next = poll();
79 if (next == nullptr) {
80 // continue to use the default initial state until a real state is available
81 // FIXME &sInitial not available, should save address earlier
82 //ALOG_ASSERT(mCurrent == &sInitial && previous == &sInitial);
83 next = mCurrent;
84 }
85
86 mCommand = next->mCommand;
87 if (next != mCurrent) {
88
89 // As soon as possible of learning of a new dump area, start using it
90 mDumpState = next->mDumpState != nullptr ? next->mDumpState : mDummyDumpState;
91 NBLog::Writer * const writer = next->mNBLogWriter != nullptr ?
92 next->mNBLogWriter : mDummyNBLogWriter.get();
93 aflog::setThreadWriter(writer);
94 setNBLogWriter(writer); // This is used for debugging only
95
96 // We want to always have a valid reference to the previous (non-idle) state.
97 // However, the state queue only guarantees access to current and previous states.
98 // So when there is a transition from a non-idle state into an idle state, we make a
99 // copy of the last known non-idle state so it is still available on return from idle.
100 // The possible transitions are:
101 // non-idle -> non-idle update previous from current in-place
102 // non-idle -> idle update previous from copy of current
103 // idle -> idle don't update previous
104 // idle -> non-idle don't update previous
105 if (!(mCurrent->mCommand & FastThreadState::IDLE)) {
106 if (mCommand & FastThreadState::IDLE) {
107 onIdle();
108 mOldTsValid = false;
109 #ifdef FAST_THREAD_STATISTICS
110 mOldLoadValid = false;
111 #endif
112 mIgnoreNextOverrun = true;
113 }
114 mPrevious = mCurrent;
115 }
116 mCurrent = next;
117 }
118 #if !LOG_NDEBUG
119 next = nullptr; // not referenced again
120 #endif
121
122 mDumpState->mCommand = mCommand;
123
124 // FIXME what does this comment mean?
125 // << current, previous, command, dumpState >>
126
127 switch (mCommand) {
128 case FastThreadState::INITIAL:
129 case FastThreadState::HOT_IDLE:
130 mSleepNs = FAST_HOT_IDLE_NS;
131 continue;
132 case FastThreadState::COLD_IDLE:
133 // only perform a cold idle command once
134 // FIXME consider checking previous state and only perform if previous != COLD_IDLE
135 if (mCurrent->mColdGen != mColdGen) {
136 int32_t *coldFutexAddr = mCurrent->mColdFutexAddr;
137 ALOG_ASSERT(coldFutexAddr != nullptr);
138 const int32_t old = android_atomic_dec(coldFutexAddr);
139 if (old <= 0) {
140 syscall(__NR_futex, coldFutexAddr, FUTEX_WAIT_PRIVATE, old - 1, nullptr);
141 }
142 const int policy = sched_getscheduler(0) & ~SCHED_RESET_ON_FORK;
143 if (!(policy == SCHED_FIFO || policy == SCHED_RR)) {
144 ALOGE("did not receive expected priority boost on time");
145 }
146 // This may be overly conservative; there could be times that the normal mixer
147 // requests such a brief cold idle that it doesn't require resetting this flag.
148 mIsWarm = false;
149 mMeasuredWarmupTs.tv_sec = 0;
150 mMeasuredWarmupTs.tv_nsec = 0;
151 mWarmupCycles = 0;
152 mWarmupConsecutiveInRangeCycles = 0;
153 mSleepNs = -1;
154 mColdGen = mCurrent->mColdGen;
155 #ifdef FAST_THREAD_STATISTICS
156 mBounds = 0;
157 mFull = false;
158 #endif
159 mOldTsValid = !clock_gettime(CLOCK_MONOTONIC, &mOldTs);
160 mTimestampStatus = INVALID_OPERATION;
161 } else {
162 mSleepNs = FAST_HOT_IDLE_NS;
163 }
164 continue;
165 case FastThreadState::EXIT:
166 onExit();
167 return false;
168 default:
169 LOG_ALWAYS_FATAL_IF(!isSubClassCommand(mCommand));
170 break;
171 }
172
173 // there is a non-idle state available to us; did the state change?
174 if (mCurrent != mPrevious) {
175 onStateChange();
176 #if 1 // FIXME shouldn't need this
177 // only process state change once
178 mPrevious = mCurrent;
179 #endif
180 }
181
182 // do work using current state here
183 mAttemptedWrite = false;
184 onWork();
185
186 // To be exactly periodic, compute the next sleep time based on current time.
187 // This code doesn't have long-term stability when the sink is non-blocking.
188 // FIXME To avoid drift, use the local audio clock or watch the sink's fill status.
189 struct timespec newTs;
190 int rc = clock_gettime(CLOCK_MONOTONIC, &newTs);
191 if (rc == 0) {
192 if (mOldTsValid) {
193 time_t sec = newTs.tv_sec - mOldTs.tv_sec;
194 auto nsec = newTs.tv_nsec - mOldTs.tv_nsec;
195 ALOGE_IF(sec < 0 || (sec == 0 && nsec < 0),
196 "clock_gettime(CLOCK_MONOTONIC) failed: was %ld.%09ld but now %ld.%09ld",
197 mOldTs.tv_sec, mOldTs.tv_nsec, newTs.tv_sec, newTs.tv_nsec);
198 if (nsec < 0) {
199 --sec;
200 nsec += 1000000000;
201 }
202 // To avoid an initial underrun on fast tracks after exiting standby,
203 // do not start pulling data from tracks and mixing until warmup is complete.
204 // Warmup is considered complete after the earlier of:
205 // MIN_WARMUP_CYCLES consecutive in-range write() attempts,
206 // where "in-range" means mWarmupNsMin <= cycle time <= mWarmupNsMax
207 // MAX_WARMUP_CYCLES write() attempts.
208 // This is overly conservative, but to get better accuracy requires a new HAL API.
209 if (!mIsWarm && mAttemptedWrite) {
210 mMeasuredWarmupTs.tv_sec += sec;
211 mMeasuredWarmupTs.tv_nsec += nsec;
212 if (mMeasuredWarmupTs.tv_nsec >= 1000000000) {
213 mMeasuredWarmupTs.tv_sec++;
214 mMeasuredWarmupTs.tv_nsec -= 1000000000;
215 }
216 ++mWarmupCycles;
217 if (mWarmupNsMin <= nsec && nsec <= mWarmupNsMax) {
218 ALOGV("warmup cycle %d in range: %.03f ms", mWarmupCycles, nsec * 1e-9);
219 ++mWarmupConsecutiveInRangeCycles;
220 } else {
221 ALOGV("warmup cycle %d out of range: %.03f ms", mWarmupCycles, nsec * 1e-9);
222 mWarmupConsecutiveInRangeCycles = 0;
223 }
224 if ((mWarmupConsecutiveInRangeCycles >= MIN_WARMUP_CYCLES) ||
225 (mWarmupCycles >= MAX_WARMUP_CYCLES)) {
226 mIsWarm = true;
227 mDumpState->mMeasuredWarmupTs = mMeasuredWarmupTs;
228 mDumpState->mWarmupCycles = mWarmupCycles;
229 const double measuredWarmupMs = (mMeasuredWarmupTs.tv_sec * 1e3) +
230 (mMeasuredWarmupTs.tv_nsec * 1e-6);
231 LOG_WARMUP_TIME(measuredWarmupMs);
232 }
233 }
234 mSleepNs = -1;
235 if (mIsWarm) {
236 if (sec > 0 || nsec > mUnderrunNs) {
237 ATRACE_NAME("underrun"); // NOLINT(misc-const-correctness)
238 // FIXME only log occasionally
239 ALOGV("underrun: time since last cycle %d.%03ld sec",
240 (int) sec, nsec / 1000000L);
241 mDumpState->mUnderruns++;
242 LOG_UNDERRUN(audio_utils_ns_from_timespec(&newTs));
243 mIgnoreNextOverrun = true;
244 } else if (nsec < mOverrunNs) {
245 if (mIgnoreNextOverrun) {
246 mIgnoreNextOverrun = false;
247 } else {
248 // FIXME only log occasionally
249 ALOGV("overrun: time since last cycle %d.%03ld sec",
250 (int) sec, nsec / 1000000L);
251 mDumpState->mOverruns++;
252 LOG_OVERRUN(audio_utils_ns_from_timespec(&newTs));
253 }
254 // This forces a minimum cycle time. It:
255 // - compensates for an audio HAL with jitter due to sample rate conversion
256 // - works with a variable buffer depth audio HAL that never pulls at a
257 // rate < than mOverrunNs per buffer.
258 // - recovers from overrun immediately after underrun
259 // It doesn't work with a non-blocking audio HAL.
260 mSleepNs = mForceNs - nsec;
261 } else {
262 mIgnoreNextOverrun = false;
263 }
264 }
265 #ifdef FAST_THREAD_STATISTICS
266 if (mIsWarm) {
267 // advance the FIFO queue bounds
268 const size_t i = mBounds & (mDumpState->mSamplingN - 1);
269 mBounds = (mBounds & 0xFFFF0000) | ((mBounds + 1) & 0xFFFF);
270 if (mFull) {
271 //mBounds += 0x10000;
272 __builtin_add_overflow(mBounds, 0x10000, &mBounds);
273 } else if (!(mBounds & (mDumpState->mSamplingN - 1))) {
274 mFull = true;
275 }
276 // compute the delta value of clock_gettime(CLOCK_MONOTONIC)
277 uint32_t monotonicNs = nsec;
278 if (sec > 0 && sec < 4) {
279 monotonicNs += sec * 1000000000U; // unsigned to prevent signed overflow.
280 }
281 // compute raw CPU load = delta value of clock_gettime(CLOCK_THREAD_CPUTIME_ID)
282 uint32_t loadNs = 0;
283 struct timespec newLoad;
284 rc = clock_gettime(CLOCK_THREAD_CPUTIME_ID, &newLoad);
285 if (rc == 0) {
286 if (mOldLoadValid) {
287 sec = newLoad.tv_sec - mOldLoad.tv_sec;
288 nsec = newLoad.tv_nsec - mOldLoad.tv_nsec;
289 if (nsec < 0) {
290 --sec;
291 nsec += 1000000000;
292 }
293 loadNs = nsec;
294 if (sec > 0 && sec < 4) {
295 loadNs += sec * 1000000000U; // unsigned to prevent signed overflow.
296 }
297 } else {
298 // first time through the loop
299 mOldLoadValid = true;
300 }
301 mOldLoad = newLoad;
302 }
303 #ifdef CPU_FREQUENCY_STATISTICS
304 // get the absolute value of CPU clock frequency in kHz
305 int cpuNum = sched_getcpu();
306 uint32_t kHz = mTcu.getCpukHz(cpuNum);
307 kHz = (kHz << 4) | (cpuNum & 0xF);
308 #endif
309 // save values in FIFO queues for dumpsys
310 // these stores #1, #2, #3 are not atomic with respect to each other,
311 // or with respect to store #4 below
312 mDumpState->mMonotonicNs[i] = monotonicNs;
313 LOG_WORK_TIME(monotonicNs);
314 mDumpState->mLoadNs[i] = loadNs;
315 #ifdef CPU_FREQUENCY_STATISTICS
316 mDumpState->mCpukHz[i] = kHz;
317 #endif
318 // this store #4 is not atomic with respect to stores #1, #2, #3 above, but
319 // the newest open & oldest closed halves are atomic with respect to each other
320 mDumpState->mBounds = mBounds;
321 ATRACE_INT(mCycleMs, monotonicNs / 1000000);
322 ATRACE_INT(mLoadUs, loadNs / 1000);
323 }
324 #endif
325 } else {
326 // first time through the loop
327 mOldTsValid = true;
328 mSleepNs = mPeriodNs;
329 mIgnoreNextOverrun = true;
330 }
331 mOldTs = newTs;
332 } else {
333 // monotonic clock is broken
334 mOldTsValid = false;
335 mSleepNs = mPeriodNs;
336 }
337
338 } // for (;;)
339
340 // never return 'true'; Thread::_threadLoop() locks mutex which can result in priority inversion
341 }
342
343 } // namespace android
344