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 com.android.server.job;
18 
19 import android.app.job.JobInfo;
20 import android.os.SystemClock;
21 import android.os.UserHandle;
22 import android.text.format.DateFormat;
23 import android.util.ArrayMap;
24 import android.util.SparseArray;
25 import android.util.TimeUtils;
26 import com.android.internal.util.RingBufferIndices;
27 import com.android.server.job.controllers.JobStatus;
28 
29 import java.io.PrintWriter;
30 
31 public final class JobPackageTracker {
32     // We batch every 30 minutes.
33     static final long BATCHING_TIME = 30*60*1000;
34     // Number of historical data sets we keep.
35     static final int NUM_HISTORY = 5;
36 
37     private static final int EVENT_BUFFER_SIZE = 100;
38 
39     public static final int EVENT_NULL = 0;
40     public static final int EVENT_START_JOB = 1;
41     public static final int EVENT_STOP_JOB = 2;
42 
43     private final RingBufferIndices mEventIndices = new RingBufferIndices(EVENT_BUFFER_SIZE);
44     private final int[] mEventCmds = new int[EVENT_BUFFER_SIZE];
45     private final long[] mEventTimes = new long[EVENT_BUFFER_SIZE];
46     private final int[] mEventUids = new int[EVENT_BUFFER_SIZE];
47     private final String[] mEventTags = new String[EVENT_BUFFER_SIZE];
48 
addEvent(int cmd, int uid, String tag)49     public void addEvent(int cmd, int uid, String tag) {
50         int index = mEventIndices.add();
51         mEventCmds[index] = cmd;
52         mEventTimes[index] = SystemClock.elapsedRealtime();
53         mEventUids[index] = uid;
54         mEventTags[index] = tag;
55     }
56 
57     DataSet mCurDataSet = new DataSet();
58     DataSet[] mLastDataSets = new DataSet[NUM_HISTORY];
59 
60     final static class PackageEntry {
61         long pastActiveTime;
62         long activeStartTime;
63         int activeNesting;
64         int activeCount;
65         boolean hadActive;
66         long pastActiveTopTime;
67         long activeTopStartTime;
68         int activeTopNesting;
69         int activeTopCount;
70         boolean hadActiveTop;
71         long pastPendingTime;
72         long pendingStartTime;
73         int pendingNesting;
74         int pendingCount;
75         boolean hadPending;
76 
getActiveTime(long now)77         public long getActiveTime(long now) {
78             long time = pastActiveTime;
79             if (activeNesting > 0) {
80                 time += now - activeStartTime;
81             }
82             return time;
83         }
84 
getActiveTopTime(long now)85         public long getActiveTopTime(long now) {
86             long time = pastActiveTopTime;
87             if (activeTopNesting > 0) {
88                 time += now - activeTopStartTime;
89             }
90             return time;
91         }
92 
getPendingTime(long now)93         public long getPendingTime(long now) {
94             long time = pastPendingTime;
95             if (pendingNesting > 0) {
96                 time += now - pendingStartTime;
97             }
98             return time;
99         }
100     }
101 
102     final static class DataSet {
103         final SparseArray<ArrayMap<String, PackageEntry>> mEntries = new SparseArray<>();
104         final long mStartUptimeTime;
105         final long mStartElapsedTime;
106         final long mStartClockTime;
107         long mSummedTime;
108         int mMaxTotalActive;
109         int mMaxFgActive;
110 
DataSet(DataSet otherTimes)111         public DataSet(DataSet otherTimes) {
112             mStartUptimeTime = otherTimes.mStartUptimeTime;
113             mStartElapsedTime = otherTimes.mStartElapsedTime;
114             mStartClockTime = otherTimes.mStartClockTime;
115         }
116 
DataSet()117         public DataSet() {
118             mStartUptimeTime = SystemClock.uptimeMillis();
119             mStartElapsedTime = SystemClock.elapsedRealtime();
120             mStartClockTime = System.currentTimeMillis();
121         }
122 
getOrCreateEntry(int uid, String pkg)123         private PackageEntry getOrCreateEntry(int uid, String pkg) {
124             ArrayMap<String, PackageEntry> uidMap = mEntries.get(uid);
125             if (uidMap == null) {
126                 uidMap = new ArrayMap<>();
127                 mEntries.put(uid, uidMap);
128             }
129             PackageEntry entry = uidMap.get(pkg);
130             if (entry == null) {
131                 entry = new PackageEntry();
132                 uidMap.put(pkg, entry);
133             }
134             return entry;
135         }
136 
getEntry(int uid, String pkg)137         public PackageEntry getEntry(int uid, String pkg) {
138             ArrayMap<String, PackageEntry> uidMap = mEntries.get(uid);
139             if (uidMap == null) {
140                 return null;
141             }
142             return uidMap.get(pkg);
143         }
144 
getTotalTime(long now)145         long getTotalTime(long now) {
146             if (mSummedTime > 0) {
147                 return mSummedTime;
148             }
149             return now - mStartUptimeTime;
150         }
151 
incPending(int uid, String pkg, long now)152         void incPending(int uid, String pkg, long now) {
153             PackageEntry pe = getOrCreateEntry(uid, pkg);
154             if (pe.pendingNesting == 0) {
155                 pe.pendingStartTime = now;
156                 pe.pendingCount++;
157             }
158             pe.pendingNesting++;
159         }
160 
decPending(int uid, String pkg, long now)161         void decPending(int uid, String pkg, long now) {
162             PackageEntry pe = getOrCreateEntry(uid, pkg);
163             if (pe.pendingNesting == 1) {
164                 pe.pastPendingTime += now - pe.pendingStartTime;
165             }
166             pe.pendingNesting--;
167         }
168 
incActive(int uid, String pkg, long now)169         void incActive(int uid, String pkg, long now) {
170             PackageEntry pe = getOrCreateEntry(uid, pkg);
171             if (pe.activeNesting == 0) {
172                 pe.activeStartTime = now;
173                 pe.activeCount++;
174             }
175             pe.activeNesting++;
176         }
177 
decActive(int uid, String pkg, long now)178         void decActive(int uid, String pkg, long now) {
179             PackageEntry pe = getOrCreateEntry(uid, pkg);
180             if (pe.activeNesting == 1) {
181                 pe.pastActiveTime += now - pe.activeStartTime;
182             }
183             pe.activeNesting--;
184         }
185 
incActiveTop(int uid, String pkg, long now)186         void incActiveTop(int uid, String pkg, long now) {
187             PackageEntry pe = getOrCreateEntry(uid, pkg);
188             if (pe.activeTopNesting == 0) {
189                 pe.activeTopStartTime = now;
190                 pe.activeTopCount++;
191             }
192             pe.activeTopNesting++;
193         }
194 
decActiveTop(int uid, String pkg, long now)195         void decActiveTop(int uid, String pkg, long now) {
196             PackageEntry pe = getOrCreateEntry(uid, pkg);
197             if (pe.activeTopNesting == 1) {
198                 pe.pastActiveTopTime += now - pe.activeTopStartTime;
199             }
200             pe.activeTopNesting--;
201         }
202 
finish(DataSet next, long now)203         void finish(DataSet next, long now) {
204             for (int i = mEntries.size() - 1; i >= 0; i--) {
205                 ArrayMap<String, PackageEntry> uidMap = mEntries.valueAt(i);
206                 for (int j = uidMap.size() - 1; j >= 0; j--) {
207                     PackageEntry pe = uidMap.valueAt(j);
208                     if (pe.activeNesting > 0 || pe.activeTopNesting > 0 || pe.pendingNesting > 0) {
209                         // Propagate existing activity in to next data set.
210                         PackageEntry nextPe = next.getOrCreateEntry(mEntries.keyAt(i), uidMap.keyAt(j));
211                         nextPe.activeStartTime = now;
212                         nextPe.activeNesting = pe.activeNesting;
213                         nextPe.activeTopStartTime = now;
214                         nextPe.activeTopNesting = pe.activeTopNesting;
215                         nextPe.pendingStartTime = now;
216                         nextPe.pendingNesting = pe.pendingNesting;
217                         // Finish it off.
218                         if (pe.activeNesting > 0) {
219                             pe.pastActiveTime += now - pe.activeStartTime;
220                             pe.activeNesting = 0;
221                         }
222                         if (pe.activeTopNesting > 0) {
223                             pe.pastActiveTopTime += now - pe.activeTopStartTime;
224                             pe.activeTopNesting = 0;
225                         }
226                         if (pe.pendingNesting > 0) {
227                             pe.pastPendingTime += now - pe.pendingStartTime;
228                             pe.pendingNesting = 0;
229                         }
230                     }
231                 }
232             }
233         }
234 
addTo(DataSet out, long now)235         void addTo(DataSet out, long now) {
236             out.mSummedTime += getTotalTime(now);
237             for (int i = mEntries.size() - 1; i >= 0; i--) {
238                 ArrayMap<String, PackageEntry> uidMap = mEntries.valueAt(i);
239                 for (int j = uidMap.size() - 1; j >= 0; j--) {
240                     PackageEntry pe = uidMap.valueAt(j);
241                     PackageEntry outPe = out.getOrCreateEntry(mEntries.keyAt(i), uidMap.keyAt(j));
242                     outPe.pastActiveTime += pe.pastActiveTime;
243                     outPe.activeCount += pe.activeCount;
244                     outPe.pastActiveTopTime += pe.pastActiveTopTime;
245                     outPe.activeTopCount += pe.activeTopCount;
246                     outPe.pastPendingTime += pe.pastPendingTime;
247                     outPe.pendingCount += pe.pendingCount;
248                     if (pe.activeNesting > 0) {
249                         outPe.pastActiveTime += now - pe.activeStartTime;
250                         outPe.hadActive = true;
251                     }
252                     if (pe.activeTopNesting > 0) {
253                         outPe.pastActiveTopTime += now - pe.activeTopStartTime;
254                         outPe.hadActiveTop = true;
255                     }
256                     if (pe.pendingNesting > 0) {
257                         outPe.pastPendingTime += now - pe.pendingStartTime;
258                         outPe.hadPending = true;
259                     }
260                 }
261             }
262             if (mMaxTotalActive > out.mMaxTotalActive) {
263                 out.mMaxTotalActive = mMaxTotalActive;
264             }
265             if (mMaxFgActive > out.mMaxFgActive) {
266                 out.mMaxFgActive = mMaxFgActive;
267             }
268         }
269 
printDuration(PrintWriter pw, long period, long duration, int count, String suffix)270         void printDuration(PrintWriter pw, long period, long duration, int count, String suffix) {
271             float fraction = duration / (float) period;
272             int percent = (int) ((fraction * 100) + .5f);
273             if (percent > 0) {
274                 pw.print(" ");
275                 pw.print(percent);
276                 pw.print("% ");
277                 pw.print(count);
278                 pw.print("x ");
279                 pw.print(suffix);
280             } else if (count > 0) {
281                 pw.print(" ");
282                 pw.print(count);
283                 pw.print("x ");
284                 pw.print(suffix);
285             }
286         }
287 
dump(PrintWriter pw, String header, String prefix, long now, long nowEllapsed, int filterUid)288         void dump(PrintWriter pw, String header, String prefix, long now, long nowEllapsed,
289                 int filterUid) {
290             final long period = getTotalTime(now);
291             pw.print(prefix); pw.print(header); pw.print(" at ");
292             pw.print(DateFormat.format("yyyy-MM-dd-HH-mm-ss", mStartClockTime).toString());
293             pw.print(" (");
294             TimeUtils.formatDuration(mStartElapsedTime, nowEllapsed, pw);
295             pw.print(") over ");
296             TimeUtils.formatDuration(period, pw);
297             pw.println(":");
298             final int NE = mEntries.size();
299             for (int i = 0; i < NE; i++) {
300                 int uid = mEntries.keyAt(i);
301                 if (filterUid != -1 && filterUid != UserHandle.getAppId(uid)) {
302                     continue;
303                 }
304                 ArrayMap<String, PackageEntry> uidMap = mEntries.valueAt(i);
305                 final int NP = uidMap.size();
306                 for (int j = 0; j < NP; j++) {
307                     PackageEntry pe = uidMap.valueAt(j);
308                     pw.print(prefix); pw.print("  ");
309                     UserHandle.formatUid(pw, uid);
310                     pw.print(" / "); pw.print(uidMap.keyAt(j));
311                     pw.print(":");
312                     printDuration(pw, period, pe.getPendingTime(now), pe.pendingCount, "pending");
313                     printDuration(pw, period, pe.getActiveTime(now), pe.activeCount, "active");
314                     printDuration(pw, period, pe.getActiveTopTime(now), pe.activeTopCount,
315                             "active-top");
316                     if (pe.pendingNesting > 0 || pe.hadPending) {
317                         pw.print(" (pending)");
318                     }
319                     if (pe.activeNesting > 0 || pe.hadActive) {
320                         pw.print(" (active)");
321                     }
322                     if (pe.activeTopNesting > 0 || pe.hadActiveTop) {
323                         pw.print(" (active-top)");
324                     }
325                     pw.println();
326                 }
327             }
328             pw.print(prefix); pw.print("  Max concurrency: ");
329             pw.print(mMaxTotalActive); pw.print(" total, ");
330             pw.print(mMaxFgActive); pw.println(" foreground");
331         }
332     }
333 
rebatchIfNeeded(long now)334     void rebatchIfNeeded(long now) {
335         long totalTime = mCurDataSet.getTotalTime(now);
336         if (totalTime > BATCHING_TIME) {
337             DataSet last = mCurDataSet;
338             last.mSummedTime = totalTime;
339             mCurDataSet = new DataSet();
340             last.finish(mCurDataSet, now);
341             System.arraycopy(mLastDataSets, 0, mLastDataSets, 1, mLastDataSets.length-1);
342             mLastDataSets[0] = last;
343         }
344     }
345 
notePending(JobStatus job)346     public void notePending(JobStatus job) {
347         final long now = SystemClock.uptimeMillis();
348         job.madePending = now;
349         rebatchIfNeeded(now);
350         mCurDataSet.incPending(job.getSourceUid(), job.getSourcePackageName(), now);
351     }
352 
noteNonpending(JobStatus job)353     public void noteNonpending(JobStatus job) {
354         final long now = SystemClock.uptimeMillis();
355         mCurDataSet.decPending(job.getSourceUid(), job.getSourcePackageName(), now);
356         rebatchIfNeeded(now);
357     }
358 
noteActive(JobStatus job)359     public void noteActive(JobStatus job) {
360         final long now = SystemClock.uptimeMillis();
361         job.madeActive = now;
362         rebatchIfNeeded(now);
363         if (job.lastEvaluatedPriority >= JobInfo.PRIORITY_TOP_APP) {
364             mCurDataSet.incActiveTop(job.getSourceUid(), job.getSourcePackageName(), now);
365         } else {
366             mCurDataSet.incActive(job.getSourceUid(), job.getSourcePackageName(), now);
367         }
368         addEvent(EVENT_START_JOB, job.getSourceUid(), job.getBatteryName());
369     }
370 
noteInactive(JobStatus job)371     public void noteInactive(JobStatus job) {
372         final long now = SystemClock.uptimeMillis();
373         if (job.lastEvaluatedPriority >= JobInfo.PRIORITY_TOP_APP) {
374             mCurDataSet.decActiveTop(job.getSourceUid(), job.getSourcePackageName(), now);
375         } else {
376             mCurDataSet.decActive(job.getSourceUid(), job.getSourcePackageName(), now);
377         }
378         rebatchIfNeeded(now);
379         addEvent(EVENT_STOP_JOB, job.getSourceUid(), job.getBatteryName());
380     }
381 
noteConcurrency(int totalActive, int fgActive)382     public void noteConcurrency(int totalActive, int fgActive) {
383         if (totalActive > mCurDataSet.mMaxTotalActive) {
384             mCurDataSet.mMaxTotalActive = totalActive;
385         }
386         if (fgActive > mCurDataSet.mMaxFgActive) {
387             mCurDataSet.mMaxFgActive = fgActive;
388         }
389     }
390 
getLoadFactor(JobStatus job)391     public float getLoadFactor(JobStatus job) {
392         final int uid = job.getSourceUid();
393         final String pkg = job.getSourcePackageName();
394         PackageEntry cur = mCurDataSet.getEntry(uid, pkg);
395         PackageEntry last = mLastDataSets[0] != null ? mLastDataSets[0].getEntry(uid, pkg) : null;
396         if (cur == null && last == null) {
397             return 0;
398         }
399         final long now = SystemClock.uptimeMillis();
400         long time = 0;
401         if (cur != null) {
402             time += cur.getActiveTime(now) + cur.getPendingTime(now);
403         }
404         long period = mCurDataSet.getTotalTime(now);
405         if (last != null) {
406             time += last.getActiveTime(now) + last.getPendingTime(now);
407             period += mLastDataSets[0].getTotalTime(now);
408         }
409         return time / (float)period;
410     }
411 
dump(PrintWriter pw, String prefix, int filterUid)412     public void dump(PrintWriter pw, String prefix, int filterUid) {
413         final long now = SystemClock.uptimeMillis();
414         final long nowEllapsed = SystemClock.elapsedRealtime();
415         final DataSet total;
416         if (mLastDataSets[0] != null) {
417             total = new DataSet(mLastDataSets[0]);
418             mLastDataSets[0].addTo(total, now);
419         } else {
420             total = new DataSet(mCurDataSet);
421         }
422         mCurDataSet.addTo(total, now);
423         for (int i = 1; i < mLastDataSets.length; i++) {
424             if (mLastDataSets[i] != null) {
425                 mLastDataSets[i].dump(pw, "Historical stats", prefix, now, nowEllapsed, filterUid);
426                 pw.println();
427             }
428         }
429         total.dump(pw, "Current stats", prefix, now, nowEllapsed, filterUid);
430     }
431 
dumpHistory(PrintWriter pw, String prefix, int filterUid)432     public boolean dumpHistory(PrintWriter pw, String prefix, int filterUid) {
433         final int size = mEventIndices.size();
434         if (size <= 0) {
435             return false;
436         }
437         pw.println("  Job history:");
438         final long now = SystemClock.elapsedRealtime();
439         for (int i=0; i<size; i++) {
440             final int index = mEventIndices.indexOf(i);
441             final int uid = mEventUids[index];
442             if (filterUid != -1 && filterUid != UserHandle.getAppId(uid)) {
443                 continue;
444             }
445             final int cmd = mEventCmds[index];
446             if (cmd == EVENT_NULL) {
447                 continue;
448             }
449             final String label;
450             switch (mEventCmds[index]) {
451                 case EVENT_START_JOB:           label = "START"; break;
452                 case EVENT_STOP_JOB:            label = " STOP"; break;
453                 default:                        label = "   ??"; break;
454             }
455             pw.print(prefix);
456             TimeUtils.formatDuration(mEventTimes[index]-now, pw, TimeUtils.HUNDRED_DAY_FIELD_LEN);
457             pw.print(" ");
458             pw.print(label);
459             pw.print(": ");
460             UserHandle.formatUid(pw, uid);
461             pw.print(" ");
462             pw.println(mEventTags[index]);
463         }
464         return true;
465     }
466 }
467