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