1 /*
2  * Copyright (C) 2017 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 com.android.internal.os;
18 
19 import android.os.Binder;
20 import android.os.SystemClock;
21 import android.text.format.DateFormat;
22 import android.util.ArrayMap;
23 import android.util.SparseArray;
24 
25 import com.android.internal.annotations.GuardedBy;
26 import com.android.internal.annotations.VisibleForTesting;
27 import com.android.internal.util.Preconditions;
28 
29 import java.io.PrintWriter;
30 import java.util.ArrayList;
31 import java.util.HashMap;
32 import java.util.List;
33 import java.util.Map;
34 import java.util.Queue;
35 import java.util.concurrent.ConcurrentLinkedQueue;
36 
37 /**
38  * Collects statistics about CPU time spent per binder call across multiple dimensions, e.g.
39  * per thread, uid or call description.
40  */
41 public class BinderCallsStats {
42     private static final int CALL_SESSIONS_POOL_SIZE = 100;
43     private static final BinderCallsStats sInstance = new BinderCallsStats();
44 
45     private volatile boolean mDetailedTracking = false;
46     @GuardedBy("mLock")
47     private final SparseArray<UidEntry> mUidEntries = new SparseArray<>();
48     private final Queue<CallSession> mCallSessionsPool = new ConcurrentLinkedQueue<>();
49     private final Object mLock = new Object();
50     private long mStartTime = System.currentTimeMillis();
51 
BinderCallsStats()52     private BinderCallsStats() {
53     }
54 
55     @VisibleForTesting
BinderCallsStats(boolean detailedTracking)56     public BinderCallsStats(boolean detailedTracking) {
57         mDetailedTracking = detailedTracking;
58     }
59 
callStarted(Binder binder, int code)60     public CallSession callStarted(Binder binder, int code) {
61         return callStarted(binder.getClass().getName(), code);
62     }
63 
callStarted(String className, int code)64     private CallSession callStarted(String className, int code) {
65         CallSession s = mCallSessionsPool.poll();
66         if (s == null) {
67             s = new CallSession();
68         }
69         s.mCallStat.className = className;
70         s.mCallStat.msg = code;
71 
72         s.mStarted = getThreadTimeMicro();
73         return s;
74     }
75 
callEnded(CallSession s)76     public void callEnded(CallSession s) {
77         Preconditions.checkNotNull(s);
78         long duration = mDetailedTracking ? getThreadTimeMicro() - s.mStarted : 1;
79         s.mCallingUId = Binder.getCallingUid();
80 
81         synchronized (mLock) {
82             UidEntry uidEntry = mUidEntries.get(s.mCallingUId);
83             if (uidEntry == null) {
84                 uidEntry = new UidEntry(s.mCallingUId);
85                 mUidEntries.put(s.mCallingUId, uidEntry);
86             }
87 
88             if (mDetailedTracking) {
89                 // Find CallDesc entry and update its total time
90                 CallStat callStat = uidEntry.mCallStats.get(s.mCallStat);
91                 // Only create CallStat if it's a new entry, otherwise update existing instance
92                 if (callStat == null) {
93                     callStat = new CallStat(s.mCallStat.className, s.mCallStat.msg);
94                     uidEntry.mCallStats.put(callStat, callStat);
95                 }
96                 callStat.callCount++;
97                 callStat.time += duration;
98             }
99 
100             uidEntry.time += duration;
101             uidEntry.callCount++;
102         }
103         if (mCallSessionsPool.size() < CALL_SESSIONS_POOL_SIZE) {
104             mCallSessionsPool.add(s);
105         }
106     }
107 
dump(PrintWriter pw)108     public void dump(PrintWriter pw) {
109         Map<Integer, Long> uidTimeMap = new HashMap<>();
110         Map<Integer, Long> uidCallCountMap = new HashMap<>();
111         long totalCallsCount = 0;
112         long totalCallsTime = 0;
113         pw.print("Start time: ");
114         pw.println(DateFormat.format("yyyy-MM-dd HH:mm:ss", mStartTime));
115         int uidEntriesSize = mUidEntries.size();
116         List<UidEntry> entries = new ArrayList<>();
117         synchronized (mLock) {
118             for (int i = 0; i < uidEntriesSize; i++) {
119                 UidEntry e = mUidEntries.valueAt(i);
120                 entries.add(e);
121                 totalCallsTime += e.time;
122                 // Update per-uid totals
123                 Long totalTimePerUid = uidTimeMap.get(e.uid);
124                 uidTimeMap.put(e.uid,
125                         totalTimePerUid == null ? e.time : totalTimePerUid + e.time);
126                 Long totalCallsPerUid = uidCallCountMap.get(e.uid);
127                 uidCallCountMap.put(e.uid, totalCallsPerUid == null ? e.callCount
128                         : totalCallsPerUid + e.callCount);
129                 totalCallsCount += e.callCount;
130             }
131         }
132         if (mDetailedTracking) {
133             pw.println("Raw data (uid,call_desc,time):");
134             entries.sort((o1, o2) -> {
135                 if (o1.time < o2.time) {
136                     return 1;
137                 } else if (o1.time > o2.time) {
138                     return -1;
139                 }
140                 return 0;
141             });
142             StringBuilder sb = new StringBuilder();
143             for (UidEntry uidEntry : entries) {
144                 List<CallStat> callStats = new ArrayList<>(uidEntry.mCallStats.keySet());
145                 callStats.sort((o1, o2) -> {
146                     if (o1.time < o2.time) {
147                         return 1;
148                     } else if (o1.time > o2.time) {
149                         return -1;
150                     }
151                     return 0;
152                 });
153                 for (CallStat e : callStats) {
154                     sb.setLength(0);
155                     sb.append("    ")
156                             .append(uidEntry.uid).append(",").append(e).append(',').append(e.time);
157                     pw.println(sb);
158                 }
159             }
160             pw.println();
161             pw.println("Per UID Summary(UID: time, % of total_time, calls_count):");
162             List<Map.Entry<Integer, Long>> uidTotals = new ArrayList<>(uidTimeMap.entrySet());
163             uidTotals.sort((o1, o2) -> o2.getValue().compareTo(o1.getValue()));
164             for (Map.Entry<Integer, Long> uidTotal : uidTotals) {
165                 Long callCount = uidCallCountMap.get(uidTotal.getKey());
166                 pw.println(String.format("  %7d: %11d %3.0f%% %8d",
167                         uidTotal.getKey(), uidTotal.getValue(),
168                         100d * uidTotal.getValue() / totalCallsTime, callCount));
169             }
170             pw.println();
171             pw.println(String.format("  Summary: total_time=%d, "
172                             + "calls_count=%d, avg_call_time=%.0f",
173                     totalCallsTime, totalCallsCount,
174                     (double)totalCallsTime / totalCallsCount));
175         } else {
176             pw.println("Per UID Summary(UID: calls_count, % of total calls_count):");
177             List<Map.Entry<Integer, Long>> uidTotals = new ArrayList<>(uidTimeMap.entrySet());
178             uidTotals.sort((o1, o2) -> o2.getValue().compareTo(o1.getValue()));
179             for (Map.Entry<Integer, Long> uidTotal : uidTotals) {
180                 Long callCount = uidCallCountMap.get(uidTotal.getKey());
181                 pw.println(String.format("    %7d: %8d %3.0f%%",
182                         uidTotal.getKey(), callCount, 100d * uidTotal.getValue() / totalCallsTime));
183             }
184         }
185     }
186 
getThreadTimeMicro()187     private long getThreadTimeMicro() {
188         // currentThreadTimeMicro is expensive, so we measure cpu time only if detailed tracking is
189         // enabled
190         return mDetailedTracking ? SystemClock.currentThreadTimeMicro() : 0;
191     }
192 
getInstance()193     public static BinderCallsStats getInstance() {
194         return sInstance;
195     }
196 
setDetailedTracking(boolean enabled)197     public void setDetailedTracking(boolean enabled) {
198         if (enabled != mDetailedTracking) {
199             reset();
200             mDetailedTracking = enabled;
201         }
202     }
203 
reset()204     public void reset() {
205         synchronized (mLock) {
206             mUidEntries.clear();
207             mStartTime = System.currentTimeMillis();
208         }
209     }
210 
211     private static class CallStat {
212         String className;
213         int msg;
214         long time;
215         long callCount;
216 
CallStat()217         CallStat() {
218         }
219 
CallStat(String className, int msg)220         CallStat(String className, int msg) {
221             this.className = className;
222             this.msg = msg;
223         }
224 
225         @Override
equals(Object o)226         public boolean equals(Object o) {
227             if (this == o) {
228                 return true;
229             }
230 
231             CallStat callStat = (CallStat) o;
232 
233             return msg == callStat.msg && (className.equals(callStat.className));
234         }
235 
236         @Override
hashCode()237         public int hashCode() {
238             int result = className.hashCode();
239             result = 31 * result + msg;
240             return result;
241         }
242 
243         @Override
toString()244         public String toString() {
245             return className + "/" + msg;
246         }
247     }
248 
249     public static class CallSession {
250         int mCallingUId;
251         long mStarted;
252         CallStat mCallStat = new CallStat();
253     }
254 
255     private static class UidEntry {
256         int uid;
257         long time;
258         long callCount;
259 
UidEntry(int uid)260         UidEntry(int uid) {
261             this.uid = uid;
262         }
263 
264         // Aggregate time spent per each call name: call_desc -> cpu_time_micros
265         Map<CallStat, CallStat> mCallStats = new ArrayMap<>();
266 
267         @Override
toString()268         public String toString() {
269             return "UidEntry{" +
270                     "time=" + time +
271                     ", callCount=" + callCount +
272                     ", mCallStats=" + mCallStats +
273                     '}';
274         }
275 
276         @Override
equals(Object o)277         public boolean equals(Object o) {
278             if (this == o) {
279                 return true;
280             }
281 
282             UidEntry uidEntry = (UidEntry) o;
283             return uid == uidEntry.uid;
284         }
285 
286         @Override
hashCode()287         public int hashCode() {
288             return uid;
289         }
290     }
291 
292 }
293