Merge "Stop deferring wake lock logging." into sc-dev am: a5706d29

package com.android.server.power;

import android.os.Handler;

import android.os.Looper;

import android.os.Message;

import android.os.PowerManager;

import android.text.TextUtils;

import android.util.Slog;

import com.android.internal.annotations.VisibleForTesting;

import com.android.internal.os.BackgroundThread;

import com.android.internal.os.SomeArgs;

import java.io.PrintWriter;

import java.text.SimpleDateFormat;

    private static final boolean DEBUG = false;

    private static final int MSG_ON_WAKE_LOCK_EVENT = 1;

    private static final int TYPE_TIME_RESET = 0x0;

    private static final int TYPE_ACQUIRE = 0x1;

    private static final int TYPE_RELEASE = 0x2;

    private final Injector mInjector;

    private final TheLog mLog;

    private final TagDatabase mTagDatabase;

    private final Handler mHandler;

    private final SimpleDateFormat mDumpsysDateFormat;

    WakeLockLog() {

    @VisibleForTesting

    WakeLockLog(Injector injector) {

        mInjector = injector;

        mHandler = new WakeLockLogHandler(injector.getLooper());

        mTagDatabase = new TagDatabase(injector);

        EntryByteTranslator translator = new EntryByteTranslator(mTagDatabase);

        mLog = new TheLog(injector, translator, mTagDatabase);

     * Dumps all the wake lock data currently saved in the wake lock log to the specified

     * {@code PrintWriter}.

     *

     * @param The {@code PrintWriter} to write to.

     * @param pw The {@code PrintWriter} to write to.

     */

    public void dump(PrintWriter pw) {

        dump(pw, false);

    /**

     * Adds a new entry to the log based on the specified wake lock parameters.

     *

     * Grabs the current time for the event and then posts the rest of the logic (actually

     * adding it to the log) to a background thread.

     *

     * @param eventType The type of event (ACQUIRE, RELEASE);

     * @param tag The wake lock's identifying tag.

     * @param ownerUid The owner UID of the wake lock.

        }

        final long time = mInjector.currentTimeMillis();

        SomeArgs args = SomeArgs.obtain();

        args.arg1 = tagNameReducer(tag);

        args.argi1 = eventType;

        args.argi2 = ownerUid;

        args.argi3 = eventType == TYPE_ACQUIRE ? translateFlagsFromPowerManager(flags) : 0;

        args.argi4 = (int) ((time >> 32) & 0xFFFFFFFFL);

        args.argi5 = (int) (time & 0xFFFFFFFFL);

        mHandler.obtainMessage(MSG_ON_WAKE_LOCK_EVENT, args).sendToTarget();

        final int translatedFlags = eventType == TYPE_ACQUIRE

                ? translateFlagsFromPowerManager(flags)

                : 0;

        handleWakeLockEventInternal(eventType, tagNameReducer(tag), ownerUid, translatedFlags,

                time);

    }

    /**

     * flags, {@code WakeLockLog.FLAG_*}, and a log-level, {@code WakeLockLog.LEVEL_*}.

     *

     * @param flags Wake lock flags including {@code PowerManager.*_WAKE_LOCK}

     *              {@link PowerManager.ACQUIRE_CAUSES_WAKEUP}, and

     *              {@link PowerManager.ON_AFTER_RELEASE}.

     *              {@link PowerManager#ACQUIRE_CAUSES_WAKEUP}, and

     *              {@link PowerManager#ON_AFTER_RELEASE}.

     * @return The compressed flags value.

     */

    int translateFlagsFromPowerManager(int flags) {

        }

        String reduciblePrefix = null;

        for (int tp = 0; tp < REDUCED_TAG_PREFIXES.length; tp++) {

            if (tag.startsWith(REDUCED_TAG_PREFIXES[tp])) {

                reduciblePrefix = REDUCED_TAG_PREFIXES[tp];

        for (String reducedTagPrefix : REDUCED_TAG_PREFIXES) {

            if (tag.startsWith(reducedTagPrefix)) {

                reduciblePrefix = reducedTagPrefix;

                break;

            }

        }

            final StringBuilder sb = new StringBuilder();

            // add prefix first

            sb.append(tag.substring(0, reduciblePrefix.length()));

            sb.append(tag, 0, reduciblePrefix.length());

            // Stop looping on final marker

            final int end = Math.max(tag.lastIndexOf("/"), tag.lastIndexOf("."));

         * @return The number of bytes written to buffer, or required to write to the buffer.

         */

        int toBytes(LogEntry entry, byte[] bytes, long timeReference) {

            int sizeNeeded = -1;

            final int sizeNeeded;

            switch (entry.type) {

                case TYPE_ACQUIRE: {

                    sizeNeeded = 3;

     * {@link EntryByteTranslator} to convert byte {@link LogEntry} to bytes within the buffer.

     *

     * This class also implements the logic around TIME_RESET events. Since the LogEntries store

     * their time (8-bit) relative to the previous event, this class can add {@link TYPE_TIME_RESET}

     * LogEntries as necessary to allow a LogEntry's relative time to fit within that range.

     * their time (8-bit) relative to the previous event, this class can add

     * {@link #TYPE_TIME_RESET} LogEntries as necessary to allow a LogEntry's relative time to fit

     * within that range.

     */

    static class TheLog {

        private final EntryByteTranslator mTranslator;

        /**

         * Second temporary buffer used when reading and writing bytes from the buffer.

         * A second temporary buffer is necessary since additional items can be read concurrently

         * from {@link mTempBuffer}. E.g., Adding an entry to a full buffer requires removing

         * from {@link #mTempBuffer}. E.g., Adding an entry to a full buffer requires removing

         * other entries from the buffer.

         */

        private final byte[] mReadWriteTempBuffer = new byte[MAX_LOG_ENTRY_BYTE_SIZE];

         * Returns an {@link Iterator} of {@link LogEntry}s for all the entries in the log.

         *

         * If the log is modified while the entries are being read, the iterator will throw a

         * {@link ConcurrentModificationExceptoin}.

         * {@link ConcurrentModificationException}.

         *

         * @param tempEntry A temporary {@link LogEntry} instance to use so that new instances

         *                  aren't allocated with every call to {@code Iterator.next}.

     * instanced into bytes.

     *

     * If a new tag is added when the database is full, the oldest tag is removed. The oldest tag

     * is calcualted using {@link TagData.lastUsedTime}.

     * is calculated using {@link TagData#lastUsedTime}.

     */

    static class TagDatabase {

        private final int mInvalidIndex;

            int byteEstimate = 0;

            int tagSize = 0;

            int tags = 0;

            for (int i = 0; i < mArray.length; i++) {

            for (TagData tagData : mArray) {

                byteEstimate += 8;  // reference pointer

                TagData data = mArray[i];

                TagData data = tagData;

                if (data != null) {

                    entries++;

                    byteEstimate += data.getByteSize();

        @Override

        public String toString() {

            StringBuilder sb = new StringBuilder();

            if (DEBUG) {

                sb.append("(").append(index).append(")");

            }

            return "[" + ownerUid + " ; " + tag + "]";

        }

     * Injector used by {@link WakeLockLog} for testing purposes.

     */

    public static class Injector {

        public Looper getLooper() {

            return BackgroundThread.get().getLooper();

        }

        public int getTagDatabaseSize() {

            return TAG_DATABASE_SIZE;

        }

            return DATE_FORMAT;

        }

    }

    private class WakeLockLogHandler extends Handler {

        WakeLockLogHandler(Looper looper) {

            super(looper);

        }

        @Override

        public void handleMessage(Message message) {

            switch(message.what) {

                case MSG_ON_WAKE_LOCK_EVENT:

                    final SomeArgs args = (SomeArgs) message.obj;

                    final String tag = (String) args.arg1;

                    final int eventType = args.argi1;

                    final int ownerUid = args.argi2;

                    final int flags = args.argi3;

                    final long time = (((long) args.argi4) << 32) + (args.argi5 & 0xFFFFFFFFL);

                    args.recycle();

                    handleWakeLockEventInternal(eventType, tag, ownerUid, flags, time);

                    break;

                default:

                    break;

            }

        }

    }

}

import static org.mockito.Mockito.spy;

import static org.mockito.Mockito.when;

import android.os.Looper;

import android.os.PowerManager;

import android.os.test.TestLooper;

import org.junit.After;

import org.junit.Before;

import org.junit.Test;

import java.io.PrintWriter;

 */

public class WakeLockLogTest {

    private TestLooper mTestLooper;

    @Before

    public void setUp() throws Exception {

        mTestLooper = new TestLooper();

    }

    @After

    public void tearDown() throws Exception {

    }

    @Test

    public void testAddTwoItems() {

        final int tagDatabaseSize = 128;

                + "  -\n"

                + "  Events: 2, Time-Resets: 0\n"

                + "  Buffer, Bytes used: 6\n",

                dispatchAndDump(log, false));

                dumpLog(log, false));

    }

    @Test

                + "  -\n"

                + "  Events: 2, Time-Resets: 1\n"

                + "  Buffer, Bytes used: 15\n",

                dispatchAndDump(log, false));

                dumpLog(log, false));

    }

    @Test

                + "  -\n"

                + "  Events: 2, Time-Resets: 0\n"

                + "  Buffer, Bytes used: 6\n",

                dispatchAndDump(log, false));

                dumpLog(log, false));

    }

    @Test

                + "  -\n"

                + "  Events: 3, Time-Resets: 0\n"

                + "  Buffer, Bytes used: 9\n",

                dispatchAndDump(log, false));

                dumpLog(log, false));

    }

    @Test

                + "  -\n"

                + "  Events: 0, Time-Resets: 0\n"

                + "  Buffer, Bytes used: 0\n",

                dispatchAndDump(log, false));

                dumpLog(log, false));

    }

    @Test

                + "  -\n"

                + "  Events: 1, Time-Resets: 0\n"

                + "  Buffer, Bytes used: 3\n",

                dispatchAndDump(log, false));

                dumpLog(log, false));

    }

    @Test

                + "  Events: 2, Time-Resets: 0\n"

                + "  Buffer, Bytes used: 5\n"

                + "  Tag Database: size(5), entries: 1, Bytes used: 80\n",

                dispatchAndDump(log, true));

                dumpLog(log, true));

    }

    @Test

                + "  -\n"

                + "  Events: 1, Time-Resets: 0\n"

                + "  Buffer, Bytes used: 3\n",

                dispatchAndDump(log, false));

                dumpLog(log, false));

    }

    private String dispatchAndDump(WakeLockLog log, boolean includeTagDb) {

        mTestLooper.dispatchAll();

    private String dumpLog(WakeLockLog log, boolean includeTagDb) {

        StringWriter sw = new StringWriter();

        PrintWriter pw = new PrintWriter(sw);

        log.dump(pw, includeTagDb);

            mLogSize = logSize;

        }

        @Override

        public Looper getLooper() {

            return mTestLooper.getLooper();

        }

        @Override

        public int getTagDatabaseSize() {

            return mTagDatabaseSize;