1 /*
2  * Copyright (C) 2016 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 package android.util;
18 
19 import android.os.Build;
20 import android.os.SystemClock;
21 import android.os.Trace;
22 
23 import java.util.ArrayDeque;
24 import java.util.Deque;
25 
26 /**
27  * Helper class for reporting boot and shutdown timing metrics.
28  * <p>Note: This class is not thread-safe. Use a separate copy for other threads</p>
29  * @hide
30  */
31 public class TimingsTraceLog {
32     // Debug boot time for every step if it's non-user build.
33     private static final boolean DEBUG_BOOT_TIME = !Build.IS_USER;
34     private final Deque<Pair<String, Long>> mStartTimes =
35             DEBUG_BOOT_TIME ? new ArrayDeque<>() : null;
36     private final String mTag;
37     private long mTraceTag;
38     private long mThreadId;
39 
TimingsTraceLog(String tag, long traceTag)40     public TimingsTraceLog(String tag, long traceTag) {
41         mTag = tag;
42         mTraceTag = traceTag;
43         mThreadId = Thread.currentThread().getId();
44     }
45 
46     /**
47      * Begin tracing named section
48      * @param name name to appear in trace
49      */
traceBegin(String name)50     public void traceBegin(String name) {
51         assertSameThread();
52         Trace.traceBegin(mTraceTag, name);
53         if (DEBUG_BOOT_TIME) {
54             mStartTimes.push(Pair.create(name, SystemClock.elapsedRealtime()));
55         }
56     }
57 
58     /**
59      * End tracing previously {@link #traceBegin(String) started} section.
60      * Also {@link #logDuration logs} the duration.
61      */
traceEnd()62     public void traceEnd() {
63         assertSameThread();
64         Trace.traceEnd(mTraceTag);
65         if (!DEBUG_BOOT_TIME) {
66             return;
67         }
68         if (mStartTimes.peek() == null) {
69             Slog.w(mTag, "traceEnd called more times than traceBegin");
70             return;
71         }
72         Pair<String, Long> event = mStartTimes.pop();
73         logDuration(event.first, (SystemClock.elapsedRealtime() - event.second));
74     }
75 
assertSameThread()76     private void assertSameThread() {
77         final Thread currentThread = Thread.currentThread();
78         if (currentThread.getId() != mThreadId) {
79             throw new IllegalStateException("Instance of TimingsTraceLog can only be called from "
80                     + "the thread it was created on (tid: " + mThreadId + "), but was from "
81                     + currentThread.getName() + " (tid: " + currentThread.getId() + ")");
82         }
83     }
84 
85     /**
86      * Log the duration so it can be parsed by external tools for performance reporting
87      */
logDuration(String name, long timeMs)88     public void logDuration(String name, long timeMs) {
89         Slog.d(mTag, name + " took to complete: " + timeMs + "ms");
90     }
91 }
92