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

Commit 14880558 authored by Chris Wren's avatar Chris Wren
Browse files

revise the reader semantics

checkpoint modifies the underlying log rather than reading timestamps.
reset replays without going back to the underlying log.
add a test

Bug: 32982362
Test: runtest --path frameworks/base/core/tests/coretests/src/android/metrics
Change-Id: I381b203a1c24fcd098d7df4d9d0a50bd8aaa1309
parent 296407ce
Loading
Loading
Loading
Loading
+129 −38
Original line number Diff line number Diff line
@@ -17,27 +17,41 @@ package android.metrics;

import android.annotation.SystemApi;
import android.util.EventLog;
import android.util.EventLog.Event;
import android.util.Log;

import com.android.internal.annotations.VisibleForTesting;
import com.android.internal.logging.MetricsLogger;
import com.android.internal.logging.nano.MetricsProto.MetricsEvent;

import java.io.IOException;
import java.util.ArrayList;
import java.util.Collection;
import java.util.LinkedList;
import java.util.Queue;

/**
 * Read platform logs.
 *
 * @hide
 */
@SystemApi
public class MetricsReader {
    private Queue<LogMaker> mEventQueue = new LinkedList<>();
    private long mLastEventMs;
    private long mCheckpointMs;
    private Queue<LogMaker> mPendingQueue = new LinkedList<>();
    private Queue<LogMaker> mSeenQueue = new LinkedList<>();
    private int[] LOGTAGS = {MetricsLogger.LOGTAG};

    private LogReader mReader = new LogReader();
    private int mCheckpointTag = -1;

    /**
     * Set the reader to isolate unit tests from the framework
     *
     * @hide
     */
    @VisibleForTesting
    public void setLogReader(LogReader reader) {
        mReader = reader;
    }

    /**
     * Read the available logs into a new session.
     *
@@ -59,14 +73,14 @@ public class MetricsReader {
    public void read(long horizonMs) {
        ArrayList<Event> nativeEvents = new ArrayList<>();
        try {
            EventLog.readEventsOnWrapping(LOGTAGS, horizonMs, nativeEvents);
            mReader.readEvents(LOGTAGS, horizonMs, nativeEvents);
        } catch (IOException e) {
            e.printStackTrace();
        }
        mEventQueue.clear();
        for (EventLog.Event event : nativeEvents) {
        mPendingQueue.clear();
        mSeenQueue.clear();
        for (Event event : nativeEvents) {
            final long eventTimestampMs = event.getTimeNanos() / 1000000;
            if (eventTimestampMs > mCheckpointMs) {
            Object data = event.getData();
            Object[] objects;
            if (data instanceof Object[]) {
@@ -76,45 +90,122 @@ public class MetricsReader {
                objects = new Object[1];
                objects[0] = data;
            }
                mEventQueue.add(new LogMaker(objects)
            final LogMaker log = new LogMaker(objects)
                    .setTimestamp(eventTimestampMs)
                        .setProcessId(event.getProcessId()));
                mLastEventMs = eventTimestampMs;
                    .setProcessId(event.getProcessId());
            if (log.getCategory() == MetricsEvent.METRICS_CHECKPOINT) {
                if (log.getSubtype() == mCheckpointTag) {
                    mPendingQueue.clear();
                }
            } else {
                mPendingQueue.offer(log);
            }
        }
    }

    /** Cause this session to only contain events that occur after this call. */
    /**
     * Empties the session and causes the next {@link #read(long)} to
     * yeild a session containing only events that occur after this call.
     */
    public void checkpoint() {
        // read the log to find the most recent event.
        read(0L);
        // write a checkpoint into the log stream
        mCheckpointTag = (int) (System.currentTimeMillis() % 0x7fffffff);
        mReader.writeCheckpoint(mCheckpointTag);
        // any queued event is now too old, so drop them.
        mEventQueue.clear();
        mCheckpointMs = mLastEventMs;
        mPendingQueue.clear();
        mSeenQueue.clear();
    }

    /**
     * Rewind the session to the beginning of time and read all available logs.
     *
     * A prior call to {@link #checkpoint()} will cause the reader to ignore
     * any event with a timestamp before the time of that call.
     *
     * The underlying log buffer is live: between calls to {@link #reset()}, older
     * events may be lost from the beginning of the session, and new events may
     * appear at the end.
     * Rewind the session to the beginning of time and replay all available logs.
     */
    public void reset() {
        read(0l);
        // flush the rest of hte pending events
        mSeenQueue.addAll(mPendingQueue);
        mPendingQueue.clear();
        mCheckpointTag = -1;

        // swap queues
        Queue<LogMaker> tmp = mPendingQueue;
        mPendingQueue = mSeenQueue;
        mSeenQueue = tmp;
    }

    /* Does the current log session have another entry? */
    public boolean hasNext() {
        return !mEventQueue.isEmpty();
        return !mPendingQueue.isEmpty();
    }

    /* Return the next entry in the current log session. */
    public LogMaker next() {
        return mEventQueue.poll();
        final LogMaker next = mPendingQueue.poll();
        if (next != null) {
            mSeenQueue.offer(next);
        }
        return next;
    }

    /**
     * Wrapper for the Event object, to facilitate testing.
     *
     * @hide
     */
    @VisibleForTesting
    public static class Event {
        long mTimeNanos;
        int mPid;
        Object mData;

        public Event(long timeNanos, int pid, Object data) {
            mTimeNanos = timeNanos;
            mPid = pid;
            mData = data;
        }

        Event(EventLog.Event nativeEvent) {
            mTimeNanos = nativeEvent.getTimeNanos();
            mPid = nativeEvent.getProcessId();
            mData = nativeEvent.getData();
        }

        public long getTimeNanos() {
            return mTimeNanos;
        }

        public int getProcessId() {
            return mPid;
        }

        public Object getData() {
            return mData;
        }

        public void setData(Object data) {
            mData = data;
        }
    }

    /**
     * Wrapper for the Event reader, to facilitate testing.
     *
     * @hide
     */
    @VisibleForTesting
    public static class LogReader {
        public void readEvents(int[] tags, long horizonMs, Collection<Event> events)
                throws IOException {
            // Testing in Android: the Static Final Class Strikes Back!
            ArrayList<EventLog.Event> nativeEvents = new ArrayList<>();
            EventLog.readEventsOnWrapping(tags, horizonMs, nativeEvents);
            for (EventLog.Event nativeEvent : nativeEvents) {
                Event event = new Event(nativeEvent);
                events.add(event);
            }
        }

        public void writeCheckpoint(int tag) {
            MetricsLogger logger = new MetricsLogger();
            logger.action(MetricsEvent.METRICS_CHECKPOINT, tag);
        }
    }
}
+106 −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 android.metrics;

import android.metrics.MetricsReader.Event;

import com.android.internal.logging.nano.MetricsProto.MetricsEvent;

import junit.framework.TestCase;

import java.util.Collection;

public class MetricsReaderTest extends TestCase {
    private static final int FULL_N = 10;
    private static final int CHECKPOINTED_N = 4;

    class FakeLogReader extends MetricsReader.LogReader {
        MetricsReader.Event[] mEvents;
        private long mHorizonMs;

        public FakeLogReader() {
            mEvents = new MetricsReader.Event[FULL_N];
            for (int i = 0; i < FULL_N; i++) {
                mEvents[i] = new MetricsReader.Event(
                        1000L + i,
                        1,
                        new LogMaker(i).serialize());
            }
        }

        @Override
        public void readEvents(int[] tags, long horizonMs, Collection<Event> events) {
            mHorizonMs = horizonMs;
            for (int i = 0; i < mEvents.length; i++) {
                events.add(mEvents[i]);
            }
        }

        @Override
        public void writeCheckpoint(int tag) {
            int i = FULL_N - CHECKPOINTED_N - 1;
            mEvents[i].setData(new LogMaker(MetricsEvent.METRICS_CHECKPOINT)
                    .setSubtype(tag)
                    .serialize());
        }
    }
    FakeLogReader mLogReader;
    MetricsReader mReader = new MetricsReader();

    public void setUp() {
        mLogReader = new FakeLogReader();
        mReader.setLogReader(mLogReader);
    }

    public void testNonBlockingRead() {
        mReader.read(0);
        assertEquals(0, mLogReader.mHorizonMs);
        for (int i = 0; i < FULL_N; i++) {
            assertTrue(mReader.hasNext());
            LogMaker log = mReader.next();
            assertEquals(i, log.getCategory());
        }
    }

    public void testReset() {
        mReader.read(0);
        while (mReader.hasNext()) {
            mReader.next();
        }
        mReader.reset();
        for (int i = 0; i < FULL_N; i++) {
            assertTrue(mReader.hasNext());
            LogMaker log = mReader.next();
            assertEquals(i, log.getCategory());
        }
    }

    public void testBlockingRead_readResetsHorizon() {
        mReader.read(1000);
        assertEquals(1000, mLogReader.mHorizonMs);
    }

    public void testWriteCheckpoint() {
        mReader.checkpoint();
        mReader.read(0);
        int m = FULL_N - CHECKPOINTED_N;
        for (int i = m; i < FULL_N; i++) {
            assertTrue(mReader.hasNext());
            LogMaker log = mReader.next();
            assertEquals(i, log.getCategory());
        }
    }
}
+3 −0
Original line number Diff line number Diff line
@@ -3777,6 +3777,9 @@ message MetricsEvent {
    // Package: Package of app that was autofilled
    AUTOFILL_SESSION_FINISHED = 919;

    // meta-event: a reader has checkpointed the log here.
    METRICS_CHECKPOINT = 920;

    // ---- End O Constants, all O constants go above this line ----

    // Add new aosp constants above this line.