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

Commit 9c988b29 authored by Santos Cordon's avatar Santos Cordon
Browse files

Add logging to Dream stop. 

Unexpected stop in dreams get logged very generically and are difficult
to debug. Additionally, in many cases of stopping, DreamController
requests the dream to stop wherein the dream finishes itself.
This ultimately gets logged as a normal finish. Added code to save
the context of the original request to stop so that it gets logged
appropriately.

Bug: 150436621
Test: Manually tested the new logged reasons.
Change-Id: I25e348026b514dffe540cf8c4cf3a9b87d385fde
parent edc77996

services/core/java/com/android/server/dreams/DreamController.java

+16 −10
Original line number Diff line number Diff line
@@ -62,6 +62,7 @@ final class DreamController { 
    private final Listener mListener;

    private final IWindowManager mIWindowManager;

    private long mDreamStartTime;

    private String mSavedStopReason;



    private final Intent mDreamingStartedIntent = new Intent(Intent.ACTION_DREAMING_STARTED)

            .addFlags(Intent.FLAG_RECEIVER_REGISTERED_ONLY);
@@ -77,14 +78,15 @@ final class DreamController { 
        public void run() {

            if (mCurrentDream != null && mCurrentDream.mBound && !mCurrentDream.mConnected) {

                Slog.w(TAG, "Bound dream did not connect in the time allotted");

                stopDream(true /*immediate*/);

                stopDream(true /*immediate*/, "slow to connect");

            }

        }

    };



    private final Runnable mStopStubbornDreamRunnable = () -> {

        Slog.w(TAG, "Stubborn dream did not finish itself in the time allotted");

        stopDream(true /*immediate*/);

        stopDream(true /*immediate*/, "slow to finish");

        mSavedStopReason = null;

    };



    public DreamController(Context context, Handler handler, Listener listener) {
@@ -116,7 +118,7 @@ final class DreamController { 


    public void startDream(Binder token, ComponentName name,

            boolean isTest, boolean canDoze, int userId, PowerManager.WakeLock wakeLock) {

        stopDream(true /*immediate*/);

        stopDream(true /*immediate*/, "starting new dream");



        Trace.traceBegin(Trace.TRACE_TAG_POWER, "startDream");

        try {
@@ -141,12 +143,12 @@ final class DreamController { 
                        Context.BIND_AUTO_CREATE | Context.BIND_FOREGROUND_SERVICE,

                        new UserHandle(userId))) {

                    Slog.e(TAG, "Unable to bind dream service: " + intent);

                    stopDream(true /*immediate*/);

                    stopDream(true /*immediate*/, "bindService failed");

                    return;

                }

            } catch (SecurityException ex) {

                Slog.e(TAG, "Unable to bind dream service: " + intent, ex);

                stopDream(true /*immediate*/);

                stopDream(true /*immediate*/, "unable to bind service: SecExp.");

                return;

            }
@@ -157,7 +159,7 @@ final class DreamController { 
        }

    }



    public void stopDream(boolean immediate) {

    public void stopDream(boolean immediate, String reason) {

        if (mCurrentDream == null) {

            return;

        }
@@ -173,6 +175,7 @@ final class DreamController { 
                    // Give the dream a moment to wake up and finish itself gently.

                    mCurrentDream.mWakingGently = true;

                    try {

                        mSavedStopReason = reason;

                        mCurrentDream.mService.wakeUp();

                        mHandler.postDelayed(mStopStubbornDreamRunnable, DREAM_FINISH_TIMEOUT);

                        return;
@@ -186,7 +189,9 @@ final class DreamController { 
            mCurrentDream = null;

            Slog.i(TAG, "Stopping dream: name=" + oldDream.mName

                    + ", isTest=" + oldDream.mIsTest + ", canDoze=" + oldDream.mCanDoze

                    + ", userId=" + oldDream.mUserId);

                    + ", userId=" + oldDream.mUserId

                    + ", reason='" + reason + "'"

                    + (mSavedStopReason == null ? "" : "(from '" + mSavedStopReason + "')"));

            MetricsLogger.hidden(mContext,

                    oldDream.mCanDoze ? MetricsEvent.DOZING : MetricsEvent.DREAMING);

            MetricsLogger.histogram(mContext,
@@ -195,6 +200,7 @@ final class DreamController { 


            mHandler.removeCallbacks(mStopUnconnectedDreamRunnable);

            mHandler.removeCallbacks(mStopStubbornDreamRunnable);

            mSavedStopReason = null;



            if (oldDream.mSentStartBroadcast) {

                mContext.sendBroadcastAsUser(mDreamingStoppedIntent, UserHandle.ALL);
@@ -233,7 +239,7 @@ final class DreamController { 
                    mCurrentDream.mDreamingStartedCallback);

        } catch (RemoteException ex) {

            Slog.e(TAG, "The dream service died unexpectedly.", ex);

            stopDream(true /*immediate*/);

            stopDream(true /*immediate*/, "attach failed");

            return;

        }
@@ -287,7 +293,7 @@ final class DreamController { 
            mHandler.post(() -> {

                mService = null;

                if (mCurrentDream == DreamRecord.this) {

                    stopDream(true /*immediate*/);

                    stopDream(true /*immediate*/, "binder died");

                }

            });

        }
@@ -312,7 +318,7 @@ final class DreamController { 
            mHandler.post(() -> {

                mService = null;

                if (mCurrentDream == DreamRecord.this) {

                    stopDream(true /*immediate*/);

                    stopDream(true /*immediate*/, "service disconnected");

                }

            });

        }

services/core/java/com/android/server/dreams/DreamManagerService.java

+9 −9
Original line number Diff line number Diff line
@@ -118,7 +118,7 @@ public final class DreamManagerService extends SystemService { 
                public void onReceive(Context context, Intent intent) {

                    writePulseGestureEnabled();

                    synchronized (mLock) {

                        stopDreamLocked(false /*immediate*/);

                        stopDreamLocked(false /*immediate*/, "user switched");

                    }

                }

            }, new IntentFilter(Intent.ACTION_USER_SWITCHED), null, mHandler);
@@ -177,7 +177,7 @@ public final class DreamManagerService extends SystemService { 
        // for example when being undocked.

        long time = SystemClock.uptimeMillis();

        mPowerManager.userActivity(time, false /*noChangeLights*/);

        stopDreamInternal(false /*immediate*/);

        stopDreamInternal(false /*immediate*/, "request awaken");

    }



    private void finishSelfInternal(IBinder token, boolean immediate) {
@@ -194,7 +194,7 @@ public final class DreamManagerService extends SystemService { 
        // device may simply go to sleep.

        synchronized (mLock) {

            if (mCurrentDreamToken == token) {

                stopDreamLocked(immediate);

                stopDreamLocked(immediate, "finished self");

            }

        }

    }
@@ -215,9 +215,9 @@ public final class DreamManagerService extends SystemService { 
        }

    }



    private void stopDreamInternal(boolean immediate) {

    private void stopDreamInternal(boolean immediate, String reason) {

        synchronized (mLock) {

            stopDreamLocked(immediate);

            stopDreamLocked(immediate, reason);

        }

    }
@@ -370,7 +370,7 @@ public final class DreamManagerService extends SystemService { 
            return;

        }



        stopDreamLocked(true /*immediate*/);

        stopDreamLocked(true /*immediate*/, "starting new dream");



        Slog.i(TAG, "Entering dreamland.");
@@ -387,7 +387,7 @@ public final class DreamManagerService extends SystemService { 
                () -> mController.startDream(newToken, name, isTest, canDoze, userId, wakeLock)));

    }



    private void stopDreamLocked(final boolean immediate) {

    private void stopDreamLocked(final boolean immediate, String reason) {

        if (mCurrentDreamToken != null) {

            if (immediate) {

                Slog.i(TAG, "Leaving dreamland.");
@@ -403,7 +403,7 @@ public final class DreamManagerService extends SystemService { 
                @Override

                public void run() {

                    Slog.i(TAG, "Performing gentle wake from dream.");

                    mController.stopDream(immediate);

                    mController.stopDream(immediate, reason);

                }

            });

        }
@@ -690,7 +690,7 @@ public final class DreamManagerService extends SystemService { 


        @Override

        public void stopDream(boolean immediate) {

            stopDreamInternal(immediate);

            stopDreamInternal(immediate, "requested stopDream");

        }



        @Override