diff --git a/apct-tests/perftests/core/src/android/os/BinderCallsStatsPerfTest.java b/apct-tests/perftests/core/src/android/os/BinderCallsStatsPerfTest.java new file mode 100644 index 0000000000000..28d40969aa210 --- /dev/null +++ b/apct-tests/perftests/core/src/android/os/BinderCallsStatsPerfTest.java @@ -0,0 +1,79 @@ +/* + * Copyright (C) 2018 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 android.os; + +import android.perftests.utils.BenchmarkState; +import android.perftests.utils.PerfStatusReporter; +import android.support.test.filters.LargeTest; +import android.support.test.runner.AndroidJUnit4; + +import com.android.internal.os.BinderCallsStats; + +import org.junit.After; +import org.junit.Before; +import org.junit.Rule; +import org.junit.Test; +import org.junit.runner.RunWith; + +import static org.junit.Assert.assertNull; + + +/** + * Performance tests for {@link BinderCallsStats} + */ +@RunWith(AndroidJUnit4.class) +@LargeTest +public class BinderCallsStatsPerfTest { + + @Rule + public PerfStatusReporter mPerfStatusReporter = new PerfStatusReporter(); + private BinderCallsStats mBinderCallsStats; + + @Before + public void setUp() { + mBinderCallsStats = new BinderCallsStats(true); + } + + @After + public void tearDown() { + } + + @Test + public void timeCallSession() { + final BenchmarkState state = mPerfStatusReporter.getBenchmarkState(); + Binder b = new Binder(); + int i = 0; + while (state.keepRunning()) { + BinderCallsStats.CallSession s = mBinderCallsStats.callStarted(b, i % 100); + mBinderCallsStats.callEnded(s); + i++; + } + } + + @Test + public void timeCallSessionTrackingDisabled() { + final BenchmarkState state = mPerfStatusReporter.getBenchmarkState(); + Binder b = new Binder(); + mBinderCallsStats = new BinderCallsStats(false); + assertNull(mBinderCallsStats.callStarted(b, 0)); + while (state.keepRunning()) { + BinderCallsStats.CallSession s = mBinderCallsStats.callStarted(b, 0); + mBinderCallsStats.callEnded(s); + } + } + +} diff --git a/core/java/android/os/Binder.java b/core/java/android/os/Binder.java index 44bd35aa896f6..0ae5394e6cb9a 100644 --- a/core/java/android/os/Binder.java +++ b/core/java/android/os/Binder.java @@ -23,6 +23,7 @@ import android.util.Log; import android.util.Slog; import android.util.SparseIntArray; +import com.android.internal.os.BinderCallsStats; import com.android.internal.os.BinderInternal; import com.android.internal.util.FastPrintWriter; import com.android.internal.util.FunctionalUtils.ThrowingRunnable; @@ -712,6 +713,8 @@ public class Binder implements IBinder { // Entry point from android_util_Binder.cpp's onTransact private boolean execTransact(int code, long dataObj, long replyObj, int flags) { + BinderCallsStats binderCallsStats = BinderCallsStats.getInstance(); + BinderCallsStats.CallSession callSession = binderCallsStats.callStarted(this, code); Parcel data = Parcel.obtain(dataObj); Parcel reply = Parcel.obtain(replyObj); // theoretically, we should call transact, which will call onTransact, @@ -756,6 +759,7 @@ public class Binder implements IBinder { // to the main transaction loop to wait for another incoming transaction. Either // way, strict mode begone! StrictMode.clearGatheredViolations(); + binderCallsStats.callEnded(callSession); return res; } diff --git a/core/java/com/android/internal/os/BinderCallsStats.java b/core/java/com/android/internal/os/BinderCallsStats.java new file mode 100644 index 0000000000000..2c48506494bc1 --- /dev/null +++ b/core/java/com/android/internal/os/BinderCallsStats.java @@ -0,0 +1,272 @@ +/* + * Copyright (C) 2017 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.os.Binder; +import android.os.SystemClock; +import android.util.ArrayMap; +import android.util.SparseArray; + +import com.android.internal.annotations.VisibleForTesting; +import com.android.internal.util.Preconditions; + +import java.io.PrintWriter; +import java.util.ArrayList; +import java.util.HashMap; +import java.util.List; +import java.util.Map; +import java.util.Queue; +import java.util.concurrent.ConcurrentLinkedQueue; + +/** + * Collects statistics about CPU time spent per binder call across multiple dimensions, e.g. + * per thread, uid or call description. + */ +public class BinderCallsStats { + private static final int CALL_SESSIONS_POOL_SIZE = 100; + private static final BinderCallsStats sInstance = new BinderCallsStats(); + + private volatile boolean mTrackingEnabled = false; + private final SparseArray mUidEntries = new SparseArray<>(); + private final Queue mCallSessionsPool = new ConcurrentLinkedQueue<>(); + + private BinderCallsStats() { + } + + @VisibleForTesting + public BinderCallsStats(boolean trackingEnabled) { + mTrackingEnabled = trackingEnabled; + } + + public CallSession callStarted(Binder binder, int code) { + if (!mTrackingEnabled) { + return null; + } + + return callStarted(binder.getClass().getName(), code); + } + + private CallSession callStarted(String className, int code) { + CallSession s = mCallSessionsPool.poll(); + if (s == null) { + s = new CallSession(); + } + s.mCallStat.className = className; + s.mCallStat.msg = code; + + s.mStarted = getThreadTimeMicro(); + return s; + } + + public void callEnded(CallSession s) { + if (!mTrackingEnabled) { + return; + } + Preconditions.checkNotNull(s); + final long cpuTimeNow = getThreadTimeMicro(); + final long duration = cpuTimeNow - s.mStarted; + s.mCallingUId = Binder.getCallingUid(); + + synchronized (mUidEntries) { + UidEntry uidEntry = mUidEntries.get(s.mCallingUId); + if (uidEntry == null) { + uidEntry = new UidEntry(s.mCallingUId); + mUidEntries.put(s.mCallingUId, uidEntry); + } + + // Find CallDesc entry and update its total time + CallStat callStat = uidEntry.mCallStats.get(s.mCallStat); + // Only create CallStat if it's a new entry, otherwise update existing instance + if (callStat == null) { + callStat = new CallStat(s.mCallStat.className, s.mCallStat.msg); + uidEntry.mCallStats.put(callStat, callStat); + } + uidEntry.time += duration; + uidEntry.callCount++; + callStat.callCount++; + callStat.time += duration; + } + if (mCallSessionsPool.size() < CALL_SESSIONS_POOL_SIZE) { + mCallSessionsPool.add(s); + } + } + + public void dump(PrintWriter pw) { + Map uidTimeMap = new HashMap<>(); + Map uidCallCountMap = new HashMap<>(); + long totalCallsCount = 0; + long totalCallsTime = 0; + int uidEntriesSize = mUidEntries.size(); + List entries = new ArrayList<>(); + synchronized (mUidEntries) { + for (int i = 0; i < uidEntriesSize; i++) { + UidEntry e = mUidEntries.valueAt(i); + entries.add(e); + totalCallsTime += e.time; + // Update per-uid totals + Long totalTimePerUid = uidTimeMap.get(e.uid); + uidTimeMap.put(e.uid, + totalTimePerUid == null ? e.time : totalTimePerUid + e.time); + Long totalCallsPerUid = uidCallCountMap.get(e.uid); + uidCallCountMap.put(e.uid, totalCallsPerUid == null ? e.callCount + : totalCallsPerUid + e.callCount); + totalCallsCount += e.callCount; + } + } + pw.println("Binder call stats:"); + pw.println(" Raw data (uid,call_desc,time):"); + entries.sort((o1, o2) -> { + if (o1.time < o2.time) { + return 1; + } else if (o1.time > o2.time) { + return -1; + } + return 0; + }); + StringBuilder sb = new StringBuilder(); + for (UidEntry uidEntry : entries) { + List callStats = new ArrayList<>(uidEntry.mCallStats.keySet()); + callStats.sort((o1, o2) -> { + if (o1.time < o2.time) { + return 1; + } else if (o1.time > o2.time) { + return -1; + } + return 0; + }); + for (CallStat e : callStats) { + sb.setLength(0); + sb.append(" ") + .append(uidEntry.uid).append(",").append(e).append(',').append(e.time); + pw.println(sb); + } + } + pw.println(); + pw.println(" Per UID Summary(UID: time, total_time_percentage, calls_count):"); + List> uidTotals = new ArrayList<>(uidTimeMap.entrySet()); + uidTotals.sort((o1, o2) -> o2.getValue().compareTo(o1.getValue())); + for (Map.Entry uidTotal : uidTotals) { + Long callCount = uidCallCountMap.get(uidTotal.getKey()); + pw.println(String.format(" %5d: %11d %3.0f%% %8d", + uidTotal.getKey(), uidTotal.getValue(), + 100d * uidTotal.getValue() / totalCallsTime, callCount)); + } + pw.println(); + pw.println(String.format(" Summary: total_time=%d, " + + "calls_count=%d, avg_call_time=%.0f", + totalCallsTime, totalCallsCount, + (double)totalCallsTime / totalCallsCount)); + } + + private static long getThreadTimeMicro() { + return SystemClock.currentThreadTimeMicro(); + } + + public static BinderCallsStats getInstance() { + return sInstance; + } + + public void setTrackingEnabled(boolean enabled) { + mTrackingEnabled = enabled; + } + + public boolean isTrackingEnabled() { + return mTrackingEnabled; + } + + private static class CallStat { + String className; + int msg; + long time; + long callCount; + + CallStat() { + } + + CallStat(String className, int msg) { + this.className = className; + this.msg = msg; + } + + @Override + public boolean equals(Object o) { + if (this == o) { + return true; + } + + CallStat callStat = (CallStat) o; + + return msg == callStat.msg && (className == callStat.className); + } + + @Override + public int hashCode() { + int result = className.hashCode(); + result = 31 * result + msg; + return result; + } + + @Override + public String toString() { + return className + "/" + msg; + } + } + + public static class CallSession { + int mCallingUId; + long mStarted; + CallStat mCallStat = new CallStat(); + } + + private static class UidEntry { + int uid; + long time; + long callCount; + + UidEntry(int uid) { + this.uid = uid; + } + + // Aggregate time spent per each call name: call_desc -> cpu_time_micros + Map mCallStats = new ArrayMap<>(); + + @Override + public String toString() { + return "UidEntry{" + + "time=" + time + + ", callCount=" + callCount + + ", mCallStats=" + mCallStats + + '}'; + } + + @Override + public boolean equals(Object o) { + if (this == o) { + return true; + } + + UidEntry uidEntry = (UidEntry) o; + return uid == uidEntry.uid; + } + + @Override + public int hashCode() { + return uid; + } + } + +} diff --git a/services/core/java/com/android/server/BinderCallsStatsService.java b/services/core/java/com/android/server/BinderCallsStatsService.java new file mode 100644 index 0000000000000..2ed451610354d --- /dev/null +++ b/services/core/java/com/android/server/BinderCallsStatsService.java @@ -0,0 +1,55 @@ +/* + * Copyright (C) 2018 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.server; + +import android.os.Binder; +import android.os.ServiceManager; +import android.os.SystemProperties; +import android.util.Slog; + +import com.android.internal.os.BinderCallsStats; + +import java.io.FileDescriptor; +import java.io.PrintWriter; + +public class BinderCallsStatsService extends Binder { + + private static final String TAG = "BinderCallsStatsService"; + + private static final String PERSIST_SYS_BINDER_CPU_STATS_TRACKING + = "persist.sys.binder_cpu_stats_tracking"; + + public static void start() { + BinderCallsStatsService service = new BinderCallsStatsService(); + ServiceManager.addService("binder_calls_stats", service); + // TODO Enable by default on eng/userdebug builds + boolean trackingEnabledDefault = false; + boolean trackingEnabled = SystemProperties.getBoolean(PERSIST_SYS_BINDER_CPU_STATS_TRACKING, + trackingEnabledDefault); + + if (trackingEnabled) { + Slog.i(TAG, "Enabled CPU usage tracking for binder calls. Controlled by " + + PERSIST_SYS_BINDER_CPU_STATS_TRACKING); + BinderCallsStats.getInstance().setTrackingEnabled(true); + } + } + + @Override + protected void dump(FileDescriptor fd, PrintWriter pw, String[] args) { + BinderCallsStats.getInstance().dump(pw); + } +} diff --git a/services/java/com/android/server/SystemServer.java b/services/java/com/android/server/SystemServer.java index d165a45f0b014..6f50ee27d1341 100644 --- a/services/java/com/android/server/SystemServer.java +++ b/services/java/com/android/server/SystemServer.java @@ -705,6 +705,11 @@ public final class SystemServer { mWebViewUpdateService = mSystemServiceManager.startService(WebViewUpdateService.class); traceEnd(); } + + // Tracks cpu time spent in binder calls + traceBeginAndSlog("StartBinderCallsStatsService"); + BinderCallsStatsService.start(); + traceEnd(); } /**