Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit ca34851e authored by Fyodor Kupolov's avatar Fyodor Kupolov
Browse files

Added BinderCallsStatsService 

It tracks binder calls into the system server and reports
statistics about CPU time spent per call on multiple dimensions,
e.g. uid or call description.

Usage: dumpsys binder_calls_stats
Overhead: ~0.5% per binder call (if enabled)

Test: manual
Bug: 75318418
Change-Id: I13b854f67f8fd1c9f985b8e45f74dcba2e73b9cb
parent 9531b70c

apct-tests/perftests/core/src/android/os/BinderCallsStatsPerfTest.java

0 → 100644
+79 −0
Original line number Diff line number Diff line 
/*

 * 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);

        }

    }



}

core/java/android/os/Binder.java

+4 −0
Original line number Diff line number Diff line
@@ -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;
@@ -710,6 +711,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,
@@ -754,6 +757,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;

    }

core/java/com/android/internal/os/BinderCallsStats.java

0 → 100644
+272 −0
Original line number Diff line number Diff line 
/*

 * 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<UidEntry> mUidEntries = new SparseArray<>();

    private final Queue<CallSession> 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<Integer, Long> uidTimeMap = new HashMap<>();

        Map<Integer, Long> uidCallCountMap = new HashMap<>();

        long totalCallsCount = 0;

        long totalCallsTime = 0;

        int uidEntriesSize = mUidEntries.size();

        List<UidEntry> 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<CallStat> 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<Map.Entry<Integer, Long>> uidTotals = new ArrayList<>(uidTimeMap.entrySet());

        uidTotals.sort((o1, o2) -> o2.getValue().compareTo(o1.getValue()));

        for (Map.Entry<Integer, Long> 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<CallStat, CallStat> 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;

        }

    }



}

services/core/java/com/android/server/BinderCallsStatsService.java

0 → 100644
+55 −0
Original line number Diff line number Diff line 
/*

 * 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);

    }

}

services/java/com/android/server/SystemServer.java

+5 −0
Original line number Diff line number Diff line
@@ -703,6 +703,11 @@ public final class SystemServer { 
            mWebViewUpdateService = mSystemServiceManager.startService(WebViewUpdateService.class);

            traceEnd();

        }



        // Tracks cpu time spent in binder calls

        traceBeginAndSlog("StartBinderCallsStatsService");

        BinderCallsStatsService.start();

        traceEnd();

    }



    /**