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

Commit 6c8490e7 authored by Pablo Gamito's avatar Pablo Gamito
Browse files

Add support for ProtoLogging without any source code pre-processing

Instead just setup the ProtoLogImpl instance in the process's initialization code.

Flag: android.tracing.perfetto_protolog_tracing
Test: atest com.android.internal.protolog.PerfettoProtoLogImplTest
Change-Id: Ie27f0ce8dfeb91374d00581fbf969afa0f370818
parent 97374985
Loading
Loading
Loading
Loading
+7 −0
Original line number Diff line number Diff line
@@ -106,6 +106,13 @@ public class LegacyProtoLogImpl implements IProtoLog {
        }
    }

    @Override
    public void log(LogLevel logLevel, IProtoLogGroup group, String messageString, Object... args) {
        // This will be removed very soon so no point implementing it here.
        throw new IllegalStateException(
                "Not implemented. Only implemented for PerfettoProtoLogImpl.");
    }

    private void logToLogcat(String tag, LogLevel level, long messageHash,
            @Nullable String messageString, Object[] args) {
        String message = null;
+152 −15
Original line number Diff line number Diff line
@@ -72,12 +72,17 @@ import java.io.IOException;
import java.io.PrintWriter;
import java.io.StringWriter;
import java.util.ArrayList;
import java.util.Arrays;
import java.util.List;
import java.util.Map;
import java.util.Optional;
import java.util.Set;
import java.util.TreeMap;
import java.util.UUID;
import java.util.concurrent.ExecutorService;
import java.util.concurrent.Executors;
import java.util.concurrent.atomic.AtomicInteger;
import java.util.stream.Collectors;

/**
 * A service for the ProtoLog logging system.
@@ -113,6 +118,21 @@ public class PerfettoProtoLogImpl implements IProtoLog {
        }, logGroups, cacheUpdater);
    }

    public PerfettoProtoLogImpl(IProtoLogGroup[] logGroups) {
        this(null, logGroups, () -> {});
    }

    public PerfettoProtoLogImpl(
            ViewerConfigInputStreamProvider viewerConfigInputStreamProvider,
            IProtoLogGroup[] logGroups,
            Runnable cacheUpdater
    ) {
        this(viewerConfigInputStreamProvider,
                new TreeMap<>(Arrays.stream(logGroups)
                        .collect(Collectors.toMap(IProtoLogGroup::name, group -> group))),
                cacheUpdater);
    }

    public PerfettoProtoLogImpl(
            ViewerConfigInputStreamProvider viewerConfigInputStreamProvider,
            TreeMap<String, IProtoLogGroup> logGroups,
@@ -153,10 +173,12 @@ public class PerfettoProtoLogImpl implements IProtoLog {
            @Nullable String messageString, Object[] args) {
        Trace.traceBegin(Trace.TRACE_TAG_WINDOW_MANAGER, "log");

        long tsNanos = SystemClock.elapsedRealtimeNanos();
        try {
            mBackgroundLoggingService.submit(() ->
                    logToProto(level, group.name(), messageHash, paramsMask, args, tsNanos));
            if (isProtoEnabled()) {
                long tsNanos = SystemClock.elapsedRealtimeNanos();
                mBackgroundLoggingService.execute(() ->
                        logToProto(level, group, messageHash, paramsMask, args, tsNanos));
            }
            if (group.isLogToLogcat()) {
                logToLogcat(group.getTag(), level, messageHash, messageString, args);
            }
@@ -165,6 +187,25 @@ public class PerfettoProtoLogImpl implements IProtoLog {
        }
    }

    @Override
    public void log(LogLevel logLevel, IProtoLogGroup group, String messageString, Object... args) {
        Trace.traceBegin(Trace.TRACE_TAG_WINDOW_MANAGER, "log");

        try {
            if (isProtoEnabled()) {
                long tsNanos = SystemClock.elapsedRealtimeNanos();
                mBackgroundLoggingService.execute(
                        () -> logStringMessageToProto(logLevel, group, messageString, args,
                                tsNanos));
            }
            if (group.isLogToLogcat()) {
                logToLogcat(group.getTag(), logLevel, 0, messageString, args);
            }
        } finally {
            Trace.traceEnd(Trace.TRACE_TAG_WINDOW_MANAGER);
        }
    }

    private void dumpTransitionTraceConfig() {
        ProtoInputStream pis = mViewerConfigInputStreamProvider.getInputStream();

@@ -320,25 +361,53 @@ public class PerfettoProtoLogImpl implements IProtoLog {
        }
    }

    private void logToProto(LogLevel level, String groupName, long messageHash, int paramsMask,
            Object[] args, long tsNanos) {
        if (!isProtoEnabled()) {
            return;
    private void logToProto(LogLevel level, IProtoLogGroup logGroup, long messageHash,
            int paramsMask, Object[] args, long tsNanos) {
        Trace.traceBegin(Trace.TRACE_TAG_WINDOW_MANAGER, "logToProto");
        try {
            doLogToProto(level, logGroup, new Message(messageHash), paramsMask, args, tsNanos);
        } finally {
            Trace.traceEnd(Trace.TRACE_TAG_WINDOW_MANAGER);
        }
    }

        Trace.traceBegin(Trace.TRACE_TAG_WINDOW_MANAGER, "logToProto");
    private void logStringMessageToProto(LogLevel logLevel, IProtoLogGroup group,
            String messageString, Object[] args, long tsNanos) {
        Trace.traceBegin(Trace.TRACE_TAG_WINDOW_MANAGER, "logStringMessageToProto");
        try {
            doLogToProto(level, groupName, messageHash, paramsMask, args, tsNanos);
            doLogToProto(logLevel, group, messageString, args, tsNanos);
        } finally {
            Trace.traceEnd(Trace.TRACE_TAG_WINDOW_MANAGER);
        }
    }

    private void doLogToProto(LogLevel level, String groupName, long messageHash, int paramsMask,
    private void doLogToProto(LogLevel level, IProtoLogGroup logGroup, String messageString,
            Object[] args, long tsNanos) {
        final List<Integer> argTypes = LogDataType.parseFormatString(messageString);
        final int typeMask = LogDataType.logDataTypesToBitMask(argTypes);
        doLogToProto(level, logGroup, new Message(messageString), typeMask, args, tsNanos);
    }

    private static class Message {
        private final Optional<Long> mMessageHash;
        private final Optional<String> mMessageString;

        private Message(Long messageHash) {
            this.mMessageHash = Optional.of(messageHash);
            this.mMessageString = Optional.empty();
        }

        private Message(String messageString) {
            this.mMessageHash = Optional.empty();
            this.mMessageString = Optional.of(messageString);
        }
    }

    private void doLogToProto(LogLevel level, IProtoLogGroup logGroup, Message message,
            int paramsMask, Object[] args, long tsNanos) {
        mDataSource.trace(ctx -> {
            final ProtoLogDataSource.TlsState tlsState = ctx.getCustomTlsState();
            final LogLevel logFrom = tlsState.getLogFromLevel(groupName);
            final LogLevel logFrom = tlsState.getLogFromLevel(logGroup.name());

            if (level.ordinal() < logFrom.ordinal()) {
                return;
@@ -359,7 +428,7 @@ public class PerfettoProtoLogImpl implements IProtoLog {
            }

            int internedStacktrace = 0;
            if (tlsState.getShouldCollectStacktrace(groupName)) {
            if (tlsState.getShouldCollectStacktrace(logGroup.name())) {
                // Intern stackstraces before creating the trace packet for the proto message so
                // that the interned stacktrace strings appear before in the trace to make the
                // trace processing easier.
@@ -367,12 +436,23 @@ public class PerfettoProtoLogImpl implements IProtoLog {
                internedStacktrace = internStacktraceString(ctx, stacktrace);
            }

            boolean needsIncrementalState = false;

            long messageHash = 0;
            if (message.mMessageHash.isPresent()) {
                messageHash = message.mMessageHash.get();
            }
            if (message.mMessageString.isPresent()) {
                needsIncrementalState = true;
                messageHash =
                        internProtoMessage(ctx, level, logGroup, message.mMessageString.get());
            }

            final ProtoOutputStream os = ctx.newTracePacket();
            os.write(TIMESTAMP, tsNanos);
            long token = os.start(PROTOLOG_MESSAGE);
            os.write(MESSAGE_ID, messageHash);

            boolean needsIncrementalState = false;
            os.write(MESSAGE_ID, messageHash);

            if (args != null) {

@@ -414,7 +494,7 @@ public class PerfettoProtoLogImpl implements IProtoLog {
                booleanParams.forEach(it -> os.write(BOOLEAN_PARAMS, it ? 1 : 0));
            }

            if (tlsState.getShouldCollectStacktrace(groupName)) {
            if (tlsState.getShouldCollectStacktrace(logGroup.name())) {
                os.write(STACKTRACE_IID, internedStacktrace);
            }

@@ -427,6 +507,63 @@ public class PerfettoProtoLogImpl implements IProtoLog {
        });
    }

    private long internProtoMessage(
            TracingContext<ProtoLogDataSource.Instance, ProtoLogDataSource.TlsState,
                    ProtoLogDataSource.IncrementalState> ctx, LogLevel level,
            IProtoLogGroup logGroup, String message) {
        final ProtoLogDataSource.IncrementalState incrementalState = ctx.getIncrementalState();

        if (!incrementalState.clearReported) {
            final ProtoOutputStream os = ctx.newTracePacket();
            os.write(SEQUENCE_FLAGS, SEQ_INCREMENTAL_STATE_CLEARED);
            incrementalState.clearReported = true;
        }


        if (!incrementalState.protologGroupInterningSet.contains(logGroup.getId())) {
            incrementalState.protologGroupInterningSet.add(logGroup.getId());

            final ProtoOutputStream os = ctx.newTracePacket();
            final long protologViewerConfigToken = os.start(PROTOLOG_VIEWER_CONFIG);
            final long groupConfigToken = os.start(GROUPS);

            os.write(ID, logGroup.getId());
            os.write(NAME, logGroup.name());
            os.write(TAG, logGroup.getTag());

            os.end(groupConfigToken);
            os.end(protologViewerConfigToken);
        }

        final Long messageHash = hash(level, logGroup.name(), message);
        if (!incrementalState.protologMessageInterningSet.contains(messageHash)) {
            incrementalState.protologMessageInterningSet.add(messageHash);

            final ProtoOutputStream os = ctx.newTracePacket();
            final long protologViewerConfigToken = os.start(PROTOLOG_VIEWER_CONFIG);
            final long messageConfigToken = os.start(MESSAGES);

            os.write(MessageData.MESSAGE_ID, messageHash);
            os.write(MESSAGE, message);
            os.write(LEVEL, level.ordinal());
            os.write(GROUP_ID, logGroup.getId());

            os.end(messageConfigToken);
            os.end(protologViewerConfigToken);
        }

        return messageHash;
    }

    private Long hash(
            LogLevel logLevel,
            String logGroup,
            String messageString
    ) {
        final String fullStringIdentifier =  messageString + logLevel + logGroup;
        return UUID.nameUUIDFromBytes(fullStringIdentifier.getBytes()).getMostSignificantBits();
    }

    private static final int STACK_SIZE_TO_PROTO_LOG_ENTRY_CALL = 12;

    private String collectStackTrace() {
+50 −39
Original line number Diff line number Diff line
@@ -44,21 +44,23 @@ public class ProtoLog {
// LINT.ThenChange(frameworks/base/tools/protologtool/src/com/android/protolog/tool/ProtoLogTool.kt)

    // Needs to be set directly otherwise the protologtool tries to transform the method call
    @Deprecated
    public static boolean REQUIRE_PROTOLOGTOOL = true;

    private static IProtoLog sProtoLogInstance;

    /**
     * DEBUG level log.
     *
     * @param group         {@code IProtoLogGroup} controlling this log call.
     * @param messageString constant format string for the logged message.
     * @param args          parameters to be used with the format string.
     *
     * NOTE: If source code is pre-processed by ProtoLogTool this is not the function call that is
     *       executed. Check generated code for actual call.
     */
    public static void d(IProtoLogGroup group, String messageString, Object... args) {
        // Stub, replaced by the ProtoLogTool.
        if (REQUIRE_PROTOLOGTOOL) {
            throw new UnsupportedOperationException(
                    "ProtoLog calls MUST be processed with ProtoLogTool");
        }
        logStringMessage(LogLevel.DEBUG, group, messageString, args);
    }

    /**
@@ -67,13 +69,12 @@ public class ProtoLog {
     * @param group         {@code IProtoLogGroup} controlling this log call.
     * @param messageString constant format string for the logged message.
     * @param args          parameters to be used with the format string.
     *
     * NOTE: If source code is pre-processed by ProtoLogTool this is not the function call that is
     *       executed. Check generated code for actual call.
     */
    public static void v(IProtoLogGroup group, String messageString, Object... args) {
        // Stub, replaced by the ProtoLogTool.
        if (REQUIRE_PROTOLOGTOOL) {
            throw new UnsupportedOperationException(
                    "ProtoLog calls MUST be processed with ProtoLogTool");
        }
        logStringMessage(LogLevel.VERBOSE, group, messageString, args);
    }

    /**
@@ -82,13 +83,12 @@ public class ProtoLog {
     * @param group         {@code IProtoLogGroup} controlling this log call.
     * @param messageString constant format string for the logged message.
     * @param args          parameters to be used with the format string.
     *
     * NOTE: If source code is pre-processed by ProtoLogTool this is not the function call that is
     *       executed. Check generated code for actual call.
     */
    public static void i(IProtoLogGroup group, String messageString, Object... args) {
        // Stub, replaced by the ProtoLogTool.
        if (REQUIRE_PROTOLOGTOOL) {
            throw new UnsupportedOperationException(
                    "ProtoLog calls MUST be processed with ProtoLogTool");
        }
        logStringMessage(LogLevel.INFO, group, messageString, args);
    }

    /**
@@ -97,13 +97,12 @@ public class ProtoLog {
     * @param group         {@code IProtoLogGroup} controlling this log call.
     * @param messageString constant format string for the logged message.
     * @param args          parameters to be used with the format string.
     *
     * NOTE: If source code is pre-processed by ProtoLogTool this is not the function call that is
     *       executed. Check generated code for actual call.
     */
    public static void w(IProtoLogGroup group, String messageString, Object... args) {
        // Stub, replaced by the ProtoLogTool.
        if (REQUIRE_PROTOLOGTOOL) {
            throw new UnsupportedOperationException(
                    "ProtoLog calls MUST be processed with ProtoLogTool");
        }
        logStringMessage(LogLevel.WARN, group, messageString, args);
    }

    /**
@@ -112,13 +111,12 @@ public class ProtoLog {
     * @param group         {@code IProtoLogGroup} controlling this log call.
     * @param messageString constant format string for the logged message.
     * @param args          parameters to be used with the format string.
     *
     * NOTE: If source code is pre-processed by ProtoLogTool this is not the function call that is
     *       executed. Check generated code for actual call.
     */
    public static void e(IProtoLogGroup group, String messageString, Object... args) {
        // Stub, replaced by the ProtoLogTool.
        if (REQUIRE_PROTOLOGTOOL) {
            throw new UnsupportedOperationException(
                    "ProtoLog calls MUST be processed with ProtoLogTool");
        }
        logStringMessage(LogLevel.ERROR, group, messageString, args);
    }

    /**
@@ -127,13 +125,12 @@ public class ProtoLog {
     * @param group         {@code IProtoLogGroup} controlling this log call.
     * @param messageString constant format string for the logged message.
     * @param args          parameters to be used with the format string.
     *
     * NOTE: If source code is pre-processed by ProtoLogTool this is not the function call that is
     *       executed. Check generated code for actual call.
     */
    public static void wtf(IProtoLogGroup group, String messageString, Object... args) {
        // Stub, replaced by the ProtoLogTool.
        if (REQUIRE_PROTOLOGTOOL) {
            throw new UnsupportedOperationException(
                    "ProtoLog calls MUST be processed with ProtoLogTool");
        }
        logStringMessage(LogLevel.WTF, group, messageString, args);
    }

    /**
@@ -142,11 +139,7 @@ public class ProtoLog {
     * @return true iff this is being logged.
     */
    public static boolean isEnabled(IProtoLogGroup group, LogLevel level) {
        if (REQUIRE_PROTOLOGTOOL) {
            throw new UnsupportedOperationException(
                    "ProtoLog calls MUST be processed with ProtoLogTool");
        }
        return false;
        return sProtoLogInstance.isEnabled(group, level);
    }

    /**
@@ -154,10 +147,28 @@ public class ProtoLog {
     * @return A singleton instance of ProtoLog.
     */
    public static IProtoLog getSingleInstance() {
        if (REQUIRE_PROTOLOGTOOL) {
            throw new UnsupportedOperationException(
                    "ProtoLog calls MUST be processed with ProtoLogTool");
        return sProtoLogInstance;
    }

    /**
     * Should be called once for each process that wants to use ProtoLog
     */
    public static synchronized void initialize(IProtoLog protoLogInstance) {
        if (sProtoLogInstance != null) {
            throw new IllegalStateException("ProtoLog already initialized in this process");
        }
        sProtoLogInstance = protoLogInstance;
    }

    private static void logStringMessage(LogLevel logLevel, IProtoLogGroup group,
            String stringMessage, Object... args) {
        if (sProtoLogInstance == null) {
            throw new IllegalStateException(
                    "Trying to use ProtoLog before it is initialized in this process.");
        }

        if (sProtoLogInstance.isEnabled(group, logLevel)) {
            sProtoLogInstance.log(logLevel, group, stringMessage, args);
        }
        return null;
    }
}
+3 −0
Original line number Diff line number Diff line
@@ -40,6 +40,7 @@ import com.android.internal.protolog.common.LogLevel;

import java.io.IOException;
import java.util.HashMap;
import java.util.HashSet;
import java.util.Map;
import java.util.Set;
import java.util.function.Consumer;
@@ -138,6 +139,8 @@ public class ProtoLogDataSource extends DataSource<ProtoLogDataSource.Instance,
    }

    public static class IncrementalState {
        public final Set<Integer> protologGroupInterningSet = new HashSet<>();
        public final Set<Long> protologMessageInterningSet = new HashSet<>();
        public final Map<String, Integer> argumentInterningMap = new HashMap<>();
        public final Map<String, Integer> stacktraceInterningMap = new HashMap<>();
        public boolean clearReported = false;
+9 −0
Original line number Diff line number Diff line
@@ -33,6 +33,15 @@ public interface IProtoLog {
    void log(LogLevel logLevel, IProtoLogGroup group, long messageHash, int paramsMask,
             String messageString, Object[] args);

    /**
     * Log a ProtoLog message
     * @param logLevel Log level of the proto message.
     * @param group The group this message belongs to.
     * @param messageString The message string.
     * @param args The arguments of the message.
     */
    void log(LogLevel logLevel, IProtoLogGroup group, String messageString, Object... args);

    /**
     * Check if ProtoLog is tracing.
     * @return true iff a ProtoLog tracing session is active.
Loading