Add trace tag for power management.

Instrumented the basic power manager state transitions,
calling into the Power HAL, setting the display power mode,
and setting the backlight.

Bug: 17004602
Change-Id: I4e362162ddfd7292a7eea8b5d029ce3f6593c4a9

diff --git a/core/java/android/os/PowerManager.java b/core/java/android/os/PowerManager.java
index f381fdf..75f8279 100644 (file)
--- a/core/java/android/os/PowerManager.java
+++ b/core/java/android/os/PowerManager.java
@@ -773,6 +773,7 @@ public final class PowerManager {
         private boolean mHeld;
         private WorkSource mWorkSource;
         private String mHistoryTag;
+        private final String mTraceName;
 
         private final Runnable mReleaser = new Runnable() {
             public void run() {
@@ -785,6 +786,7 @@ public final class PowerManager {
             mTag = tag;
             mPackageName = packageName;
             mToken = new Binder();
+            mTraceName = "WakeLock (" + mTag + ")";
         }
 
         @Override
@@ -792,6 +794,7 @@ public final class PowerManager {
             synchronized (mToken) {
                 if (mHeld) {
                     Log.wtf(TAG, "WakeLock finalized while still held: " + mTag);
+                    Trace.asyncTraceEnd(Trace.TRACE_TAG_POWER, mTraceName, 0);
                     try {
                         mService.releaseWakeLock(mToken, 0);
                     } catch (RemoteException e) {
@@ -858,6 +861,7 @@ public final class PowerManager {
                 // should immediately acquire the wake lock once again despite never having
                 // been explicitly released by the keyguard.
                 mHandler.removeCallbacks(mReleaser);
+                Trace.asyncTraceBegin(Trace.TRACE_TAG_POWER, mTraceName, 0);
                 try {
                     mService.acquireWakeLock(mToken, mFlags, mTag, mPackageName, mWorkSource,
                             mHistoryTag);
@@ -897,6 +901,7 @@ public final class PowerManager {
                 if (!mRefCounted || --mCount == 0) {
                     mHandler.removeCallbacks(mReleaser);
                     if (mHeld) {
+                        Trace.asyncTraceEnd(Trace.TRACE_TAG_POWER, mTraceName, 0);
                         try {
                             mService.releaseWakeLock(mToken, flags);
                         } catch (RemoteException e) {

diff --git a/core/java/android/os/Trace.java b/core/java/android/os/Trace.java
index 474192f..31b5849 100644 (file)
--- a/core/java/android/os/Trace.java
+++ b/core/java/android/os/Trace.java
@@ -36,6 +36,7 @@ public final class Trace {
     private static final String TAG = "Trace";
 
     // These tags must be kept in sync with system/core/include/cutils/trace.h.
+    // They should also be added to frameworks/native/cmds/atrace/atrace.cpp.
     /** @hide */
     public static final long TRACE_TAG_NEVER = 0;
     /** @hide */
@@ -72,6 +73,8 @@ public final class Trace {
     public static final long TRACE_TAG_RS = 1L << 15;
     /** @hide */
     public static final long TRACE_TAG_BIONIC = 1L << 16;
+    /** @hide */
+    public static final long TRACE_TAG_POWER = 1L << 17;
 
     private static final long TRACE_TAG_NOT_READY = 1L << 63;
     private static final int MAX_SECTION_NAME_LEN = 127;

diff --git a/services/core/java/com/android/server/display/DisplayPowerController.java b/services/core/java/com/android/server/display/DisplayPowerController.java
index 9a67321..46cb6c3 100644 (file)
--- a/services/core/java/com/android/server/display/DisplayPowerController.java
+++ b/services/core/java/com/android/server/display/DisplayPowerController.java
@@ -37,7 +37,7 @@ import android.os.Message;
 import android.os.PowerManager;
 import android.os.RemoteException;
 import android.os.SystemClock;
-import android.text.format.DateUtils;
+import android.os.Trace;
 import android.util.MathUtils;
 import android.util.Slog;
 import android.util.Spline;
@@ -74,6 +74,8 @@ final class DisplayPowerController implements AutomaticBrightnessController.Call
     private static boolean DEBUG = false;
     private static final boolean DEBUG_PRETEND_PROXIMITY_SENSOR_ABSENT = false;
 
+    private static final String SCREEN_ON_BLOCKED_TRACE_NAME = "Screen on blocked";
+
     // If true, uses the electron beam on animation.
     // We might want to turn this off if we cannot get a guarantee that the screen
     // actually turns on and starts showing new content after the call to set the
@@ -714,11 +716,10 @@ final class DisplayPowerController implements AutomaticBrightnessController.Call
 
     private void blockScreenOn() {
         if (!mScreenOnWasBlocked) {
+            Trace.asyncTraceBegin(Trace.TRACE_TAG_POWER, SCREEN_ON_BLOCKED_TRACE_NAME, 0);
             mScreenOnWasBlocked = true;
             mScreenOnBlockStartRealTime = SystemClock.elapsedRealtime();
-            if (DEBUG) {
-                Slog.d(TAG, "Blocked screen on.");
-            }
+            Slog.i(TAG, "Blocking screen on until initial contents have been drawn.");
         }
     }
 
@@ -726,9 +727,8 @@ final class DisplayPowerController implements AutomaticBrightnessController.Call
         if (mScreenOnWasBlocked) {
             mScreenOnWasBlocked = false;
             long delay = SystemClock.elapsedRealtime() - mScreenOnBlockStartRealTime;
-            if (delay > 1000 || DEBUG) {
-                Slog.d(TAG, "Unblocked screen on after " + delay + " ms");
-            }
+            Slog.i(TAG, "Unblocked screen on after " + delay + " ms");
+            Trace.asyncTraceEnd(Trace.TRACE_TAG_POWER, SCREEN_ON_BLOCKED_TRACE_NAME, 0);
         }
     }
 

diff --git a/services/core/java/com/android/server/display/DisplayPowerState.java b/services/core/java/com/android/server/display/DisplayPowerState.java
index 6522b89..a7651e4 100644 (file)
--- a/services/core/java/com/android/server/display/DisplayPowerState.java
+++ b/services/core/java/com/android/server/display/DisplayPowerState.java
@@ -23,6 +23,7 @@ import android.os.AsyncTask;
 import android.os.Handler;
 import android.os.Looper;
 import android.os.PowerManager;
+import android.os.Trace;
 import android.util.FloatProperty;
 import android.util.IntProperty;
 import android.util.Slog;
@@ -405,19 +406,38 @@ final class DisplayPowerState {
                     }
                     boolean suspending = Display.isSuspendedState(state);
                     if (stateChanged && !suspending) {
-                        mBlanker.requestDisplayState(state);
+                        requestDisplayState(state);
                     }
                     if (backlightChanged) {
-                        mBacklight.setBrightness(backlight);
+                        setBrightness(backlight);
                     }
                     if (stateChanged && suspending) {
-                        mBlanker.requestDisplayState(state);
+                        requestDisplayState(state);
                     }
                 }
 
                 // Let the outer class know that all changes have been applied.
                 postScreenUpdateThreadSafe();
             }
+
+            private void requestDisplayState(int state) {
+                Trace.traceBegin(Trace.TRACE_TAG_POWER, "requestDisplayState("
+                        + Display.stateToString(state) + ")");
+                try {
+                    mBlanker.requestDisplayState(state);
+                } finally {
+                    Trace.traceEnd(Trace.TRACE_TAG_POWER);
+                }
+            }
+
+            private void setBrightness(int backlight) {
+                Trace.traceBegin(Trace.TRACE_TAG_POWER, "setBrightness(" + backlight + ")");
+                try {
+                    mBacklight.setBrightness(backlight);
+                } finally {
+                    Trace.traceEnd(Trace.TRACE_TAG_POWER);
+                }
+            }
         };
     }
 }

diff --git a/services/core/java/com/android/server/display/LocalDisplayAdapter.java b/services/core/java/com/android/server/display/LocalDisplayAdapter.java
index 4fd006d..9c91ab5 100644 (file)
--- a/services/core/java/com/android/server/display/LocalDisplayAdapter.java
+++ b/services/core/java/com/android/server/display/LocalDisplayAdapter.java
@@ -21,7 +21,7 @@ import android.os.Handler;
 import android.os.IBinder;
 import android.os.Looper;
 import android.os.SystemProperties;
-import android.util.Pair;
+import android.os.Trace;
 import android.util.Slog;
 import android.util.SparseArray;
 import android.view.Display;
@@ -224,8 +224,14 @@ final class LocalDisplayAdapter extends DisplayAdapter {
         @Override
         public void requestDisplayStateLocked(int state) {
             if (mState != state) {
-                SurfaceControl.setDisplayPowerMode(getDisplayTokenLocked(),
-                        getPowerModeForState(state));
+                final int mode = getPowerModeForState(state);
+                Trace.traceBegin(Trace.TRACE_TAG_POWER, "requestDisplayState("
+                        + Display.stateToString(state) + ", id=" + mBuiltInDisplayId + ")");
+                try {
+                    SurfaceControl.setDisplayPowerMode(getDisplayTokenLocked(), mode);
+                } finally {
+                    Trace.traceEnd(Trace.TRACE_TAG_POWER);
+                }
                 mState = state;
                 updateDeviceInfoLocked();
             }

diff --git a/services/core/java/com/android/server/dreams/DreamController.java b/services/core/java/com/android/server/dreams/DreamController.java
index 334f0ac..768ccf2 100644 (file)
--- a/services/core/java/com/android/server/dreams/DreamController.java
+++ b/services/core/java/com/android/server/dreams/DreamController.java
@@ -25,6 +25,7 @@ import android.os.Handler;
 import android.os.IBinder;
 import android.os.RemoteException;
 import android.os.IBinder.DeathRecipient;
+import android.os.Trace;
 import android.os.UserHandle;
 import android.service.dreams.DreamService;
 import android.service.dreams.IDreamService;
@@ -111,41 +112,46 @@ final class DreamController {
             boolean isTest, boolean canDoze, int userId) {
         stopDream(true /*immediate*/);
 
-        // Close the notification shade. Don't need to send to all, but better to be explicit.
-        mContext.sendBroadcastAsUser(mCloseNotificationShadeIntent, UserHandle.ALL);
+        Trace.traceBegin(Trace.TRACE_TAG_POWER, "startDream");
+        try {
+            // Close the notification shade. Don't need to send to all, but better to be explicit.
+            mContext.sendBroadcastAsUser(mCloseNotificationShadeIntent, UserHandle.ALL);
 
-        Slog.i(TAG, "Starting dream: name=" + name
-                + ", isTest=" + isTest + ", canDoze=" + canDoze
-                + ", userId=" + userId);
+            Slog.i(TAG, "Starting dream: name=" + name
+                    + ", isTest=" + isTest + ", canDoze=" + canDoze
+                    + ", userId=" + userId);
 
-        mCurrentDream = new DreamRecord(token, name, isTest, canDoze, userId);
+            mCurrentDream = new DreamRecord(token, name, isTest, canDoze, userId);
 
-        try {
-            mIWindowManager.addWindowToken(token, WindowManager.LayoutParams.TYPE_DREAM);
-        } catch (RemoteException ex) {
-            Slog.e(TAG, "Unable to add window token for dream.", ex);
-            stopDream(true /*immediate*/);
-            return;
-        }
+            try {
+                mIWindowManager.addWindowToken(token, WindowManager.LayoutParams.TYPE_DREAM);
+            } catch (RemoteException ex) {
+                Slog.e(TAG, "Unable to add window token for dream.", ex);
+                stopDream(true /*immediate*/);
+                return;
+            }
 
-        Intent intent = new Intent(DreamService.SERVICE_INTERFACE);
-        intent.setComponent(name);
-        intent.addFlags(Intent.FLAG_ACTIVITY_EXCLUDE_FROM_RECENTS);
-        try {
-            if (!mContext.bindServiceAsUser(intent, mCurrentDream,
-                    Context.BIND_AUTO_CREATE, new UserHandle(userId))) {
-                Slog.e(TAG, "Unable to bind dream service: " + intent);
+            Intent intent = new Intent(DreamService.SERVICE_INTERFACE);
+            intent.setComponent(name);
+            intent.addFlags(Intent.FLAG_ACTIVITY_EXCLUDE_FROM_RECENTS);
+            try {
+                if (!mContext.bindServiceAsUser(intent, mCurrentDream,
+                        Context.BIND_AUTO_CREATE, new UserHandle(userId))) {
+                    Slog.e(TAG, "Unable to bind dream service: " + intent);
+                    stopDream(true /*immediate*/);
+                    return;
+                }
+            } catch (SecurityException ex) {
+                Slog.e(TAG, "Unable to bind dream service: " + intent, ex);
                 stopDream(true /*immediate*/);
                 return;
             }
-        } catch (SecurityException ex) {
-            Slog.e(TAG, "Unable to bind dream service: " + intent, ex);
-            stopDream(true /*immediate*/);
-            return;
-        }
 
-        mCurrentDream.mBound = true;
-        mHandler.postDelayed(mStopUnconnectedDreamRunnable, DREAM_CONNECTION_TIMEOUT);
+            mCurrentDream.mBound = true;
+            mHandler.postDelayed(mStopUnconnectedDreamRunnable, DREAM_CONNECTION_TIMEOUT);
+        } finally {
+            Trace.traceEnd(Trace.TRACE_TAG_POWER);
+        }
     }
 
     public void stopDream(boolean immediate) {
@@ -153,71 +159,76 @@ final class DreamController {
             return;
         }
 
-        if (!immediate) {
-            if (mCurrentDream.mWakingGently) {
-                return; // already waking gently
-            }
+        Trace.traceBegin(Trace.TRACE_TAG_POWER, "stopDream");
+        try {
+            if (!immediate) {
+                if (mCurrentDream.mWakingGently) {
+                    return; // already waking gently
+                }
 
-            if (mCurrentDream.mService != null) {
-                // Give the dream a moment to wake up and finish itself gently.
-                mCurrentDream.mWakingGently = true;
-                try {
-                    mCurrentDream.mService.wakeUp();
-                    mHandler.postDelayed(mStopStubbornDreamRunnable, DREAM_FINISH_TIMEOUT);
-                    return;
-                } catch (RemoteException ex) {
-                    // oh well, we tried, finish immediately instead
+                if (mCurrentDream.mService != null) {
+                    // Give the dream a moment to wake up and finish itself gently.
+                    mCurrentDream.mWakingGently = true;
+                    try {
+                        mCurrentDream.mService.wakeUp();
+                        mHandler.postDelayed(mStopStubbornDreamRunnable, DREAM_FINISH_TIMEOUT);
+                        return;
+                    } catch (RemoteException ex) {
+                        // oh well, we tried, finish immediately instead
+                    }
                 }
             }
-        }
 
-        final DreamRecord oldDream = mCurrentDream;
-        mCurrentDream = null;
-        Slog.i(TAG, "Stopping dream: name=" + oldDream.mName
-                + ", isTest=" + oldDream.mIsTest + ", canDoze=" + oldDream.mCanDoze
-                + ", userId=" + oldDream.mUserId);
+            final DreamRecord oldDream = mCurrentDream;
+            mCurrentDream = null;
+            Slog.i(TAG, "Stopping dream: name=" + oldDream.mName
+                    + ", isTest=" + oldDream.mIsTest + ", canDoze=" + oldDream.mCanDoze
+                    + ", userId=" + oldDream.mUserId);
 
-        mHandler.removeCallbacks(mStopUnconnectedDreamRunnable);
-        mHandler.removeCallbacks(mStopStubbornDreamRunnable);
+            mHandler.removeCallbacks(mStopUnconnectedDreamRunnable);
+            mHandler.removeCallbacks(mStopStubbornDreamRunnable);
 
-        if (oldDream.mSentStartBroadcast) {
-            mContext.sendBroadcastAsUser(mDreamingStoppedIntent, UserHandle.ALL);
-        }
+            if (oldDream.mSentStartBroadcast) {
+                mContext.sendBroadcastAsUser(mDreamingStoppedIntent, UserHandle.ALL);
+            }
 
-        if (oldDream.mService != null) {
-            // Tell the dream that it's being stopped so that
-            // it can shut down nicely before we yank its window token out from
-            // under it.
-            try {
-                oldDream.mService.detach();
-            } catch (RemoteException ex) {
-                // we don't care; this thing is on the way out
+            if (oldDream.mService != null) {
+                // Tell the dream that it's being stopped so that
+                // it can shut down nicely before we yank its window token out from
+                // under it.
+                try {
+                    oldDream.mService.detach();
+                } catch (RemoteException ex) {
+                    // we don't care; this thing is on the way out
+                }
+
+                try {
+                    oldDream.mService.asBinder().unlinkToDeath(oldDream, 0);
+                } catch (NoSuchElementException ex) {
+                    // don't care
+                }
+                oldDream.mService = null;
             }
 
-            try {
-                oldDream.mService.asBinder().unlinkToDeath(oldDream, 0);
-            } catch (NoSuchElementException ex) {
-                // don't care
+            if (oldDream.mBound) {
+                mContext.unbindService(oldDream);
             }
-            oldDream.mService = null;
-        }
 
-        if (oldDream.mBound) {
-            mContext.unbindService(oldDream);
-        }
+            try {
+                mIWindowManager.removeWindowToken(oldDream.mToken);
+            } catch (RemoteException ex) {
+                Slog.w(TAG, "Error removing window token for dream.", ex);
+            }
 
-        try {
-            mIWindowManager.removeWindowToken(oldDream.mToken);
-        } catch (RemoteException ex) {
-            Slog.w(TAG, "Error removing window token for dream.", ex);
+            mHandler.post(new Runnable() {
+                @Override
+                public void run() {
+                    mListener.onDreamStopped(oldDream.mToken);
+                }
+            });
+        } finally {
+            Trace.traceEnd(Trace.TRACE_TAG_POWER);
         }
-
-        mHandler.post(new Runnable() {
-            @Override
-            public void run() {
-                mListener.onDreamStopped(oldDream.mToken);
-            }
-        });
     }
 
     private void attach(IDreamService service) {

diff --git a/services/core/java/com/android/server/lights/LightsService.java b/services/core/java/com/android/server/lights/LightsService.java
index 94cf668..9dcc529 100644 (file)
--- a/services/core/java/com/android/server/lights/LightsService.java
+++ b/services/core/java/com/android/server/lights/LightsService.java
@@ -23,6 +23,7 @@ import android.content.pm.PackageManager;
 import android.os.Handler;
 import android.os.IHardwareService;
 import android.os.Message;
+import android.os.Trace;
 import android.util.Slog;
 
 import java.io.FileInputStream;
@@ -105,7 +106,12 @@ public class LightsService extends SystemService {
                 mMode = mode;
                 mOnMS = onMS;
                 mOffMS = offMS;
-                setLight_native(mNativePointer, mId, color, mode, onMS, offMS, brightnessMode);
+                Trace.traceBegin(Trace.TRACE_TAG_POWER, "setLight(" + mId + ", " + color + ")");
+                try {
+                    setLight_native(mNativePointer, mId, color, mode, onMS, offMS, brightnessMode);
+                } finally {
+                    Trace.traceEnd(Trace.TRACE_TAG_POWER);
+                }
             }
         }
 

diff --git a/services/core/java/com/android/server/power/Notifier.java b/services/core/java/com/android/server/power/Notifier.java
index 2b4a24a..4649724 100644 (file)
--- a/services/core/java/com/android/server/power/Notifier.java
+++ b/services/core/java/com/android/server/power/Notifier.java
@@ -406,7 +406,6 @@ final class Notifier {
 
     private void sendNextBroadcast() {
         final int powerState;
-        final int goToSleepReason;
         synchronized (mLock) {
             if (mBroadcastedPowerState == POWER_STATE_UNKNOWN) {
                 // Broadcasted power state is unknown.  Send wake up.

diff --git a/services/core/java/com/android/server/power/PowerManagerService.java b/services/core/java/com/android/server/power/PowerManagerService.java
index db19285..41db2c3 100644 (file)
--- a/services/core/java/com/android/server/power/PowerManagerService.java
+++ b/services/core/java/com/android/server/power/PowerManagerService.java
@@ -56,6 +56,7 @@ import android.os.RemoteException;
 import android.os.SystemClock;
 import android.os.SystemProperties;
 import android.os.SystemService;
+import android.os.Trace;
 import android.os.UserHandle;
 import android.os.WorkSource;
 import android.provider.Settings;
@@ -817,17 +818,12 @@ public final class PowerManagerService extends com.android.server.SystemService
                         + " [" + wakeLock.mTag + "], flags=0x" + Integer.toHexString(flags));
             }
 
-            mWakeLocks.remove(index);
-            notifyWakeLockReleasedLocked(wakeLock);
-            wakeLock.mLock.unlinkToDeath(wakeLock, 0);
-
             if ((flags & PowerManager.WAIT_FOR_PROXIMITY_NEGATIVE) != 0) {
                 mRequestWaitForNegativeProximity = true;
             }
 
-            applyWakeLockFlagsOnReleaseLocked(wakeLock);
-            mDirty |= DIRTY_WAKE_LOCKS;
-            updatePowerStateLocked();
+            wakeLock.mLock.unlinkToDeath(wakeLock, 0);
+            removeWakeLockLocked(wakeLock, index);
         }
     }
 
@@ -843,15 +839,19 @@ public final class PowerManagerService extends com.android.server.SystemService
                 return;
             }
 
-            mWakeLocks.remove(index);
-            notifyWakeLockReleasedLocked(wakeLock);
-
-            applyWakeLockFlagsOnReleaseLocked(wakeLock);
-            mDirty |= DIRTY_WAKE_LOCKS;
-            updatePowerStateLocked();
+            removeWakeLockLocked(wakeLock, index);
         }
     }
 
+    private void removeWakeLockLocked(WakeLock wakeLock, int index) {
+        mWakeLocks.remove(index);
+        notifyWakeLockReleasedLocked(wakeLock);
+
+        applyWakeLockFlagsOnReleaseLocked(wakeLock);
+        mDirty |= DIRTY_WAKE_LOCKS;
+        updatePowerStateLocked();
+    }
+
     private void applyWakeLockFlagsOnReleaseLocked(WakeLock wakeLock) {
         if ((wakeLock.mFlags & PowerManager.ON_AFTER_RELEASE) != 0
                 && isScreenLock(wakeLock)) {
@@ -972,21 +972,26 @@ public final class PowerManagerService extends com.android.server.SystemService
             return false;
         }
 
-        mNotifier.onUserActivity(event, uid);
+        Trace.traceBegin(Trace.TRACE_TAG_POWER, "userActivity");
+        try {
+            mNotifier.onUserActivity(event, uid);
 
-        if ((flags & PowerManager.USER_ACTIVITY_FLAG_NO_CHANGE_LIGHTS) != 0) {
-            if (eventTime > mLastUserActivityTimeNoChangeLights
-                    && eventTime > mLastUserActivityTime) {
-                mLastUserActivityTimeNoChangeLights = eventTime;
-                mDirty |= DIRTY_USER_ACTIVITY;
-                return true;
-            }
-        } else {
-            if (eventTime > mLastUserActivityTime) {
-                mLastUserActivityTime = eventTime;
-                mDirty |= DIRTY_USER_ACTIVITY;
-                return true;
+            if ((flags & PowerManager.USER_ACTIVITY_FLAG_NO_CHANGE_LIGHTS) != 0) {
+                if (eventTime > mLastUserActivityTimeNoChangeLights
+                        && eventTime > mLastUserActivityTime) {
+                    mLastUserActivityTimeNoChangeLights = eventTime;
+                    mDirty |= DIRTY_USER_ACTIVITY;
+                    return true;
+                }
+            } else {
+                if (eventTime > mLastUserActivityTime) {
+                    mLastUserActivityTime = eventTime;
+                    mDirty |= DIRTY_USER_ACTIVITY;
+                    return true;
+                }
             }
+        } finally {
+            Trace.traceEnd(Trace.TRACE_TAG_POWER);
         }
         return false;
     }
@@ -1009,25 +1014,30 @@ public final class PowerManagerService extends com.android.server.SystemService
             return false;
         }
 
-        switch (mWakefulness) {
-            case WAKEFULNESS_ASLEEP:
-                Slog.i(TAG, "Waking up from sleep (uid " + uid +")...");
-                break;
-            case WAKEFULNESS_DREAMING:
-                Slog.i(TAG, "Waking up from dream (uid " + uid +")...");
-                break;
-            case WAKEFULNESS_DOZING:
-                Slog.i(TAG, "Waking up from dozing (uid " + uid +")...");
-                break;
-        }
+        Trace.traceBegin(Trace.TRACE_TAG_POWER, "wakeUp");
+        try {
+            switch (mWakefulness) {
+                case WAKEFULNESS_ASLEEP:
+                    Slog.i(TAG, "Waking up from sleep (uid " + uid +")...");
+                    break;
+                case WAKEFULNESS_DREAMING:
+                    Slog.i(TAG, "Waking up from dream (uid " + uid +")...");
+                    break;
+                case WAKEFULNESS_DOZING:
+                    Slog.i(TAG, "Waking up from dozing (uid " + uid +")...");
+                    break;
+            }
 
-        mLastWakeTime = eventTime;
-        mDirty |= DIRTY_WAKEFULNESS;
-        mWakefulness = WAKEFULNESS_AWAKE;
-        setInteractiveStateLocked(true, 0);
+            mLastWakeTime = eventTime;
+            mDirty |= DIRTY_WAKEFULNESS;
+            mWakefulness = WAKEFULNESS_AWAKE;
+            setInteractiveStateLocked(true, 0);
 
-        userActivityNoUpdateLocked(
-                eventTime, PowerManager.USER_ACTIVITY_EVENT_OTHER, 0, uid);
+            userActivityNoUpdateLocked(
+                    eventTime, PowerManager.USER_ACTIVITY_EVENT_OTHER, 0, uid);
+        } finally {
+            Trace.traceEnd(Trace.TRACE_TAG_POWER);
+        }
         return true;
     }
 
@@ -1055,53 +1065,58 @@ public final class PowerManagerService extends com.android.server.SystemService
             return false;
         }
 
-        switch (reason) {
-            case PowerManager.GO_TO_SLEEP_REASON_DEVICE_ADMIN:
-                Slog.i(TAG, "Going to sleep due to device administration policy "
-                        + "(uid " + uid +")...");
-                break;
-            case PowerManager.GO_TO_SLEEP_REASON_TIMEOUT:
-                Slog.i(TAG, "Going to sleep due to screen timeout (uid " + uid +")...");
-                break;
-            case PowerManager.GO_TO_SLEEP_REASON_LID_SWITCH:
-                Slog.i(TAG, "Going to sleep due to lid switch (uid " + uid +")...");
-                break;
-            case PowerManager.GO_TO_SLEEP_REASON_POWER_BUTTON:
-                Slog.i(TAG, "Going to sleep due to power button (uid " + uid +")...");
-                break;
-            case PowerManager.GO_TO_SLEEP_REASON_HDMI:
-                Slog.i(TAG, "Going to sleep due to HDMI standby (uid " + uid +")...");
-                break;
-            default:
-                Slog.i(TAG, "Going to sleep by application request (uid " + uid +")...");
-                reason = PowerManager.GO_TO_SLEEP_REASON_APPLICATION;
-                break;
-        }
-
-        mLastSleepTime = eventTime;
-        mDirty |= DIRTY_WAKEFULNESS;
-        mWakefulness = WAKEFULNESS_DOZING;
-        mSandmanSummoned = true;
-        setInteractiveStateLocked(false, reason);
-
-        // Report the number of wake locks that will be cleared by going to sleep.
-        int numWakeLocksCleared = 0;
-        final int numWakeLocks = mWakeLocks.size();
-        for (int i = 0; i < numWakeLocks; i++) {
-            final WakeLock wakeLock = mWakeLocks.get(i);
-            switch (wakeLock.mFlags & PowerManager.WAKE_LOCK_LEVEL_MASK) {
-                case PowerManager.FULL_WAKE_LOCK:
-                case PowerManager.SCREEN_BRIGHT_WAKE_LOCK:
-                case PowerManager.SCREEN_DIM_WAKE_LOCK:
-                    numWakeLocksCleared += 1;
+        Trace.traceBegin(Trace.TRACE_TAG_POWER, "goToSleep");
+        try {
+            switch (reason) {
+                case PowerManager.GO_TO_SLEEP_REASON_DEVICE_ADMIN:
+                    Slog.i(TAG, "Going to sleep due to device administration policy "
+                            + "(uid " + uid +")...");
+                    break;
+                case PowerManager.GO_TO_SLEEP_REASON_TIMEOUT:
+                    Slog.i(TAG, "Going to sleep due to screen timeout (uid " + uid +")...");
+                    break;
+                case PowerManager.GO_TO_SLEEP_REASON_LID_SWITCH:
+                    Slog.i(TAG, "Going to sleep due to lid switch (uid " + uid +")...");
+                    break;
+                case PowerManager.GO_TO_SLEEP_REASON_POWER_BUTTON:
+                    Slog.i(TAG, "Going to sleep due to power button (uid " + uid +")...");
+                    break;
+                case PowerManager.GO_TO_SLEEP_REASON_HDMI:
+                    Slog.i(TAG, "Going to sleep due to HDMI standby (uid " + uid +")...");
+                    break;
+                default:
+                    Slog.i(TAG, "Going to sleep by application request (uid " + uid +")...");
+                    reason = PowerManager.GO_TO_SLEEP_REASON_APPLICATION;
                     break;
             }
-        }
-        EventLog.writeEvent(EventLogTags.POWER_SLEEP_REQUESTED, numWakeLocksCleared);
 
-        // Skip dozing if requested.
-        if ((flags & PowerManager.GO_TO_SLEEP_FLAG_NO_DOZE) != 0) {
-            reallyGoToSleepNoUpdateLocked(eventTime, uid);
+            mLastSleepTime = eventTime;
+            mDirty |= DIRTY_WAKEFULNESS;
+            mWakefulness = WAKEFULNESS_DOZING;
+            mSandmanSummoned = true;
+            setInteractiveStateLocked(false, reason);
+
+            // Report the number of wake locks that will be cleared by going to sleep.
+            int numWakeLocksCleared = 0;
+            final int numWakeLocks = mWakeLocks.size();
+            for (int i = 0; i < numWakeLocks; i++) {
+                final WakeLock wakeLock = mWakeLocks.get(i);
+                switch (wakeLock.mFlags & PowerManager.WAKE_LOCK_LEVEL_MASK) {
+                    case PowerManager.FULL_WAKE_LOCK:
+                    case PowerManager.SCREEN_BRIGHT_WAKE_LOCK:
+                    case PowerManager.SCREEN_DIM_WAKE_LOCK:
+                        numWakeLocksCleared += 1;
+                        break;
+                }
+            }
+            EventLog.writeEvent(EventLogTags.POWER_SLEEP_REQUESTED, numWakeLocksCleared);
+
+            // Skip dozing if requested.
+            if ((flags & PowerManager.GO_TO_SLEEP_FLAG_NO_DOZE) != 0) {
+                reallyGoToSleepNoUpdateLocked(eventTime, uid);
+            }
+        } finally {
+            Trace.traceEnd(Trace.TRACE_TAG_POWER);
         }
         return true;
     }
@@ -1124,12 +1139,17 @@ public final class PowerManagerService extends com.android.server.SystemService
             return false;
         }
 
-        Slog.i(TAG, "Nap time (uid " + uid +")...");
+        Trace.traceBegin(Trace.TRACE_TAG_POWER, "nap");
+        try {
+            Slog.i(TAG, "Nap time (uid " + uid +")...");
 
-        mDirty |= DIRTY_WAKEFULNESS;
-        mWakefulness = WAKEFULNESS_DREAMING;
-        mSandmanSummoned = true;
-        setInteractiveStateLocked(true, 0);
+            mDirty |= DIRTY_WAKEFULNESS;
+            mWakefulness = WAKEFULNESS_DREAMING;
+            mSandmanSummoned = true;
+            setInteractiveStateLocked(true, 0);
+        } finally {
+            Trace.traceEnd(Trace.TRACE_TAG_POWER);
+        }
         return true;
     }
 
@@ -1145,11 +1165,16 @@ public final class PowerManagerService extends com.android.server.SystemService
             return false;
         }
 
-        Slog.i(TAG, "Sleeping (uid " + uid +")...");
+        Trace.traceBegin(Trace.TRACE_TAG_POWER, "reallyGoToSleep");
+        try {
+            Slog.i(TAG, "Sleeping (uid " + uid +")...");
 
-        mDirty |= DIRTY_WAKEFULNESS;
-        mWakefulness = WAKEFULNESS_ASLEEP;
-        setInteractiveStateLocked(false, PowerManager.GO_TO_SLEEP_REASON_TIMEOUT);
+            mDirty |= DIRTY_WAKEFULNESS;
+            mWakefulness = WAKEFULNESS_ASLEEP;
+            setInteractiveStateLocked(false, PowerManager.GO_TO_SLEEP_REASON_TIMEOUT);
+        } finally {
+            Trace.traceEnd(Trace.TRACE_TAG_POWER);
+        }
         return true;
     }
 
@@ -1186,40 +1211,45 @@ public final class PowerManagerService extends com.android.server.SystemService
             Slog.wtf(TAG, "Power manager lock was not held when calling updatePowerStateLocked");
         }
 
-        // Phase 0: Basic state updates.
-        updateIsPoweredLocked(mDirty);
-        updateStayOnLocked(mDirty);
-
-        // Phase 1: Update wakefulness.
-        // Loop because the wake lock and user activity computations are influenced
-        // by changes in wakefulness.
-        final long now = SystemClock.uptimeMillis();
-        int dirtyPhase2 = 0;
-        for (;;) {
-            int dirtyPhase1 = mDirty;
-            dirtyPhase2 |= dirtyPhase1;
-            mDirty = 0;
+        Trace.traceBegin(Trace.TRACE_TAG_POWER, "updatePowerState");
+        try {
+            // Phase 0: Basic state updates.
+            updateIsPoweredLocked(mDirty);
+            updateStayOnLocked(mDirty);
 
-            updateWakeLockSummaryLocked(dirtyPhase1);
-            updateUserActivitySummaryLocked(now, dirtyPhase1);
-            if (!updateWakefulnessLocked(dirtyPhase1)) {
-                break;
+            // Phase 1: Update wakefulness.
+            // Loop because the wake lock and user activity computations are influenced
+            // by changes in wakefulness.
+            final long now = SystemClock.uptimeMillis();
+            int dirtyPhase2 = 0;
+            for (;;) {
+                int dirtyPhase1 = mDirty;
+                dirtyPhase2 |= dirtyPhase1;
+                mDirty = 0;
+
+                updateWakeLockSummaryLocked(dirtyPhase1);
+                updateUserActivitySummaryLocked(now, dirtyPhase1);
+                if (!updateWakefulnessLocked(dirtyPhase1)) {
+                    break;
+                }
             }
-        }
 
-        // Phase 2: Update dreams and display power state.
-        updateDreamLocked(dirtyPhase2);
-        updateDisplayPowerStateLocked(dirtyPhase2);
+            // Phase 2: Update dreams and display power state.
+            updateDreamLocked(dirtyPhase2);
+            updateDisplayPowerStateLocked(dirtyPhase2);
 
-        // Phase 3: Send notifications, if needed.
-        if (mDisplayReady) {
-            finishInteractiveStateChangeLocked();
-        }
+            // Phase 3: Send notifications, if needed.
+            if (mDisplayReady) {
+                finishInteractiveStateChangeLocked();
+            }
 
-        // Phase 4: Update suspend blocker.
-        // Because we might release the last suspend blocker here, we need to make sure
-        // we finished everything else first!
-        updateSuspendBlockerLocked();
+            // Phase 4: Update suspend blocker.
+            // Because we might release the last suspend blocker here, we need to make sure
+            // we finished everything else first!
+            updateSuspendBlockerLocked();
+        } finally {
+            Trace.traceEnd(Trace.TRACE_TAG_POWER);
+        }
     }
 
     /**
@@ -1990,7 +2020,12 @@ public final class PowerManagerService extends com.android.server.SystemService
                 Slog.d(TAG, "Setting HAL auto-suspend mode to " + enable);
             }
             mHalAutoSuspendModeEnabled = enable;
-            nativeSetAutoSuspend(enable);
+            Trace.traceBegin(Trace.TRACE_TAG_POWER, "setHalAutoSuspend(" + enable + ")");
+            try {
+                nativeSetAutoSuspend(enable);
+            } finally {
+                Trace.traceEnd(Trace.TRACE_TAG_POWER);
+            }
         }
     }
 
@@ -2000,7 +2035,12 @@ public final class PowerManagerService extends com.android.server.SystemService
                 Slog.d(TAG, "Setting HAL interactive mode to " + enable);
             }
             mHalInteractiveModeEnabled = enable;
-            nativeSetInteractive(enable);
+            Trace.traceBegin(Trace.TRACE_TAG_POWER, "setHalInteractive(" + enable + ")");
+            try {
+                nativeSetInteractive(enable);
+            } finally {
+                Trace.traceEnd(Trace.TRACE_TAG_POWER);
+            }
         }
     }
 
@@ -2587,20 +2627,23 @@ public final class PowerManagerService extends com.android.server.SystemService
 
     private final class SuspendBlockerImpl implements SuspendBlocker {
         private final String mName;
+        private final String mTraceName;
         private int mReferenceCount;
 
         public SuspendBlockerImpl(String name) {
             mName = name;
+            mTraceName = "SuspendBlocker (" + name + ")";
         }
 
         @Override
         protected void finalize() throws Throwable {
             try {
                 if (mReferenceCount != 0) {
-                    Log.wtf(TAG, "Suspend blocker \"" + mName
+                    Slog.wtf(TAG, "Suspend blocker \"" + mName
                             + "\" was finalized without being released!");
                     mReferenceCount = 0;
                     nativeReleaseSuspendBlocker(mName);
+                    Trace.asyncTraceEnd(Trace.TRACE_TAG_POWER, mTraceName, 0);
                 }
             } finally {
                 super.finalize();
@@ -2615,6 +2658,7 @@ public final class PowerManagerService extends com.android.server.SystemService
                     if (DEBUG_SPEW) {
                         Slog.d(TAG, "Acquiring suspend blocker \"" + mName + "\".");
                     }
+                    Trace.asyncTraceBegin(Trace.TRACE_TAG_POWER, mTraceName, 0);
                     nativeAcquireSuspendBlocker(mName);
                 }
             }
@@ -2629,8 +2673,9 @@ public final class PowerManagerService extends com.android.server.SystemService
                         Slog.d(TAG, "Releasing suspend blocker \"" + mName + "\".");
                     }
                     nativeReleaseSuspendBlocker(mName);
+                    Trace.asyncTraceEnd(Trace.TRACE_TAG_POWER, mTraceName, 0);
                 } else if (mReferenceCount < 0) {
-                    Log.wtf(TAG, "Suspend blocker \"" + mName
+                    Slog.wtf(TAG, "Suspend blocker \"" + mName
                             + "\" was released without being acquired!", new Throwable());
                     mReferenceCount = 0;
                 }
@@ -2646,6 +2691,8 @@ public final class PowerManagerService extends com.android.server.SystemService
     }
 
     private final class ScreenOnBlockerImpl implements ScreenOnBlocker {
+        private static final String TRACE_NAME = "ScreenOnBlocker";
+
         private int mNestCount;
 
         public boolean isHeld() {
@@ -2658,9 +2705,12 @@ public final class PowerManagerService extends com.android.server.SystemService
         public void acquire() {
             synchronized (this) {
                 mNestCount += 1;
-                if (DEBUG) {
+                if (DEBUG || true) {
                     Slog.d(TAG, "Screen on blocked: mNestCount=" + mNestCount);
                 }
+                if (mNestCount == 1) {
+                    Trace.asyncTraceBegin(Trace.TRACE_TAG_POWER, TRACE_NAME, 0);
+                }
             }
         }
 
@@ -2668,16 +2718,16 @@ public final class PowerManagerService extends com.android.server.SystemService
         public void release() {
             synchronized (this) {
                 mNestCount -= 1;
-                if (mNestCount < 0) {
-                    Log.wtf(TAG, "Screen on blocker was released without being acquired!",
-                            new Throwable());
-                    mNestCount = 0;
-                }
                 if (mNestCount == 0) {
+                    if (DEBUG || true) {
+                        Slog.d(TAG, "Screen on unblocked: mNestCount=" + mNestCount);
+                    }
                     mHandler.sendEmptyMessage(MSG_SCREEN_ON_BLOCKER_RELEASED);
-                }
-                if (DEBUG) {
-                    Slog.d(TAG, "Screen on unblocked: mNestCount=" + mNestCount);
+                    Trace.asyncTraceEnd(Trace.TRACE_TAG_POWER, TRACE_NAME, 0);
+                } else if (mNestCount < 0) {
+                    Slog.wtf(TAG, "Screen on blocker was released without being acquired!",
+                            new Throwable());
+                    mNestCount = 0;
                 }
             }
         }