Merge "Log deferred jobs metrics to batterystats"
diff --git a/core/java/android/os/BatteryStats.java b/core/java/android/os/BatteryStats.java
index 7cd58e8..6ecf6d5 100644
--- a/core/java/android/os/BatteryStats.java
+++ b/core/java/android/os/BatteryStats.java
@@ -287,6 +287,16 @@
private static final String SYNC_DATA = "sy";
private static final String JOB_DATA = "jb";
private static final String JOB_COMPLETION_DATA = "jbc";
+
+ /**
+ * jbd line is:
+ * BATTERY_STATS_CHECKIN_VERSION, uid, which, "jbd",
+ * jobsDeferredEventCount, jobsDeferredCount, averageLatencyMillis,
+ * count at latency < 1 hr, count at latency < 2 hrs, count at latency < 6 hrs, beyond 6 hrs
+ * <p>
+ * @see #JOB_FRESHNESS_BUCKETS
+ */
+ private static final String JOBS_DEFERRED_DATA = "jbd";
private static final String KERNEL_WAKELOCK_DATA = "kwl";
private static final String WAKEUP_REASON_DATA = "wr";
private static final String NETWORK_DATA = "nt";
@@ -349,6 +359,19 @@
public static final String UID_TIMES_TYPE_ALL = "A";
/**
+ * These are the thresholds for bucketing last time since a job was run for an app
+ * that just moved to ACTIVE due to a launch. So if the last time a job ran was less
+ * than 30 minutes ago, then it's reasonably fresh, 2 hours ago, not so fresh and so
+ * on.
+ */
+ public static final long[] JOB_FRESHNESS_BUCKETS = {
+ 1 * 60 * 60 * 1000L,
+ 2 * 60 * 60 * 1000L,
+ 6 * 60 * 60 * 1000L,
+ Long.MAX_VALUE
+ };
+
+ /**
* State for keeping track of counting information.
*/
public static abstract class Counter {
@@ -846,6 +869,20 @@
*/
public abstract long getWifiRadioApWakeupCount(int which);
+ /**
+ * Appends the deferred jobs data to the StringBuilder passed in, in checkin format
+ * @param sb StringBuilder that can be overwritten with the deferred jobs data
+ * @param which one of STATS_*
+ */
+ public abstract void getDeferredJobsCheckinLineLocked(StringBuilder sb, int which);
+
+ /**
+ * Appends the deferred jobs data to the StringBuilder passed in
+ * @param sb StringBuilder that can be overwritten with the deferred jobs data
+ * @param which one of STATS_*
+ */
+ public abstract void getDeferredJobsLineLocked(StringBuilder sb, int which);
+
public static abstract class Sensor {
/*
* FIXME: it's not correct to use this magic value because it
@@ -4070,6 +4107,12 @@
}
}
+ // Dump deferred jobs stats
+ u.getDeferredJobsCheckinLineLocked(sb, which);
+ if (sb.length() > 0) {
+ dumpLine(pw, uid, category, JOBS_DEFERRED_DATA, sb.toString());
+ }
+
dumpTimer(pw, uid, category, FLASHLIGHT_DATA, u.getFlashlightTurnedOnTimer(),
rawRealtime, which);
dumpTimer(pw, uid, category, CAMERA_DATA, u.getCameraTurnedOnTimer(),
@@ -5698,6 +5741,11 @@
}
}
+ u.getDeferredJobsLineLocked(sb, which);
+ if (sb.length() > 0) {
+ pw.print(" Jobs deferred on launch "); pw.println(sb.toString());
+ }
+
uidActivity |= printTimer(pw, sb, u.getFlashlightTurnedOnTimer(), rawRealtime, which,
prefix, "Flashlight");
uidActivity |= printTimer(pw, sb, u.getCameraTurnedOnTimer(), rawRealtime, which,
diff --git a/core/java/android/os/BatteryStatsInternal.java b/core/java/android/os/BatteryStatsInternal.java
index b0436eb..679f18e 100644
--- a/core/java/android/os/BatteryStatsInternal.java
+++ b/core/java/android/os/BatteryStatsInternal.java
@@ -18,7 +18,7 @@
/**
* Battery stats local system service interface. This is used to pass internal data out of
- * BatteryStatsImpl.
+ * BatteryStatsImpl, as well as make unchecked calls into BatteryStatsImpl.
*
* @hide Only for use within Android OS.
*/
@@ -32,4 +32,13 @@
* Returns the mobile data interfaces.
*/
public abstract String[] getMobileIfaces();
+
+ /**
+ * Inform battery stats how many deferred jobs existed when the app got launched and how
+ * long ago was the last job execution for the app.
+ * @param uid the uid of the app.
+ * @param numDeferred number of deferred jobs.
+ * @param sinceLast how long in millis has it been since a job was run
+ */
+ public abstract void noteJobsDeferred(int uid, int numDeferred, long sinceLast);
}
diff --git a/core/java/com/android/internal/os/BatteryStatsImpl.java b/core/java/com/android/internal/os/BatteryStatsImpl.java
index 4e51591..d1932cf 100644
--- a/core/java/com/android/internal/os/BatteryStatsImpl.java
+++ b/core/java/com/android/internal/os/BatteryStatsImpl.java
@@ -134,7 +134,7 @@
private static final int MAGIC = 0xBA757475; // 'BATSTATS'
// Current on-disk Parcel version
- private static final int VERSION = 174 + (USE_OLD_HISTORY ? 1000 : 0);
+ private static final int VERSION = 175 + (USE_OLD_HISTORY ? 1000 : 0);
// Maximum number of items we will record in the history.
private static final int MAX_HISTORY_ITEMS;
@@ -1222,7 +1222,7 @@
* @param out the Parcel to be written to.
* @param counter a Counter, or null.
*/
- public static void writeCounterToParcel(Parcel out, Counter counter) {
+ public static void writeCounterToParcel(Parcel out, @Nullable Counter counter) {
if (counter == null) {
out.writeInt(0); // indicates null
return;
@@ -1232,6 +1232,19 @@
counter.writeToParcel(out);
}
+ /**
+ * Reads a Counter that was written using {@link #writeCounterToParcel(Parcel, Counter)}.
+ * @param timeBase the timebase to assign to the Counter
+ * @param in the parcel to read from
+ * @return the Counter or null.
+ */
+ public static @Nullable Counter readCounterFromParcel(TimeBase timeBase, Parcel in) {
+ if (in.readInt() == 0) {
+ return null;
+ }
+ return new Counter(timeBase, in);
+ }
+
@Override
public int getCountLocked(int which) {
int val = mCount.get();
@@ -4071,6 +4084,11 @@
addHistoryEventLocked(elapsedRealtime, uptime, HistoryItem.EVENT_JOB_FINISH, name, uid);
}
+ public void noteJobsDeferredLocked(int uid, int numDeferred, long sinceLast) {
+ uid = mapUid(uid);
+ getUidStatsLocked(uid).noteJobsDeferredLocked(numDeferred, sinceLast);
+ }
+
public void noteAlarmStartLocked(String name, WorkSource workSource, int uid) {
noteAlarmStartOrFinishLocked(HistoryItem.EVENT_ALARM_START, name, workSource, uid);
}
@@ -6749,6 +6767,29 @@
final ArrayMap<String, SparseIntArray> mJobCompletions = new ArrayMap<>();
/**
+ * Count of app launch events that had associated deferred job counts or info about
+ * last time a job was run.
+ */
+ Counter mJobsDeferredEventCount;
+
+ /**
+ * Count of deferred jobs that were pending when the app was launched or brought to
+ * the foreground through a user interaction.
+ */
+ Counter mJobsDeferredCount;
+
+ /**
+ * Sum of time since the last time a job was run for this app before it was launched.
+ */
+ LongSamplingCounter mJobsFreshnessTimeMs;
+
+ /**
+ * Array of counts of instances where the time since the last job was run for the app
+ * fell within one of the thresholds in {@link #JOB_FRESHNESS_BUCKETS}.
+ */
+ final Counter[] mJobsFreshnessBuckets;
+
+ /**
* The statistics we have collected for this uid's sensor activations.
*/
final SparseArray<Sensor> mSensorStats = new SparseArray<>();
@@ -6822,6 +6863,10 @@
mWifiMulticastTimer = new StopwatchTimer(mBsi.mClocks, this, WIFI_MULTICAST_ENABLED,
mBsi.mWifiMulticastTimers, mBsi.mOnBatteryTimeBase);
mProcessStateTimer = new StopwatchTimer[NUM_PROCESS_STATE];
+ mJobsDeferredEventCount = new Counter(mBsi.mOnBatteryTimeBase);
+ mJobsDeferredCount = new Counter(mBsi.mOnBatteryTimeBase);
+ mJobsFreshnessTimeMs = new LongSamplingCounter(mBsi.mOnBatteryTimeBase);
+ mJobsFreshnessBuckets = new Counter[JOB_FRESHNESS_BUCKETS.length];
}
@VisibleForTesting
@@ -7799,6 +7844,55 @@
return 0;
}
+ @Override
+ public void getDeferredJobsCheckinLineLocked(StringBuilder sb, int which) {
+ sb.setLength(0);
+ final int deferredEventCount = mJobsDeferredEventCount.getCountLocked(which);
+ if (deferredEventCount == 0) {
+ return;
+ }
+ final int deferredCount = mJobsDeferredCount.getCountLocked(which);
+ final long averageLatency = deferredEventCount != 0
+ ? mJobsFreshnessTimeMs.getCountLocked(which) / deferredEventCount
+ : 0L;
+ sb.append(deferredEventCount); sb.append(',');
+ sb.append(deferredCount); sb.append(',');
+ sb.append(averageLatency);
+ for (int i = 0; i < JOB_FRESHNESS_BUCKETS.length; i++) {
+ if (mJobsFreshnessBuckets[i] == null) {
+ sb.append(",0");
+ } else {
+ sb.append(",");
+ sb.append(mJobsFreshnessBuckets[i].getCountLocked(which));
+ }
+ }
+ }
+
+ @Override
+ public void getDeferredJobsLineLocked(StringBuilder sb, int which) {
+ sb.setLength(0);
+ final int deferredEventCount = mJobsDeferredEventCount.getCountLocked(which);
+ if (deferredEventCount == 0) {
+ return;
+ }
+ final int deferredCount = mJobsDeferredCount.getCountLocked(which);
+ final long averageLatency = deferredEventCount != 0
+ ? mJobsFreshnessTimeMs.getCountLocked(which) / deferredEventCount
+ : 0L;
+ sb.append("times="); sb.append(deferredEventCount); sb.append(", ");
+ sb.append("count="); sb.append(deferredCount); sb.append(", ");
+ sb.append("avgLatency="); sb.append(averageLatency); sb.append(", ");
+ for (int i = 0; i < JOB_FRESHNESS_BUCKETS.length; i++) {
+ sb.append("<"); sb.append(JOB_FRESHNESS_BUCKETS[i]); sb.append("ms=");
+ if (mJobsFreshnessBuckets[i] == null) {
+ sb.append("0");
+ } else {
+ sb.append(mJobsFreshnessBuckets[i].getCountLocked(which));
+ }
+ sb.append(" ");
+ }
+ }
+
void initNetworkActivityLocked() {
mNetworkByteActivityCounters = new LongSamplingCounter[NUM_NETWORK_ACTIVITY_TYPES];
mNetworkPacketActivityCounters = new LongSamplingCounter[NUM_NETWORK_ACTIVITY_TYPES];
@@ -7982,6 +8076,16 @@
}
mJobStats.cleanup();
mJobCompletions.clear();
+
+ mJobsDeferredEventCount.reset(false);
+ mJobsDeferredCount.reset(false);
+ mJobsFreshnessTimeMs.reset(false);
+ for (int ij = 0; ij < JOB_FRESHNESS_BUCKETS.length; ij++) {
+ if (mJobsFreshnessBuckets[ij] != null) {
+ mJobsFreshnessBuckets[ij].reset(false);
+ }
+ }
+
for (int ise=mSensorStats.size()-1; ise>=0; ise--) {
Sensor s = mSensorStats.valueAt(ise);
if (s.reset()) {
@@ -7990,6 +8094,7 @@
active = true;
}
}
+
for (int ip=mProcessStats.size()-1; ip>=0; ip--) {
Proc proc = mProcessStats.valueAt(ip);
proc.detach();
@@ -8207,6 +8312,13 @@
writeJobCompletionsToParcelLocked(out);
+ mJobsDeferredEventCount.writeToParcel(out);
+ mJobsDeferredCount.writeToParcel(out);
+ mJobsFreshnessTimeMs.writeToParcel(out);
+ for (int i = 0; i < JOB_FRESHNESS_BUCKETS.length; i++) {
+ Counter.writeCounterToParcel(out, mJobsFreshnessBuckets[i]);
+ }
+
int NSE = mSensorStats.size();
out.writeInt(NSE);
for (int ise=0; ise<NSE; ise++) {
@@ -8502,6 +8614,14 @@
readJobCompletionsFromParcelLocked(in);
+ mJobsDeferredEventCount = new Counter(mBsi.mOnBatteryTimeBase, in);
+ mJobsDeferredCount = new Counter(mBsi.mOnBatteryTimeBase, in);
+ mJobsFreshnessTimeMs = new LongSamplingCounter(mBsi.mOnBatteryTimeBase, in);
+ for (int i = 0; i < JOB_FRESHNESS_BUCKETS.length; i++) {
+ mJobsFreshnessBuckets[i] = Counter.readCounterFromParcel(mBsi.mOnBatteryTimeBase,
+ in);
+ }
+
int numSensors = in.readInt();
mSensorStats.clear();
for (int k = 0; k < numSensors; k++) {
@@ -8770,6 +8890,26 @@
}
}
+ public void noteJobsDeferredLocked(int numDeferred, long sinceLast) {
+ mJobsDeferredEventCount.addAtomic(1);
+ mJobsDeferredCount.addAtomic(numDeferred);
+ if (sinceLast != 0) {
+ // Add the total time, which can be divided by the event count to get an average
+ mJobsFreshnessTimeMs.addCountLocked(sinceLast);
+ // Also keep track of how many times there were in these different buckets.
+ for (int i = 0; i < JOB_FRESHNESS_BUCKETS.length; i++) {
+ if (sinceLast < JOB_FRESHNESS_BUCKETS[i]) {
+ if (mJobsFreshnessBuckets[i] == null) {
+ mJobsFreshnessBuckets[i] = new Counter(
+ mBsi.mOnBatteryTimeBase);
+ }
+ mJobsFreshnessBuckets[i].addAtomic(1);
+ break;
+ }
+ }
+ }
+ }
+
/**
* The statistics associated with a particular wake lock.
*/
@@ -13921,6 +14061,16 @@
u.readJobCompletionsFromParcelLocked(in);
+ u.mJobsDeferredEventCount.readSummaryFromParcelLocked(in);
+ u.mJobsDeferredCount.readSummaryFromParcelLocked(in);
+ u.mJobsFreshnessTimeMs.readSummaryFromParcelLocked(in);
+ for (int i = 0; i < JOB_FRESHNESS_BUCKETS.length; i++) {
+ if (in.readInt() != 0) {
+ u.mJobsFreshnessBuckets[i] = new Counter(u.mBsi.mOnBatteryTimeBase);
+ u.mJobsFreshnessBuckets[i].readSummaryFromParcelLocked(in);
+ }
+ }
+
int NP = in.readInt();
if (NP > 1000) {
throw new ParcelFormatException("File corrupt: too many sensors " + NP);
@@ -14419,6 +14569,17 @@
u.writeJobCompletionsToParcelLocked(out);
+ u.mJobsDeferredEventCount.writeSummaryFromParcelLocked(out);
+ u.mJobsDeferredCount.writeSummaryFromParcelLocked(out);
+ u.mJobsFreshnessTimeMs.writeSummaryFromParcelLocked(out);
+ for (int i = 0; i < JOB_FRESHNESS_BUCKETS.length; i++) {
+ if (u.mJobsFreshnessBuckets[i] != null) {
+ u.mJobsFreshnessBuckets[i].writeSummaryFromParcelLocked(out);
+ } else {
+ out.writeInt(0);
+ }
+ }
+
int NSE = u.mSensorStats.size();
out.writeInt(NSE);
for (int ise=0; ise<NSE; ise++) {
diff --git a/services/core/java/com/android/server/am/BatteryStatsService.java b/services/core/java/com/android/server/am/BatteryStatsService.java
index 9d1adb2..dd2358c 100644
--- a/services/core/java/com/android/server/am/BatteryStatsService.java
+++ b/services/core/java/com/android/server/am/BatteryStatsService.java
@@ -202,6 +202,12 @@
public String[] getMobileIfaces() {
return mStats.getMobileIfaces().clone();
}
+
+ @Override
+ public void noteJobsDeferred(int uid, int numDeferred, long sinceLast) {
+ if (DBG) Slog.d(TAG, "Jobs deferred " + uid + ": " + numDeferred + " " + sinceLast);
+ BatteryStatsService.this.noteJobsDeferred(uid, numDeferred, sinceLast);
+ }
}
private static void awaitUninterruptibly(Future<?> future) {
@@ -456,6 +462,13 @@
}
}
+ void noteJobsDeferred(int uid, int numDeferred, long sinceLast) {
+ // No need to enforce calling permission, as it is called from an internal interface
+ synchronized (mStats) {
+ mStats.noteJobsDeferredLocked(uid, numDeferred, sinceLast);
+ }
+ }
+
public void noteWakupAlarm(String name, int uid, WorkSource workSource, String tag) {
enforceCallingPermission();
synchronized (mStats) {
diff --git a/services/core/java/com/android/server/job/JobSchedulerService.java b/services/core/java/com/android/server/job/JobSchedulerService.java
index c33d7f4..05c7f19 100644
--- a/services/core/java/com/android/server/job/JobSchedulerService.java
+++ b/services/core/java/com/android/server/job/JobSchedulerService.java
@@ -49,6 +49,7 @@
import android.database.ContentObserver;
import android.net.Uri;
import android.os.BatteryStats;
+import android.os.BatteryStatsInternal;
import android.os.Binder;
import android.os.Handler;
import android.os.Looper;
@@ -62,6 +63,7 @@
import android.os.UserHandle;
import android.os.UserManagerInternal;
import android.provider.Settings;
+import android.text.format.DateUtils;
import android.util.KeyValueListParser;
import android.util.Slog;
import android.util.SparseArray;
@@ -2282,14 +2284,20 @@
return;
}
- final long sinceLast = sElapsedRealtimeClock.millis() -
- mUsageStats.getTimeSinceLastJobRun(packageName, userId);
+ long sinceLast = mUsageStats.getTimeSinceLastJobRun(packageName, userId);
+ if (sinceLast > 2 * DateUtils.DAY_IN_MILLIS) {
+ // Too long ago, not worth logging
+ sinceLast = 0L;
+ }
final DeferredJobCounter counter = new DeferredJobCounter();
synchronized (mLock) {
mJobs.forEachJobForSourceUid(uid, counter);
}
-
- mUsageStats.reportAppJobState(packageName, userId, counter.numDeferred(), sinceLast);
+ if (counter.numDeferred() > 0 || sinceLast > 0) {
+ BatteryStatsInternal mBatteryStatsInternal = LocalServices.getService
+ (BatteryStatsInternal.class);
+ mBatteryStatsInternal.noteJobsDeferred(uid, counter.numDeferred(), sinceLast);
+ }
}
}