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

Commit 0765882a authored by Pablo Gamito's avatar Pablo Gamito
Browse files

Ensure incremental state flag is set when using interned data 

The `SEQ_NEEDS_INCREMENTAL_STATE` flag was not being consistently set on trace packets for log messages containing interned data, such as string arguments or stack traces. This could lead to decoding errors when parsing the trace if there was an packet loss leading to the interned values being lost.

Test: atest TracingTests
Flag: EXEMPT minor change
Bug: 424792568
Change-Id: If6415fa15589bc19525e76c5dbfbacb04aff508a
parent 09eb061d

core/java/com/android/internal/protolog/PerfettoProtoLogImpl.java

+4 −2
Original line number Diff line number Diff line
@@ -613,6 +613,8 @@ public abstract class PerfettoProtoLogImpl extends IProtoLogClient.Stub implemen 
                return;

            }



            boolean needsIncrementalState = false;



            if (args != null) {

                // Intern all string params before creating the trace packet for the proto

                // message so that the interned strings appear before in the trace to make the
@@ -621,6 +623,7 @@ public abstract class PerfettoProtoLogImpl extends IProtoLogClient.Stub implemen 
                for (Object o : args) {

                    int type = LogDataType.bitmaskToLogDataType(message.getMessageMask(), argIndex);

                    if (type == LogDataType.STRING) {

                        needsIncrementalState = true;

                        if (o == null) {

                            internStringArg(ctx, NULL_STRING);

                        } else {
@@ -636,11 +639,10 @@ public abstract class PerfettoProtoLogImpl extends IProtoLogClient.Stub implemen 
                // 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.

                needsIncrementalState = true;

                internedStacktrace = internStacktraceString(ctx, stacktrace);

            }



            boolean needsIncrementalState = false;



            long messageHash = 0;

            if (message.mMessageHash != null) {

                messageHash = message.mMessageHash;

tests/Tracing/src/com/android/internal/protolog/ProcessedPerfettoProtoLogImplTest.java

+79 −0
Original line number Diff line number Diff line
@@ -31,11 +31,15 @@ import static org.mockito.Mockito.never; 
import static org.mockito.Mockito.verify;

import static org.mockito.Mockito.when;



import static perfetto.protos.TracePacketOuterClass.TracePacket.SequenceFlags.SEQ_NEEDS_INCREMENTAL_STATE;



import static java.io.File.createTempFile;



import android.os.SystemClock;

import android.platform.test.annotations.Presubmit;

import android.tools.ScenarioBuilder;

import android.tools.Tag;

import android.tools.io.TraceType;

import android.tools.traces.TraceConfig;

import android.tools.traces.TraceConfigs;

import android.tools.traces.io.ResultReader;
@@ -65,6 +69,7 @@ import org.mockito.stubbing.Answer; 


import perfetto.protos.Protolog;

import perfetto.protos.ProtologCommon;

import perfetto.protos.TraceOuterClass.Trace;



import java.io.File;

import java.io.IOException;
@@ -154,6 +159,13 @@ public class ProcessedPerfettoProtoLogImplTest { 
                                .setLevel(ProtologCommon.ProtoLogLevel.PROTOLOG_LEVEL_WTF)

                                .setGroupId(1)

                                .setLocation("com/test/MyTestClass.java:192")

                ).addMessages(

                        Protolog.ProtoLogViewerConfig.MessageData.newBuilder()

                                .setMessageId(6)

                                .setMessage("My Test String Arg Message %s")

                                .setLevel(ProtologCommon.ProtoLogLevel.PROTOLOG_LEVEL_DEBUG)

                                .setGroupId(1)

                                .setLocation("com/test/MyTestClass.java:193")

                );



        ViewerConfigInputStreamProvider viewerConfigInputStreamProvider = Mockito.mock(
@@ -1218,6 +1230,73 @@ public class ProcessedPerfettoProtoLogImplTest { 
                .isEqualTo(expectedLoggedMessage);

    }



    @Test

    public void incrementalStateFlagSetForStackTrace() throws IOException {

        PerfettoTraceMonitor traceMonitor = PerfettoTraceMonitor.newBuilder()

                .enableProtoLog(

                        true,

                        List.of(new PerfettoTraceMonitor.Builder.ProtoLogGroupOverride(

                                TestProtoLogGroup.TEST_GROUP.toString(), LogLevel.DEBUG,

                                true)), // enable stacktrace

                        TEST_PROTOLOG_DATASOURCE_NAME

                ).build();

        try {

            traceMonitor.start();



            // Log a message with a stacktrace but no string arguments. The stacktrace is the only

            // interned data.

            sProtoLog.log(LogLevel.DEBUG, TestProtoLogGroup.TEST_GROUP, 1,

                    LogDataType.BOOLEAN, new Object[]{true});

        } finally {

            traceMonitor.stop(mWriter);

        }



        final ResultReader reader = new ResultReader(mWriter.write(), mTraceConfig);

        final var traceBytes = reader.readBytes(TraceType.PERFETTO, Tag.ALL);

        final var trace = Trace.parseFrom(traceBytes);

        final var protoLogMessagePackets = trace.getPacketList().stream()

                .filter(it -> it.hasProtologMessage()

                        && it.getProtologMessage().getMessageId() == 1)

                .toList();



        Truth.assertThat(protoLogMessagePackets).hasSize(1);

        final var sequenceFlag = protoLogMessagePackets.getFirst().getSequenceFlags();

        final var incrementalStateFlag = SEQ_NEEDS_INCREMENTAL_STATE.getNumber();

        Truth.assertWithMessage("SEQ_NEEDS_INCREMENTAL_STATE flag should be set")

                .that(sequenceFlag & incrementalStateFlag).isEqualTo(incrementalStateFlag);

    }



    @Test

    public void incrementalStateFlagSetForStringArg() throws IOException {

        PerfettoTraceMonitor traceMonitor = PerfettoTraceMonitor.newBuilder()

                .enableProtoLog(true, List.of(), TEST_PROTOLOG_DATASOURCE_NAME)

                .build();

        try {

            traceMonitor.start();



            // Log a message with a string argument. The argument is the only

            // interned data.

            sProtoLog.log(LogLevel.DEBUG, TestProtoLogGroup.TEST_GROUP, 6,

                    LogDataType.STRING, new Object[]{"test_string"});

        } finally {

            traceMonitor.stop(mWriter);

        }



        final ResultReader reader = new ResultReader(mWriter.write(), mTraceConfig);

        final var traceBytes = reader.readBytes(TraceType.PERFETTO, Tag.ALL);

        final var trace = Trace.parseFrom(traceBytes);

        final var protoLogMessagePackets = trace.getPacketList().stream()

                .filter(it -> it.hasProtologMessage()

                        && it.getProtologMessage().getMessageId() == 6)

                .toList();



        Truth.assertThat(protoLogMessagePackets).hasSize(1);

        final var sequenceFlag = protoLogMessagePackets.getFirst().getSequenceFlags();

        final var incrementalStateFlag = SEQ_NEEDS_INCREMENTAL_STATE.getNumber();

        Truth.assertWithMessage("SEQ_NEEDS_INCREMENTAL_STATE flag should be set")

                .that(sequenceFlag & incrementalStateFlag).isEqualTo(incrementalStateFlag);

    }



    private enum TestProtoLogGroup implements IProtoLogGroup {

        TEST_GROUP(true, true, false, "TEST_TAG");

tests/Tracing/src/com/android/internal/protolog/UnprocessedPerfettoProtoLogImplTest.java

0 → 100644
+212 −0
Original line number Diff line number Diff line 
/*

 * Copyright (C) 2025 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 com.android.internal.protolog;



import static android.tools.traces.Utils.busyWaitForDataSourceRegistration;



import static perfetto.protos.TracePacketOuterClass.TracePacket.SequenceFlags.SEQ_NEEDS_INCREMENTAL_STATE;



import static java.io.File.createTempFile;



import android.tools.ScenarioBuilder;

import android.tools.Tag;

import android.tools.io.TraceType;

import android.tools.traces.TraceConfig;

import android.tools.traces.TraceConfigs;

import android.tools.traces.io.ResultReader;

import android.tools.traces.io.ResultWriter;

import android.tools.traces.monitors.PerfettoTraceMonitor;

import android.tracing.perfetto.DataSourceParams;



import androidx.test.platform.app.InstrumentationRegistry;



import com.android.internal.protolog.common.IProtoLogGroup;

import com.android.internal.protolog.common.LogLevel;



import com.google.common.truth.Truth;



import org.junit.After;

import org.junit.Before;

import org.junit.BeforeClass;

import org.junit.Test;



import perfetto.protos.TraceOuterClass.Trace;

import perfetto.protos.TracePacketOuterClass.TracePacket;



import java.io.File;

import java.io.IOException;

import java.util.List;



public class UnprocessedPerfettoProtoLogImplTest {

    private static final String TEST_PROTOLOG_DATASOURCE_NAME = "test.android.protolog.unprocessed";



    private final File mTracingDirectory = InstrumentationRegistry.getInstrumentation()

            .getTargetContext().getFilesDir();



    private final ResultWriter mWriter = new ResultWriter()

            .forScenario(new ScenarioBuilder()

                    .forClass(createTempFile("temp", "").getName()).build())

            .withOutputDir(mTracingDirectory)

            .setRunComplete();



    private final TraceConfigs mTraceConfig = new TraceConfigs(

            new TraceConfig(false, true, false),

            new TraceConfig(false, true, false),

            new TraceConfig(false, true, false),

            new TraceConfig(false, true, false)

    );



    private static ProtoLogDataSource sTestDataSource;

    private static UnprocessedPerfettoProtoLogImpl sProtoLog;



    public UnprocessedPerfettoProtoLogImplTest() throws IOException { }



    @BeforeClass

    public static void setUp() throws Exception {

        sTestDataSource = new ProtoLogDataSource(TEST_PROTOLOG_DATASOURCE_NAME);

        DataSourceParams params =

                new DataSourceParams.Builder()

                        .setBufferExhaustedPolicy(

                                DataSourceParams

                                        .PERFETTO_DS_BUFFER_EXHAUSTED_POLICY_DROP)

                        .build();

        sTestDataSource.register(params);

        busyWaitForDataSourceRegistration(TEST_PROTOLOG_DATASOURCE_NAME);



        sProtoLog = new UnprocessedPerfettoProtoLogImpl(sTestDataSource,

                TestProtoLogGroup.values());

        sProtoLog.enable();

    }



    @Before

    public void before() {

        TestProtoLogGroup.TEST_GROUP.setLogToLogcat(false);

        TestProtoLogGroup.TEST_GROUP.setLogToProto(false);

    }



    @After

    public void tearDown() {

        ProtoLogImpl.setSingleInstance(null);

    }



    @Test

    public void incrementalStateFlagSetForUnprocessedMessage() throws IOException {

        PerfettoTraceMonitor traceMonitor = PerfettoTraceMonitor.newBuilder()

                .enableProtoLog(true, List.of(), TEST_PROTOLOG_DATASOURCE_NAME)

                .build();

        try {

            traceMonitor.start();



            // Log a message with a string format. The message format string is the only

            // interned data.

            sProtoLog.log(LogLevel.DEBUG, TestProtoLogGroup.TEST_GROUP,

                    "My Unprocessed Message");

        } finally {

            traceMonitor.stop(mWriter);

        }



        final ResultReader reader = new ResultReader(mWriter.write(), mTraceConfig);

        final var traceBytes = reader.readBytes(TraceType.PERFETTO, Tag.ALL);

        final var trace = Trace.parseFrom(traceBytes);



        final var targetViewerConfigs = trace.getPacketList().stream()

                .filter(TracePacket::hasProtologViewerConfig)

                .map(TracePacket::getProtologViewerConfig)

                .filter(config ->

                        config.getMessagesList().stream()

                                .anyMatch(messageConfig ->

                                        messageConfig.getGroupId()

                                                == TestProtoLogGroup.TEST_GROUP.getId()

                                ) && config.getMessagesCount() == 1

                )

                .toList();



        Truth.assertThat(targetViewerConfigs).hasSize(1);

        final var targetViewerConfig = targetViewerConfigs.getFirst();

        Truth.assertThat(targetViewerConfig.getMessagesList()).hasSize(1);

        final var targetMessageId = targetViewerConfig.getMessages(0).getMessageId();



        final var targetProtoLogMessagePackets = trace.getPacketList().stream()

                .filter(TracePacket::hasProtologMessage)

                .filter(packet -> packet.getProtologMessage().getMessageId()

                        == targetMessageId)

                .toList();



        Truth.assertThat(targetProtoLogMessagePackets).hasSize(1);

        final var targetProtoLogMessagePacket = targetProtoLogMessagePackets.getFirst();

        Truth.assertWithMessage("SEQ_NEEDS_INCREMENTAL_STATE flag should be set")

                .that(targetProtoLogMessagePacket.getSequenceFlags()

                        & SEQ_NEEDS_INCREMENTAL_STATE.getNumber())

                .isEqualTo(SEQ_NEEDS_INCREMENTAL_STATE.getNumber());

    }



    private enum TestProtoLogGroup implements IProtoLogGroup {

        TEST_GROUP(true, true, false, "TEST_TAG");



        private final boolean mEnabled;

        private volatile boolean mLogToProto;

        private volatile boolean mLogToLogcat;

        private final String mTag;



        TestProtoLogGroup(boolean enabled, boolean logToProto, boolean logToLogcat, String tag) {

            this.mEnabled = enabled;

            this.mLogToProto = logToProto;

            this.mLogToLogcat = logToLogcat;

            this.mTag = tag;

        }



        @Override

        public boolean isEnabled() {

            return mEnabled;

        }



        @Override

        public boolean isLogToProto() {

            return mLogToProto;

        }



        @Override

        public boolean isLogToLogcat() {

            return mLogToLogcat;

        }



        @Override

        public boolean isLogToAny() {

            return mLogToLogcat || mLogToProto;

        }



        @Override

        public String getTag() {

            return mTag;

        }



        @Override

        public void setLogToProto(boolean logToProto) {

            this.mLogToProto = logToProto;

        }



        @Override

        public void setLogToLogcat(boolean logToLogcat) {

            this.mLogToLogcat = logToLogcat;

        }



        @Override

        public int getId() {

            return ordinal();

        }

    }

}