From 62793e4382b4b0b53d7373d92a62dc4e3ccbde05 Mon Sep 17 00:00:00 2001 From: Dianne Hackborn Date: Mon, 9 Mar 2015 11:15:41 -0700 Subject: Battery stats issues: fix jiffy handling, print scan counts. Issue #19431959: Framework incorrectly assumes that kernel clock_ticks are 10ms We now retrieve the time of a jiffy from the kernel, and all CPU times are now handled in milliseconds. Issue #19571810: Add per-app breakdown of number of WiFi scans in batterystats checkin data Added to the report (the information was already being tracked). Change-Id: If1702d6b9bcf851704129f1811471e68ed576a5d --- core/java/android/os/BatteryStats.java | 41 +++++++++++---------- .../android/internal/os/BatteryStatsHelper.java | 4 +-- .../com/android/internal/os/BatteryStatsImpl.java | 23 ++++++++++-- .../com/android/internal/os/ProcessCpuTracker.java | 42 +++++++++++++--------- 4 files changed, 67 insertions(+), 43 deletions(-) (limited to 'core') diff --git a/core/java/android/os/BatteryStats.java b/core/java/android/os/BatteryStats.java index 0fee4b3..d03fe41 100644 --- a/core/java/android/os/BatteryStats.java +++ b/core/java/android/os/BatteryStats.java @@ -86,10 +86,10 @@ public abstract class BatteryStats implements Parcelable { */ public static final int WIFI_SCAN = 6; - /** - * A constant indicating a wifi multicast timer - */ - public static final int WIFI_MULTICAST_ENABLED = 7; + /** + * A constant indicating a wifi multicast timer + */ + public static final int WIFI_MULTICAST_ENABLED = 7; /** * A constant indicating a video turn on timer @@ -353,7 +353,9 @@ public abstract class BatteryStats implements Parcelable { public abstract long getWifiRunningTime(long elapsedRealtimeUs, int which); public abstract long getFullWifiLockTime(long elapsedRealtimeUs, int which); public abstract long getWifiScanTime(long elapsedRealtimeUs, int which); + public abstract int getWifiScanCount(int which); public abstract long getWifiBatchedScanTime(int csphBin, long elapsedRealtimeUs, int which); + public abstract int getWifiBatchedScanCount(int csphBin, int which); public abstract long getWifiMulticastTime(long elapsedRealtimeUs, int which); public abstract long getAudioTurnedOnTime(long elapsedRealtimeUs, int which); public abstract long getVideoTurnedOnTime(long elapsedRealtimeUs, int which); @@ -2140,13 +2142,6 @@ public abstract class BatteryStats implements Parcelable { } } - public final static void formatTime(StringBuilder sb, long time) { - long sec = time / 100; - formatTimeRaw(sb, sec); - sb.append((time - (sec * 100)) * 10); - sb.append("ms "); - } - public final static void formatTimeMs(StringBuilder sb, long time) { long sec = time / 1000; formatTimeRaw(sb, sec); @@ -2572,6 +2567,7 @@ public abstract class BatteryStats implements Parcelable { long wifiPacketsTx = u.getNetworkActivityPackets(NETWORK_WIFI_TX_DATA, which); long fullWifiLockOnTime = u.getFullWifiLockTime(rawRealtime, which); long wifiScanTime = u.getWifiScanTime(rawRealtime, which); + int wifiScanCount = u.getWifiScanCount(which); long uidWifiRunningTime = u.getWifiRunningTime(rawRealtime, which); if (mobileBytesRx > 0 || mobileBytesTx > 0 || wifiBytesRx > 0 || wifiBytesTx > 0 @@ -2584,10 +2580,10 @@ public abstract class BatteryStats implements Parcelable { mobileActiveTime, mobileActiveCount); } - if (fullWifiLockOnTime != 0 || wifiScanTime != 0 + if (fullWifiLockOnTime != 0 || wifiScanTime != 0 || wifiScanCount != 0 || uidWifiRunningTime != 0) { dumpLine(pw, uid, category, WIFI_DATA, - fullWifiLockOnTime, wifiScanTime, uidWifiRunningTime); + fullWifiLockOnTime, wifiScanTime, uidWifiRunningTime, wifiScanCount); } if (u.hasUserActivity()) { @@ -2705,9 +2701,9 @@ public abstract class BatteryStats implements Parcelable { : processStats.entrySet()) { Uid.Proc ps = ent.getValue(); - final long userMillis = ps.getUserTime(which) * 10; - final long systemMillis = ps.getSystemTime(which) * 10; - final long foregroundMillis = ps.getForegroundTime(which) * 10; + final long userMillis = ps.getUserTime(which); + final long systemMillis = ps.getSystemTime(which); + final long foregroundMillis = ps.getForegroundTime(which); final int starts = ps.getStarts(which); final int numCrashes = ps.getNumCrashes(which); final int numAnrs = ps.getNumAnrs(which); @@ -3420,6 +3416,7 @@ public abstract class BatteryStats implements Parcelable { long wifiTxPackets = u.getNetworkActivityPackets(NETWORK_WIFI_TX_DATA, which); long fullWifiLockOnTime = u.getFullWifiLockTime(rawRealtime, which); long wifiScanTime = u.getWifiScanTime(rawRealtime, which); + int wifiScanCount = u.getWifiScanCount(which); long uidWifiRunningTime = u.getWifiRunningTime(rawRealtime, which); if (mobileRxBytes > 0 || mobileTxBytes > 0 @@ -3455,7 +3452,7 @@ public abstract class BatteryStats implements Parcelable { pw.print(" received, "); pw.print(wifiTxPackets); pw.println(" sent)"); } - if (fullWifiLockOnTime != 0 || wifiScanTime != 0 + if (fullWifiLockOnTime != 0 || wifiScanTime != 0 || wifiScanCount != 0 || uidWifiRunningTime != 0) { sb.setLength(0); sb.append(prefix); sb.append(" Wifi Running: "); @@ -3469,7 +3466,9 @@ public abstract class BatteryStats implements Parcelable { sb.append(prefix); sb.append(" Wifi Scan: "); formatTimeMs(sb, wifiScanTime / 1000); sb.append("("); sb.append(formatRatioLocked(wifiScanTime, - whichBatteryRealtime)); sb.append(")"); + whichBatteryRealtime)); sb.append(") "); + sb.append(wifiScanCount); + sb.append("x"); pw.println(sb.toString()); } @@ -3728,9 +3727,9 @@ public abstract class BatteryStats implements Parcelable { sb.append(prefix); sb.append(" Proc "); sb.append(ent.getKey()); sb.append(":\n"); sb.append(prefix); sb.append(" CPU: "); - formatTime(sb, userTime); sb.append("usr + "); - formatTime(sb, systemTime); sb.append("krn ; "); - formatTime(sb, foregroundTime); sb.append("fg"); + formatTimeMs(sb, userTime); sb.append("usr + "); + formatTimeMs(sb, systemTime); sb.append("krn ; "); + formatTimeMs(sb, foregroundTime); sb.append("fg"); if (starts != 0 || numCrashes != 0 || numAnrs != 0) { sb.append("\n"); sb.append(prefix); sb.append(" "); boolean hasOne = false; diff --git a/core/java/com/android/internal/os/BatteryStatsHelper.java b/core/java/com/android/internal/os/BatteryStatsHelper.java index eae4427..5d73be0 100644 --- a/core/java/com/android/internal/os/BatteryStatsHelper.java +++ b/core/java/com/android/internal/os/BatteryStatsHelper.java @@ -425,8 +425,8 @@ public final class BatteryStatsHelper { final long userTime = ps.getUserTime(which); final long systemTime = ps.getSystemTime(which); final long foregroundTime = ps.getForegroundTime(which); - cpuFgTime += foregroundTime * 10; // convert to millis - final long tmpCpuTime = (userTime + systemTime) * 10; // convert to millis + cpuFgTime += foregroundTime; + final long tmpCpuTime = userTime + systemTime; int totalTimeAtSpeeds = 0; // Get the total first for (int step = 0; step < speedSteps; step++) { diff --git a/core/java/com/android/internal/os/BatteryStatsImpl.java b/core/java/com/android/internal/os/BatteryStatsImpl.java index f6c5dc7..e02b959 100644 --- a/core/java/com/android/internal/os/BatteryStatsImpl.java +++ b/core/java/com/android/internal/os/BatteryStatsImpl.java @@ -4749,6 +4749,14 @@ public final class BatteryStatsImpl extends BatteryStats { } @Override + public int getWifiScanCount(int which) { + if (mWifiScanTimer == null) { + return 0; + } + return mWifiScanTimer.getCountLocked(which); + } + + @Override public long getWifiBatchedScanTime(int csphBin, long elapsedRealtimeUs, int which) { if (csphBin < 0 || csphBin >= NUM_WIFI_BATCHED_SCAN_BINS) return 0; if (mWifiBatchedScanTimer[csphBin] == null) { @@ -4758,6 +4766,15 @@ public final class BatteryStatsImpl extends BatteryStats { } @Override + public int getWifiBatchedScanCount(int csphBin, int which) { + if (csphBin < 0 || csphBin >= NUM_WIFI_BATCHED_SCAN_BINS) return 0; + if (mWifiBatchedScanTimer[csphBin] == null) { + return 0; + } + return mWifiBatchedScanTimer[csphBin].getCountLocked(which); + } + + @Override public long getWifiMulticastTime(long elapsedRealtimeUs, int which) { if (mWifiMulticastTimer == null) { return 0; @@ -5601,17 +5618,17 @@ public final class BatteryStatsImpl extends BatteryStats { boolean mActive = true; /** - * Total time (in 1/100 sec) spent executing in user code. + * Total time (in ms) spent executing in user code. */ long mUserTime; /** - * Total time (in 1/100 sec) spent executing in kernel code. + * Total time (in ms) spent executing in kernel code. */ long mSystemTime; /** - * Amount of time the process was running in the foreground. + * Amount of time (in ms) the process was running in the foreground. */ long mForegroundTime; diff --git a/core/java/com/android/internal/os/ProcessCpuTracker.java b/core/java/com/android/internal/os/ProcessCpuTracker.java index 501e0ec..2983047 100644 --- a/core/java/com/android/internal/os/ProcessCpuTracker.java +++ b/core/java/com/android/internal/os/ProcessCpuTracker.java @@ -22,11 +22,13 @@ import android.os.FileUtils; import android.os.Process; import android.os.StrictMode; import android.os.SystemClock; +import android.system.OsConstants; import android.util.Slog; import com.android.internal.util.FastPrintWriter; import libcore.io.IoUtils; +import libcore.io.Libcore; import java.io.File; import java.io.FileInputStream; @@ -130,6 +132,9 @@ public class ProcessCpuTracker { private final boolean mIncludeThreads; + // How long a CPU jiffy is in milliseconds. + private final long mJiffyMillis; + private float mLoad1 = 0; private float mLoad5 = 0; private float mLoad15 = 0; @@ -269,6 +274,8 @@ public class ProcessCpuTracker { public ProcessCpuTracker(boolean includeThreads) { mIncludeThreads = includeThreads; + long jiffyHz = Libcore.os.sysconf(OsConstants._SC_CLK_TCK); + mJiffyMillis = 1000/jiffyHz; } public void onLoadChanged(float load1, float load5, float load15) { @@ -294,15 +301,15 @@ public class ProcessCpuTracker { if (Process.readProcFile("/proc/stat", SYSTEM_CPU_FORMAT, null, sysCpu, null)) { // Total user time is user + nice time. - final long usertime = sysCpu[0]+sysCpu[1]; + final long usertime = (sysCpu[0]+sysCpu[1]) * mJiffyMillis; // Total system time is simply system time. - final long systemtime = sysCpu[2]; + final long systemtime = sysCpu[2] * mJiffyMillis; // Total idle time is simply idle time. - final long idletime = sysCpu[3]; + final long idletime = sysCpu[3] * mJiffyMillis; // Total irq time is iowait + irq + softirq time. - final long iowaittime = sysCpu[4]; - final long irqtime = sysCpu[5]; - final long softirqtime = sysCpu[6]; + final long iowaittime = sysCpu[4] * mJiffyMillis; + final long irqtime = sysCpu[5] * mJiffyMillis; + final long softirqtime = sysCpu[6] * mJiffyMillis; // This code is trying to avoid issues with idle time going backwards, // but currently it gets into situations where it triggers most of the time. :( @@ -318,10 +325,11 @@ public class ProcessCpuTracker { mRelStatsAreGood = true; if (DEBUG) { - Slog.i("Load", "Total U:" + sysCpu[0] + " N:" + sysCpu[1] - + " S:" + sysCpu[2] + " I:" + sysCpu[3] - + " W:" + sysCpu[4] + " Q:" + sysCpu[5] - + " O:" + sysCpu[6]); + Slog.i("Load", "Total U:" + (sysCpu[0]*mJiffyMillis) + + " N:" + (sysCpu[1]*mJiffyMillis) + + " S:" + (sysCpu[2]*mJiffyMillis) + " I:" + (sysCpu[3]*mJiffyMillis) + + " W:" + (sysCpu[4]*mJiffyMillis) + " Q:" + (sysCpu[5]*mJiffyMillis) + + " O:" + (sysCpu[6]*mJiffyMillis)); Slog.i("Load", "Rel U:" + mRelUserTime + " S:" + mRelSystemTime + " I:" + mRelIdleTime + " Q:" + mRelIrqTime); } @@ -414,8 +422,8 @@ public class ProcessCpuTracker { final long minfaults = procStats[PROCESS_STAT_MINOR_FAULTS]; final long majfaults = procStats[PROCESS_STAT_MAJOR_FAULTS]; - final long utime = procStats[PROCESS_STAT_UTIME]; - final long stime = procStats[PROCESS_STAT_STIME]; + final long utime = procStats[PROCESS_STAT_UTIME] * mJiffyMillis; + final long stime = procStats[PROCESS_STAT_STIME] * mJiffyMillis; if (utime == st.base_utime && stime == st.base_stime) { st.rel_utime = 0; @@ -489,8 +497,8 @@ public class ProcessCpuTracker { st.baseName = procStatsString[0]; st.base_minfaults = procStats[PROCESS_FULL_STAT_MINOR_FAULTS]; st.base_majfaults = procStats[PROCESS_FULL_STAT_MAJOR_FAULTS]; - st.base_utime = procStats[PROCESS_FULL_STAT_UTIME]; - st.base_stime = procStats[PROCESS_FULL_STAT_STIME]; + st.base_utime = procStats[PROCESS_FULL_STAT_UTIME] * mJiffyMillis; + st.base_stime = procStats[PROCESS_FULL_STAT_STIME] * mJiffyMillis; } else { Slog.i(TAG, "Skipping kernel process pid " + pid + " name " + procStatsString[0]); @@ -576,7 +584,7 @@ public class ProcessCpuTracker { null, statsData, null)) { long time = statsData[PROCESS_STAT_UTIME] + statsData[PROCESS_STAT_STIME]; - return time; + return time * mJiffyMillis; } return 0; } @@ -777,7 +785,7 @@ public class ProcessCpuTracker { for (int i=0; i