From d84ad30ee62ee9610ed4a59a8ce4dcbb8eddf7d8 Mon Sep 17 00:00:00 2001 From: Adam Lesinski Date: Tue, 17 May 2016 18:31:02 -0700 Subject: [PATCH] Fix parsing of kernel wakelocks We handled stale wakelocks (wakelocks that disappear from /d/wakeup_sources) differently in previous version of Android. They would be set stale, but still be updated with their previous counts (they would never disappear). The method setStale has been replaced with endSample(), which is semantically different. Once a SamplingTimer has endSample() called, it expects any future calls to update() to be a new sample, meaning the entire amount passed to update() is included in the kernel wakelock's total. Since stale wakelocks were never removed from the list, this would increase by large amounts when nothing had actually changed. This was exacerbated by the fact that there was a bug where the last wakelock in /d/wakeup_sources was never parsed, so if the order ever changed, this "stale" wakelock would suddenly re-appear and the entire amount reported would be charged to the wakelock, instead of just the difference since the last update. All this was exposed when we added support to handle wakelocks that would disappear and reappear with smaller values, meaning the kernel had pruned them from its accounting and reset them. Bug:28601080 Change-Id: Ic96027f7d580dac5e20aa73d67e5cedac4ccabeb --- .../android/internal/os/BatteryStatsImpl.java | 25 ++- .../internal/os/KernelWakelockReader.java | 29 ++-- .../internal/os/KernelWakelockReaderTest.java | 147 ++++++++++++++++++ 3 files changed, 170 insertions(+), 31 deletions(-) create mode 100644 core/tests/coretests/src/com/android/internal/os/KernelWakelockReaderTest.java diff --git a/core/java/com/android/internal/os/BatteryStatsImpl.java b/core/java/com/android/internal/os/BatteryStatsImpl.java index 937fc75046cb7..93dc625f88469 100644 --- a/core/java/com/android/internal/os/BatteryStatsImpl.java +++ b/core/java/com/android/internal/os/BatteryStatsImpl.java @@ -8873,8 +8873,6 @@ public class BatteryStatsImpl extends BatteryStats { return; } - // Record whether we've seen a non-zero time (for debugging b/22716723). - boolean seenNonZeroTime = false; for (Map.Entry ent : wakelockStats.entrySet()) { String name = ent.getKey(); KernelWakelockStats.Entry kws = ent.getValue(); @@ -8884,27 +8882,24 @@ public class BatteryStatsImpl extends BatteryStats { kwlt = new SamplingTimer(mClocks, mOnBatteryScreenOffTimeBase); mKernelWakelockStats.put(name, kwlt); } + kwlt.update(kws.mTotalTime, kws.mCount); kwlt.setUpdateVersion(kws.mVersion); - - if (kws.mVersion != wakelockStats.kernelWakelockVersion) { - seenNonZeroTime |= kws.mTotalTime > 0; - } } int numWakelocksSetStale = 0; - if (wakelockStats.size() != mKernelWakelockStats.size()) { - // Set timers to stale if they didn't appear in /proc/wakelocks this time. - for (Map.Entry ent : mKernelWakelockStats.entrySet()) { - SamplingTimer st = ent.getValue(); - if (st.getUpdateVersion() != wakelockStats.kernelWakelockVersion) { - st.endSample(); - numWakelocksSetStale++; - } + // Set timers to stale if they didn't appear in /d/wakeup_sources (or /proc/wakelocks) + // this time. + for (Map.Entry ent : mKernelWakelockStats.entrySet()) { + SamplingTimer st = ent.getValue(); + if (st.getUpdateVersion() != wakelockStats.kernelWakelockVersion) { + st.endSample(); + numWakelocksSetStale++; } } - if (!seenNonZeroTime) { + // Record whether we've seen a non-zero time (for debugging b/22716723). + if (wakelockStats.isEmpty()) { Slog.wtf(TAG, "All kernel wakelocks had time of zero"); } diff --git a/core/java/com/android/internal/os/KernelWakelockReader.java b/core/java/com/android/internal/os/KernelWakelockReader.java index 6654ea5683e3f..8036f257823b2 100644 --- a/core/java/com/android/internal/os/KernelWakelockReader.java +++ b/core/java/com/android/internal/os/KernelWakelockReader.java @@ -18,6 +18,8 @@ package com.android.internal.os; import android.os.Process; import android.util.Slog; +import com.android.internal.annotations.VisibleForTesting; + import java.io.FileInputStream; import java.util.Iterator; @@ -106,14 +108,14 @@ public class KernelWakelockReader { /** * Reads the wakelocks and updates the staleStats with the new information. */ - private KernelWakelockStats parseProcWakelocks(byte[] wlBuffer, int len, boolean wakeup_sources, - final KernelWakelockStats staleStats) { + @VisibleForTesting + public KernelWakelockStats parseProcWakelocks(byte[] wlBuffer, int len, boolean wakeup_sources, + final KernelWakelockStats staleStats) { String name; int count; long totalTime; int startIndex; int endIndex; - int numUpdatedWlNames = 0; // Advance past the first line. int i; @@ -126,11 +128,10 @@ public class KernelWakelockReader { for (endIndex=startIndex; endIndex < len && wlBuffer[endIndex] != '\n' && wlBuffer[endIndex] != '\0'; endIndex++); - endIndex++; // endIndex is an exclusive upper bound. // Don't go over the end of the buffer, Process.parseProcLine might // write to wlBuffer[endIndex] - if (endIndex >= (len - 1) ) { - return staleStats; + if (endIndex > (len - 1) ) { + break; } String[] nameStringArray = mProcWakelocksName; @@ -161,7 +162,6 @@ public class KernelWakelockReader { if (!staleStats.containsKey(name)) { staleStats.put(name, new KernelWakelockStats.Entry(count, totalTime, sKernelWakelockUpdateVersion)); - numUpdatedWlNames++; } else { KernelWakelockStats.Entry kwlStats = staleStats.get(name); if (kwlStats.mVersion == sKernelWakelockUpdateVersion) { @@ -171,7 +171,6 @@ public class KernelWakelockReader { kwlStats.mCount = count; kwlStats.mTotalTime = totalTime; kwlStats.mVersion = sKernelWakelockUpdateVersion; - numUpdatedWlNames++; } } } else if (!parsed) { @@ -182,16 +181,14 @@ public class KernelWakelockReader { Slog.wtf(TAG, "Failed to parse proc line!"); } } - startIndex = endIndex; + startIndex = endIndex + 1; } - if (staleStats.size() != numUpdatedWlNames) { - // Don't report old data. - Iterator itr = staleStats.values().iterator(); - while (itr.hasNext()) { - if (itr.next().mVersion != sKernelWakelockUpdateVersion) { - itr.remove(); - } + // Don't report old data. + Iterator itr = staleStats.values().iterator(); + while (itr.hasNext()) { + if (itr.next().mVersion != sKernelWakelockUpdateVersion) { + itr.remove(); } } diff --git a/core/tests/coretests/src/com/android/internal/os/KernelWakelockReaderTest.java b/core/tests/coretests/src/com/android/internal/os/KernelWakelockReaderTest.java new file mode 100644 index 0000000000000..4e4bb350739d7 --- /dev/null +++ b/core/tests/coretests/src/com/android/internal/os/KernelWakelockReaderTest.java @@ -0,0 +1,147 @@ +/* + * Copyright (C) 2016 The Android Open Source Project + * + * Licensed under the Apache License, Version 2.0 (the "License"); you may not + * use this file except in compliance with the License. You may obtain a copy of + * the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, WITHOUT + * WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the + * License for the specific language governing permissions and limitations under + * the License. + */ +package com.android.internal.os; + +import android.support.test.filters.SmallTest; + +import junit.framework.TestCase; + +import java.nio.charset.Charset; + +public class KernelWakelockReaderTest extends TestCase { + /** + * Helper class that builds the mock Kernel module file /d/wakeup_sources. + */ + private static class ProcFileBuilder { + private final static String sHeader = "name\t\tactive_count\tevent_count\twakeup_count\t" + + "expire_count\tactive_since\ttotal_time\tmax_time\tlast_change\t" + + "prevent_suspend_time\n"; + + private StringBuilder mStringBuilder; + + private void ensureHeader() { + if (mStringBuilder == null) { + mStringBuilder = new StringBuilder(); + mStringBuilder.append(sHeader); + } + } + + public ProcFileBuilder addLine(String name, int count, long timeMillis) { + ensureHeader(); + mStringBuilder.append(name).append("\t").append(count).append("\t0\t0\t0\t0\t") + .append(timeMillis).append("\t0\t0\t0\n"); + return this; + } + + public byte[] getBytes() throws Exception { + ensureHeader(); + byte[] data = mStringBuilder.toString().getBytes(Charset.forName("UTF-8")); + + // The Kernel puts a \0 at the end of the data. Since each of our lines ends with \n, + // we override the last \n with a \0. + data[data.length - 1] = 0; + return data; + } + } + + private KernelWakelockReader mReader; + + @Override + public void setUp() throws Exception { + super.setUp(); + mReader = new KernelWakelockReader(); + } + + @SmallTest + public void testParseEmptyFile() throws Exception { + KernelWakelockStats staleStats = mReader.parseProcWakelocks(new byte[0], 0, true, + new KernelWakelockStats()); + assertTrue(staleStats.isEmpty()); + } + + @SmallTest + public void testOnlyHeader() throws Exception { + byte[] buffer = new ProcFileBuilder().getBytes(); + KernelWakelockStats staleStats = mReader.parseProcWakelocks(buffer, buffer.length, true, + new KernelWakelockStats()); + assertTrue(staleStats.isEmpty()); + } + + @SmallTest + public void testOneWakelock() throws Exception { + byte[] buffer = new ProcFileBuilder() + .addLine("Wakelock", 34, 123) // Milliseconds + .getBytes(); + KernelWakelockStats staleStats = mReader.parseProcWakelocks(buffer, buffer.length, true, + new KernelWakelockStats()); + assertEquals(1, staleStats.size()); + assertTrue(staleStats.containsKey("Wakelock")); + + KernelWakelockStats.Entry entry = staleStats.get("Wakelock"); + assertEquals(34, entry.mCount); + assertEquals(123 * 1000, entry.mTotalTime); // Microseconds + } + + @SmallTest + public void testTwoWakelocks() throws Exception { + byte[] buffer = new ProcFileBuilder() + .addLine("Wakelock", 1, 10) + .addLine("Fakelock", 2, 20) + .getBytes(); + KernelWakelockStats staleStats = mReader.parseProcWakelocks(buffer, buffer.length, true, + new KernelWakelockStats()); + assertEquals(2, staleStats.size()); + assertTrue(staleStats.containsKey("Wakelock")); + assertTrue(staleStats.containsKey("Fakelock")); + } + + @SmallTest + public void testDuplicateWakelocksAccumulate() throws Exception { + byte[] buffer = new ProcFileBuilder() + .addLine("Wakelock", 1, 10) // Milliseconds + .addLine("Wakelock", 1, 10) // Milliseconds + .getBytes(); + KernelWakelockStats staleStats = mReader.parseProcWakelocks(buffer, buffer.length, true, + new KernelWakelockStats()); + assertEquals(1, staleStats.size()); + assertTrue(staleStats.containsKey("Wakelock")); + + KernelWakelockStats.Entry entry = staleStats.get("Wakelock"); + assertEquals(2, entry.mCount); + assertEquals(20 * 1000, entry.mTotalTime); // Microseconds + } + + @SmallTest + public void testWakelocksBecomeStale() throws Exception { + byte[] buffer = new ProcFileBuilder() + .addLine("Fakelock", 3, 30) + .getBytes(); + KernelWakelockStats staleStats = new KernelWakelockStats(); + + staleStats = mReader.parseProcWakelocks(buffer, buffer.length, true, staleStats); + assertEquals(1, staleStats.size()); + assertTrue(staleStats.containsKey("Fakelock")); + + buffer = new ProcFileBuilder() + .addLine("Wakelock", 1, 10) + .getBytes(); + + staleStats = mReader.parseProcWakelocks(buffer, buffer.length, true, staleStats); + assertEquals(1, staleStats.size()); + assertTrue(staleStats.containsKey("Wakelock")); + assertFalse(staleStats.containsKey("Fakelock")); + } +}