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