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

Commit af52d7ae authored by Hugo Benichi's avatar Hugo Benichi
Browse files

ConnectivityService: log wakelock activity in dumps 

This patch adds wakelock acquire and release activity to
ConnectivityService logs in dumpsys. All of the last 20 acquire and
release operations are logged.

This patch also:
  - does a bit of cleanup to related dumpsys logs
  - unify pretty printing of internal event ids to their names.
  - delete mInetLog which was obsolete and not used.

Example of logs:
  NetTransition WakeLock activity (most recent first):
    03-30 02:15:40.628 - RELEASE 1 by EVENT_EXPIRE_NET_TRANSITION_WAKELOCK: not released (serial number was 2)
    03-30 02:15:09.965 - ACQUIRE 2 for NetworkAgentInfo [WIFI () - 101]
    03-30 02:15:01.877 - RELEASE 1 by EVENT_CLEAR_NET_TRANSITION_WAKELOCK: released
    03-30 02:14:40.598 - ACQUIRE 1 for NetworkAgentInfo [WIFI () - 100]

Test: inspected result of $ adb shell dumpsys connectivity
Bug: 36703718
Change-Id: Ia8e2016fc512ee798ef0adc3f612d1f6c33d4870
parent e940d545

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

+52 −67
Original line number Diff line number Diff line
@@ -395,6 +395,10 @@ public class ConnectivityService extends IConnectivityManager.Stub 
     */

    private static final int EVENT_REGISTER_NETWORK_LISTENER_WITH_INTENT = 31;



    private static String eventName(int what) {

        return sMagicDecoderRing.get(what, Integer.toString(what));

    }



    /** Handler thread used for both of the handlers below. */

    @VisibleForTesting

    protected final HandlerThread mHandlerThread;
@@ -407,15 +411,10 @@ public class ConnectivityService extends IConnectivityManager.Stub 
    private Intent mInitialBroadcast;



    private PowerManager.WakeLock mNetTransitionWakeLock;

    private String mNetTransitionWakeLockCausedBy = "";

    private int mNetTransitionWakeLockSerialNumber;

    private int mNetTransitionWakeLockTimeout;

    private final PowerManager.WakeLock mPendingIntentWakeLock;



    // used in DBG mode to track inet condition reports

    private static final int INET_CONDITION_LOG_MAX_SIZE = 15;

    private ArrayList mInetLog;



    // track the current default http proxy - tell the world if we get a new one (real change)

    private volatile ProxyInfo mDefaultProxy = null;

    private Object mProxyLock = new Object();
@@ -457,10 +456,12 @@ public class ConnectivityService extends IConnectivityManager.Stub 
    private final LocalLog mNetworkRequestInfoLogs = new LocalLog(MAX_NETWORK_REQUEST_LOGS);



    // NetworkInfo blocked and unblocked String log entries

    // TODO: consider reducing memory usage. Each log line is ~40 2B chars, for a total of ~8kB.

    private static final int MAX_NETWORK_INFO_LOGS = 100;

    private static final int MAX_NETWORK_INFO_LOGS = 40;

    private final LocalLog mNetworkInfoBlockingLogs = new LocalLog(MAX_NETWORK_INFO_LOGS);



    private static final int MAX_WAKELOCK_LOGS = 20;

    private final LocalLog mWakelockLogs = new LocalLog(MAX_WAKELOCK_LOGS);



    // Array of <Network,ReadOnlyLocalLogs> tracking network validation and results

    private static final int MAX_VALIDATION_LOGS = 10;

    private static class ValidationLog {
@@ -815,10 +816,6 @@ public class ConnectivityService extends IConnectivityManager.Stub 
            loge("Error registering observer :" + e);

        }



        if (DBG) {

            mInetLog = new ArrayList();

        }



        mSettingsObserver = new SettingsObserver(mContext, mHandler);

        registerSettingsCallbacks();
@@ -1041,22 +1038,19 @@ public class ConnectivityService extends IConnectivityManager.Stub 
        if (ni == null || !LOGD_BLOCKED_NETWORKINFO) {

            return;

        }

        boolean removed = false;

        boolean added = false;

        final boolean blocked;

        synchronized (mBlockedAppUids) {

            if (ni.getDetailedState() == DetailedState.BLOCKED && mBlockedAppUids.add(uid)) {

                added = true;

                blocked = true;

            } else if (ni.isConnected() && mBlockedAppUids.remove(uid)) {

                removed = true;

            }

                blocked = false;

            } else {

                return;

            }

        if (added) {

            log("Returning blocked NetworkInfo to uid=" + uid);

            mNetworkInfoBlockingLogs.log("BLOCKED " + uid);

        } else if (removed) {

            log("Returning unblocked NetworkInfo to uid=" + uid);

            mNetworkInfoBlockingLogs.log("UNBLOCKED " + uid);

        }

        String action = blocked ? "BLOCKED" : "UNBLOCKED";

        log(String.format("Returning %s NetworkInfo to uid=%d", action, uid));

        mNetworkInfoBlockingLogs.log(action + " " + uid);

    }



    /**
@@ -2028,16 +2022,6 @@ public class ConnectivityService extends IConnectivityManager.Stub 


        mLegacyTypeTracker.dump(pw);



        synchronized (this) {

            pw.print("mNetTransitionWakeLock: currently " +

                    (mNetTransitionWakeLock.isHeld() ? "" : "not ") + "held");

            if (!TextUtils.isEmpty(mNetTransitionWakeLockCausedBy)) {

                pw.println(", last requested for " + mNetTransitionWakeLockCausedBy);

            } else {

                pw.println(", last requested never");

            }

        }



        pw.println();

        mTethering.dump(fd, pw, args);
@@ -2047,17 +2031,6 @@ public class ConnectivityService extends IConnectivityManager.Stub 
        pw.println();

        dumpAvoidBadWifiSettings(pw);



        pw.println();

        if (mInetLog != null && mInetLog.size() > 0) {

            pw.println();

            pw.println("Inet condition reports:");

            pw.increaseIndent();

            for(int i = 0; i < mInetLog.size(); i++) {

                pw.println(mInetLog.get(i));

            }

            pw.decreaseIndent();

        }



        if (argsContain(args, "--short") == false) {

            pw.println();

            synchronized (mValidationLogs) {
@@ -2081,6 +2054,12 @@ public class ConnectivityService extends IConnectivityManager.Stub 
            pw.increaseIndent();

            mNetworkInfoBlockingLogs.reverseDump(fd, pw, args);

            pw.decreaseIndent();



            pw.println();

            pw.println("NetTransition WakeLock activity (most recent first):");

            pw.increaseIndent();

            mWakelockLogs.reverseDump(fd, pw, args);

            pw.decreaseIndent();

        }

    }
@@ -2089,8 +2068,7 @@ public class ConnectivityService extends IConnectivityManager.Stub 
        final NetworkAgentInfo officialNai = getNetworkAgentInfoForNetwork(nai.network);

        if (officialNai != null && officialNai.equals(nai)) return true;

        if (officialNai != null || VDBG) {

            final String msg = sMagicDecoderRing.get(what, Integer.toString(what));

            loge(msg + " - isLiveNetworkAgent found mismatched netId: " + officialNai +

            loge(eventName(what) + " - isLiveNetworkAgent found mismatched netId: " + officialNai +

                " - " + nai);

        }

        return false;
@@ -2127,8 +2105,7 @@ public class ConnectivityService extends IConnectivityManager.Stub 
            NetworkAgentInfo nai = mNetworkAgentInfos.get(msg.replyTo);

            if (nai == null) {

                if (VDBG) {

                    final String what = sMagicDecoderRing.get(msg.what, Integer.toString(msg.what));

                    log(String.format("%s from unknown NetworkAgent", what));

                    log(String.format("%s from unknown NetworkAgent", eventName(msg.what)));

                }

                return;

            }
@@ -2865,25 +2842,7 @@ public class ConnectivityService extends IConnectivityManager.Stub 
            switch (msg.what) {

                case EVENT_EXPIRE_NET_TRANSITION_WAKELOCK:

                case EVENT_CLEAR_NET_TRANSITION_WAKELOCK: {

                    String causedBy = null;

                    synchronized (ConnectivityService.this) {

                        if (msg.arg1 == mNetTransitionWakeLockSerialNumber &&

                                mNetTransitionWakeLock.isHeld()) {

                            mNetTransitionWakeLock.release();

                            causedBy = mNetTransitionWakeLockCausedBy;

                        } else {

                            break;

                        }

                    }

                    if (VDBG) {

                        if (msg.what == EVENT_EXPIRE_NET_TRANSITION_WAKELOCK) {

                            log("Failed to find a new network - expiring NetTransition Wakelock");

                        } else {

                            log("NetTransition Wakelock (" +

                                    (causedBy == null ? "unknown" : causedBy) +

                                    " cleared because we found a replacement network");

                        }

                    }

                    handleNetworkTransitionWakelockRelease(msg.what, msg.arg1);

                    break;

                }

                case EVENT_APPLY_GLOBAL_HTTP_PROXY: {
@@ -3112,7 +3071,7 @@ public class ConnectivityService extends IConnectivityManager.Stub 
            if (mNetTransitionWakeLock.isHeld()) return;

            serialNum = ++mNetTransitionWakeLockSerialNumber;

            mNetTransitionWakeLock.acquire();

            mNetTransitionWakeLockCausedBy = forWhom;

            mWakelockLogs.log(String.format("ACQUIRE %d for %s", serialNum, forWhom));

        }

        mHandler.sendMessageDelayed(mHandler.obtainMessage(

                EVENT_EXPIRE_NET_TRANSITION_WAKELOCK, serialNum, 0),
@@ -3120,6 +3079,32 @@ public class ConnectivityService extends IConnectivityManager.Stub 
        return;

    }



    private void handleNetworkTransitionWakelockRelease(int eventId, int wantSerialNumber) {

        final int serialNumber;

        final boolean isHeld;

        final boolean release;

        synchronized (this) {

            serialNumber = mNetTransitionWakeLockSerialNumber;

            isHeld = mNetTransitionWakeLock.isHeld();

            release = (wantSerialNumber == serialNumber) && isHeld;

            if (release) {

                mNetTransitionWakeLock.release();

            }

        }

        final String result;

        if (release) {

            result = "released";

        } else if (!isHeld) {

            result = "already released";

        } else {

            result = String.format("not released (serial number was %d)", serialNumber);

        }

        String msg = String.format(

                "RELEASE %d by %s: %s", wantSerialNumber, eventName(eventId), result);

        mWakelockLogs.log(msg);

        if (DBG) log(msg);

    }



    // 100 percent is full good, 0 is full bad.

    @Override

    public void reportInetCondition(int networkType, int percentage) {