FastThread.cpp revision d2123e631834a887c2d8600c3ac43dda02d47cb9 
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 <utils/Log.h>
26#include <utils/Trace.h>
27#include "FastThread.h"
28#include "FastThreadDumpState.h"
29
30#define FAST_DEFAULT_NS    999999999L   // ~1 sec: default time to sleep
31#define FAST_HOT_IDLE_NS     1000000L   // 1 ms: time to sleep while hot idling
32#define MIN_WARMUP_CYCLES          2    // minimum number of consecutive in-range loop cycles
33                                        // to wait for warmup
34#define MAX_WARMUP_CYCLES         10    // maximum number of loop cycles to wait for warmup
35
36namespace android {
37
38FastThread::FastThread() : Thread(false /*canCallJava*/),
39    // re-initialized to &initial by subclass constructor
40     previous(NULL), current(NULL),
41    /* oldTs({0, 0}), */
42    oldTsValid(false),
43    sleepNs(-1),
44    periodNs(0),
45    underrunNs(0),
46    overrunNs(0),
47    forceNs(0),
48    warmupNsMin(0),
49    warmupNsMax(LONG_MAX),
50    // re-initialized to &dummyDumpState by subclass constructor
51    mDummyDumpState(NULL),
52    dumpState(NULL),
53    ignoreNextOverrun(true),
54#ifdef FAST_MIXER_STATISTICS
55    // oldLoad
56    oldLoadValid(false),
57    bounds(0),
58    full(false),
59    // tcu
60#endif
61    coldGen(0),
62    isWarm(false),
63    /* measuredWarmupTs({0, 0}), */
64    warmupCycles(0),
65    warmupConsecutiveInRangeCycles(0),
66    // dummyLogWriter
67    logWriter(&dummyLogWriter),
68    timestampStatus(INVALID_OPERATION),
69
70    command(FastThreadState::INITIAL),
71#if 0
72    frameCount(0),
73#endif
74    attemptedWrite(false)
75{
76    oldTs.tv_sec = 0;
77    oldTs.tv_nsec = 0;
78    measuredWarmupTs.tv_sec = 0;
79    measuredWarmupTs.tv_nsec = 0;
80}
81
82FastThread::~FastThread()
83{
84}
85
86bool FastThread::threadLoop()
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 FastThreadState *next = poll();
105        if (next == NULL) {
106            // continue to use the default initial state until a real state is available
107            // FIXME &initial not available, should save address earlier
108            //ALOG_ASSERT(current == &initial && previous == &initial);
109            next = current;
110        }
111
112        command = next->mCommand;
113        if (next != current) {
114
115            // As soon as possible of learning of a new dump area, start using it
116            dumpState = next->mDumpState != NULL ? next->mDumpState : mDummyDumpState;
117            logWriter = next->mNBLogWriter != NULL ? next->mNBLogWriter : &dummyLogWriter;
118            setLog(logWriter);
119
120            // We want to always have a valid reference to the previous (non-idle) state.
121            // However, the state queue only guarantees access to current and previous states.
122            // So when there is a transition from a non-idle state into an idle state, we make a
123            // copy of the last known non-idle state so it is still available on return from idle.
124            // The possible transitions are:
125            //  non-idle -> non-idle    update previous from current in-place
126            //  non-idle -> idle        update previous from copy of current
127            //  idle     -> idle        don't update previous
128            //  idle     -> non-idle    don't update previous
129            if (!(current->mCommand & FastThreadState::IDLE)) {
130                if (command & FastThreadState::IDLE) {
131                    onIdle();
132                    oldTsValid = false;
133#ifdef FAST_MIXER_STATISTICS
134                    oldLoadValid = false;
135#endif
136                    ignoreNextOverrun = true;
137                }
138                previous = current;
139            }
140            current = next;
141        }
142#if !LOG_NDEBUG
143        next = NULL;    // not referenced again
144#endif
145
146        dumpState->mCommand = command;
147
148        // << current, previous, command, dumpState >>
149
150        switch (command) {
151        case FastThreadState::INITIAL:
152        case FastThreadState::HOT_IDLE:
153            sleepNs = FAST_HOT_IDLE_NS;
154            continue;
155        case FastThreadState::COLD_IDLE:
156            // only perform a cold idle command once
157            // FIXME consider checking previous state and only perform if previous != COLD_IDLE
158            if (current->mColdGen != coldGen) {
159                int32_t *coldFutexAddr = current->mColdFutexAddr;
160                ALOG_ASSERT(coldFutexAddr != NULL);
161                int32_t old = android_atomic_dec(coldFutexAddr);
162                if (old <= 0) {
163                    syscall(__NR_futex, coldFutexAddr, FUTEX_WAIT_PRIVATE, old - 1, NULL);
164                }
165                int policy = sched_getscheduler(0);
166                if (!(policy == SCHED_FIFO || policy == SCHED_RR)) {
167                    ALOGE("did not receive expected priority boost");
168                }
169                // This may be overly conservative; there could be times that the normal mixer
170                // requests such a brief cold idle that it doesn't require resetting this flag.
171                isWarm = false;
172                measuredWarmupTs.tv_sec = 0;
173                measuredWarmupTs.tv_nsec = 0;
174                warmupCycles = 0;
175                warmupConsecutiveInRangeCycles = 0;
176                sleepNs = -1;
177                coldGen = current->mColdGen;
178#ifdef FAST_MIXER_STATISTICS
179                bounds = 0;
180                full = false;
181#endif
182                oldTsValid = !clock_gettime(CLOCK_MONOTONIC, &oldTs);
183                timestampStatus = INVALID_OPERATION;
184            } else {
185                sleepNs = FAST_HOT_IDLE_NS;
186            }
187            continue;
188        case FastThreadState::EXIT:
189            onExit();
190            return false;
191        default:
192            LOG_ALWAYS_FATAL_IF(!isSubClassCommand(command));
193            break;
194        }
195
196        // there is a non-idle state available to us; did the state change?
197        if (current != previous) {
198            onStateChange();
199#if 1   // FIXME shouldn't need this
200            // only process state change once
201            previous = current;
202#endif
203        }
204
205        // do work using current state here
206        attemptedWrite = false;
207        onWork();
208
209        // To be exactly periodic, compute the next sleep time based on current time.
210        // This code doesn't have long-term stability when the sink is non-blocking.
211        // FIXME To avoid drift, use the local audio clock or watch the sink's fill status.
212        struct timespec newTs;
213        int rc = clock_gettime(CLOCK_MONOTONIC, &newTs);
214        if (rc == 0) {
215            //logWriter->logTimestamp(newTs);
216            if (oldTsValid) {
217                time_t sec = newTs.tv_sec - oldTs.tv_sec;
218                long nsec = newTs.tv_nsec - oldTs.tv_nsec;
219                ALOGE_IF(sec < 0 || (sec == 0 && nsec < 0),
220                        "clock_gettime(CLOCK_MONOTONIC) failed: was %ld.%09ld but now %ld.%09ld",
221                        oldTs.tv_sec, oldTs.tv_nsec, newTs.tv_sec, newTs.tv_nsec);
222                if (nsec < 0) {
223                    --sec;
224                    nsec += 1000000000;
225                }
226                // To avoid an initial underrun on fast tracks after exiting standby,
227                // do not start pulling data from tracks and mixing until warmup is complete.
228                // Warmup is considered complete after the earlier of:
229                //      MIN_WARMUP_CYCLES consecutive in-range write() attempts,
230                //          where "in-range" means warmupNsMin <= cycle time <= warmupNsMax
231                //      MAX_WARMUP_CYCLES write() attempts.
232                // This is overly conservative, but to get better accuracy requires a new HAL API.
233                if (!isWarm && attemptedWrite) {
234                    measuredWarmupTs.tv_sec += sec;
235                    measuredWarmupTs.tv_nsec += nsec;
236                    if (measuredWarmupTs.tv_nsec >= 1000000000) {
237                        measuredWarmupTs.tv_sec++;
238                        measuredWarmupTs.tv_nsec -= 1000000000;
239                    }
240                    ++warmupCycles;
241                    if (warmupNsMin <= nsec && nsec <= warmupNsMax) {
242                        ALOGV("warmup cycle %d in range: %.03f ms", warmupCycles, nsec * 1e-9);
243                        ++warmupConsecutiveInRangeCycles;
244                    } else {
245                        ALOGV("warmup cycle %d out of range: %.03f ms", warmupCycles, nsec * 1e-9);
246                        warmupConsecutiveInRangeCycles = 0;
247                    }
248                    if ((warmupConsecutiveInRangeCycles >= MIN_WARMUP_CYCLES) ||
249                            (warmupCycles >= MAX_WARMUP_CYCLES)) {
250                        isWarm = true;
251                        dumpState->mMeasuredWarmupTs = measuredWarmupTs;
252                        dumpState->mWarmupCycles = warmupCycles;
253                    }
254                }
255                sleepNs = -1;
256                if (isWarm) {
257                    if (sec > 0 || nsec > underrunNs) {
258                        ATRACE_NAME("underrun");
259                        // FIXME only log occasionally
260                        ALOGV("underrun: time since last cycle %d.%03ld sec",
261                                (int) sec, nsec / 1000000L);
262                        dumpState->mUnderruns++;
263                        ignoreNextOverrun = true;
264                    } else if (nsec < overrunNs) {
265                        if (ignoreNextOverrun) {
266                            ignoreNextOverrun = false;
267                        } else {
268                            // FIXME only log occasionally
269                            ALOGV("overrun: time since last cycle %d.%03ld sec",
270                                    (int) sec, nsec / 1000000L);
271                            dumpState->mOverruns++;
272                        }
273                        // This forces a minimum cycle time. It:
274                        //  - compensates for an audio HAL with jitter due to sample rate conversion
275                        //  - works with a variable buffer depth audio HAL that never pulls at a
276                        //    rate < than overrunNs per buffer.
277                        //  - recovers from overrun immediately after underrun
278                        // It doesn't work with a non-blocking audio HAL.
279                        sleepNs = forceNs - nsec;
280                    } else {
281                        ignoreNextOverrun = false;
282                    }
283                }
284#ifdef FAST_MIXER_STATISTICS
285                if (isWarm) {
286                    // advance the FIFO queue bounds
287                    size_t i = bounds & (dumpState->mSamplingN - 1);
288                    bounds = (bounds & 0xFFFF0000) | ((bounds + 1) & 0xFFFF);
289                    if (full) {
290                        bounds += 0x10000;
291                    } else if (!(bounds & (dumpState->mSamplingN - 1))) {
292                        full = true;
293                    }
294                    // compute the delta value of clock_gettime(CLOCK_MONOTONIC)
295                    uint32_t monotonicNs = nsec;
296                    if (sec > 0 && sec < 4) {
297                        monotonicNs += sec * 1000000000;
298                    }
299                    // compute raw CPU load = delta value of clock_gettime(CLOCK_THREAD_CPUTIME_ID)
300                    uint32_t loadNs = 0;
301                    struct timespec newLoad;
302                    rc = clock_gettime(CLOCK_THREAD_CPUTIME_ID, &newLoad);
303                    if (rc == 0) {
304                        if (oldLoadValid) {
305                            sec = newLoad.tv_sec - oldLoad.tv_sec;
306                            nsec = newLoad.tv_nsec - oldLoad.tv_nsec;
307                            if (nsec < 0) {
308                                --sec;
309                                nsec += 1000000000;
310                            }
311                            loadNs = nsec;
312                            if (sec > 0 && sec < 4) {
313                                loadNs += sec * 1000000000;
314                            }
315                        } else {
316                            // first time through the loop
317                            oldLoadValid = true;
318                        }
319                        oldLoad = newLoad;
320                    }
321#ifdef CPU_FREQUENCY_STATISTICS
322                    // get the absolute value of CPU clock frequency in kHz
323                    int cpuNum = sched_getcpu();
324                    uint32_t kHz = tcu.getCpukHz(cpuNum);
325                    kHz = (kHz << 4) | (cpuNum & 0xF);
326#endif
327                    // save values in FIFO queues for dumpsys
328                    // these stores #1, #2, #3 are not atomic with respect to each other,
329                    // or with respect to store #4 below
330                    dumpState->mMonotonicNs[i] = monotonicNs;
331                    dumpState->mLoadNs[i] = loadNs;
332#ifdef CPU_FREQUENCY_STATISTICS
333                    dumpState->mCpukHz[i] = kHz;
334#endif
335                    // this store #4 is not atomic with respect to stores #1, #2, #3 above, but
336                    // the newest open & oldest closed halves are atomic with respect to each other
337                    dumpState->mBounds = bounds;
338                    ATRACE_INT("cycle_ms", monotonicNs / 1000000);
339                    ATRACE_INT("load_us", loadNs / 1000);
340                }
341#endif
342            } else {
343                // first time through the loop
344                oldTsValid = true;
345                sleepNs = periodNs;
346                ignoreNextOverrun = true;
347            }
348            oldTs = newTs;
349        } else {
350            // monotonic clock is broken
351            oldTsValid = false;
352            sleepNs = periodNs;
353        }
354
355    }   // for (;;)
356
357    // never return 'true'; Thread::_threadLoop() locks mutex which can result in priority inversion
358}
359
360}   // namespace android
361