android-10.0.0_r47/s

/*
 * Copyright (C) 2018 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.tradefed.result.proto;

import com.android.tradefed.build.IBuildInfo;
import com.android.tradefed.invoker.IInvocationContext;
import com.android.tradefed.invoker.InvocationContext;
import com.android.tradefed.invoker.proto.InvocationContext.Context;
import com.android.tradefed.log.LogUtil.CLog;
import com.android.tradefed.metrics.proto.MetricMeasurement.Metric;
import com.android.tradefed.result.FileInputStreamSource;
import com.android.tradefed.result.ILogSaverListener;
import com.android.tradefed.result.ITestInvocationListener;
import com.android.tradefed.result.InputStreamSource;
import com.android.tradefed.result.LogDataType;
import com.android.tradefed.result.LogFile;
import com.android.tradefed.result.TestDescription;
import com.android.tradefed.result.proto.LogFileProto.LogFileInfo;
import com.android.tradefed.result.proto.TestRecordProto.ChildReference;
import com.android.tradefed.result.proto.TestRecordProto.TestRecord;
import com.android.tradefed.testtype.suite.ModuleDefinition;

import com.google.common.base.Strings;
import com.google.protobuf.Any;
import com.google.protobuf.InvalidProtocolBufferException;
import com.google.protobuf.Timestamp;

import java.io.File;
import java.lang.reflect.InvocationTargetException;
import java.lang.reflect.Method;
import java.util.HashMap;
import java.util.List;
import java.util.Map.Entry;

/** Parser for the Tradefed results proto format. */
public class ProtoResultParser {

    private ITestInvocationListener mListener;
    private String mCurrentRunName = null;
    /**
     * We don't always want to report the invocation level events again. If we are within an
     * invocation scope we should not report it again.
     */
    private boolean mReportInvocation = false;
    /** Prefix that will be added to the files logged through the parser. */
    private String mFilePrefix;
    /** The context from the invocation in progress, not the proto one. */
    private IInvocationContext mMainContext;

    private boolean mQuietParsing = true;

    /** Ctor. */
    public ProtoResultParser(
            ITestInvocationListener listener,
            IInvocationContext context,
            boolean reportInvocation) {
        this(listener, context, reportInvocation, "subprocess-");
    }

    /** Ctor. */
    public ProtoResultParser(
            ITestInvocationListener listener,
            IInvocationContext context,
            boolean reportInvocation,
            String prefixForFile) {
        mListener = listener;
        mMainContext = context;
        mReportInvocation = reportInvocation;
        mFilePrefix = prefixForFile;
    }

    /** Enumeration representing the current level of the proto being processed. */
    public enum TestLevel {
        INVOCATION,
        MODULE,
        TEST_RUN,
        TEST_CASE
    }

    /** Sets whether or not to print when events are received. */
    public void setQuiet(boolean quiet) {
        mQuietParsing = quiet;
    }

    /**
     * Main entry function that takes the finalized completed proto and replay its results.
     *
     * @param finalProto The final {@link TestRecord} to be parsed.
     */
    public void processFinalizedProto(TestRecord finalProto) {
        if (!finalProto.getParentTestRecordId().isEmpty()) {
            throw new IllegalArgumentException("processFinalizedProto only expect a root proto.");
        }

        // Invocation Start
        handleInvocationStart(finalProto);

        evalProto(finalProto.getChildrenList(), false);
        // Invocation End
        handleInvocationEnded(finalProto);
    }

    /**
     * Main entry function where each proto is presented to get parsed into Tradefed events.
     *
     * @param currentProto The current {@link TestRecord} to be parsed.
     * @return True if the proto processed was a module.
     */
    public TestLevel processNewProto(TestRecord currentProto) {
        // Handle initial root proto
        if (currentProto.getParentTestRecordId().isEmpty()) {
            handleRootProto(currentProto);
            return TestLevel.INVOCATION;
        } else if (currentProto.hasDescription()) {
            // If it has a Any Description with Context then it's a module
            handleModuleProto(currentProto);
            return TestLevel.MODULE;
        } else if (mCurrentRunName == null
                || currentProto.getTestRecordId().equals(mCurrentRunName)) {
            // Need to track the parent test run id to make sure we need testRunEnd or testRunFail
            handleTestRun(currentProto);
            return TestLevel.TEST_RUN;
        } else {
            // Test cases handling
            handleTestCase(currentProto);
            return TestLevel.TEST_CASE;
        }
    }

    private void evalProto(List<ChildReference> children, boolean isInRun) {
        for (ChildReference child : children) {
            TestRecord childProto = child.getInlineTestRecord();
            if (isInRun) {
                // test case
                String[] info = childProto.getTestRecordId().split("#");
                TestDescription description = new TestDescription(info[0], info[1]);
                mListener.testStarted(description, timeStampToMillis(childProto.getStartTime()));
                handleTestCaseEnd(description, childProto);
            } else {
                boolean inRun = false;
                if (childProto.hasDescription()) {
                    // Module start
                    handleModuleStart(childProto);
                } else {
                    // run start
                    handleTestRunStart(childProto);
                    inRun = true;
                }
                evalProto(childProto.getChildrenList(), inRun);
                if (childProto.hasDescription()) {
                    // Module end
                    handleModuleProto(childProto);
                } else {
                    // run end
                    handleTestRunEnd(childProto);
                }
            }
        }
    }

    /** Handles the root of the invocation: They have no parent record id. */
    private void handleRootProto(TestRecord rootProto) {
        if (rootProto.hasEndTime()) {
            handleInvocationEnded(rootProto);
        } else {
            handleInvocationStart(rootProto);
        }
    }

    private void handleInvocationStart(TestRecord startInvocationProto) {
        // invocation starting
        Any anyDescription = startInvocationProto.getDescription();
        if (!anyDescription.is(Context.class)) {
            throw new RuntimeException("Expected Any description of type Context");
        }
        IInvocationContext receivedProto;
        try {
            receivedProto = InvocationContext.fromProto(anyDescription.unpack(Context.class));
        } catch (InvalidProtocolBufferException e) {
            throw new RuntimeException(e);
        }

        log("Invocation started proto");
        if (!mReportInvocation) {
            CLog.d("Skipping invocation start reporting.");
            return;
        }
        // Only report invocation start if enabled
        mListener.invocationStarted(receivedProto);
    }

    private void handleInvocationEnded(TestRecord endInvocationProto) {
        // Still report the logs even if not reporting the invocation level.
        handleLogs(endInvocationProto);

        // Get final context in case it changed.
        Any anyDescription = endInvocationProto.getDescription();
        if (!anyDescription.is(Context.class)) {
            throw new RuntimeException("Expected Any description of type Context");
        }
        try {
            IInvocationContext context =
                    InvocationContext.fromProto(anyDescription.unpack(Context.class));
            mergeInvocationContext(mMainContext, context);
        } catch (InvalidProtocolBufferException e) {
            throw new RuntimeException(e);
        }

        if (endInvocationProto.hasDebugInfo()) {
            // TODO: Re-interpret the exception with proper type.
            String trace = endInvocationProto.getDebugInfo().getTrace();
            mListener.invocationFailed(new Throwable(trace));
        }

        log("Invocation ended proto");
        if (!mReportInvocation) {
            CLog.d("Skipping invocation ended reporting.");
            return;
        }
        // Only report invocation ended if enabled
        long elapsedTime =
                timeStampToMillis(endInvocationProto.getEndTime())
                        - timeStampToMillis(endInvocationProto.getStartTime());
        mListener.invocationEnded(elapsedTime);
    }

    /** Handles module level of the invocation: They have a Description for the module context. */
    private void handleModuleProto(TestRecord moduleProto) {
        if (moduleProto.hasEndTime()) {
            handleModuleEnded(moduleProto);
        } else {
            handleModuleStart(moduleProto);
        }
    }

    private void handleModuleStart(TestRecord moduleProto) {
        Any anyDescription = moduleProto.getDescription();
        if (!anyDescription.is(Context.class)) {
            throw new RuntimeException("Expected Any description of type Context");
        }
        try {
            IInvocationContext moduleContext =
                    InvocationContext.fromProto(anyDescription.unpack(Context.class));
            String message = "Test module started proto";
            if (moduleContext.getAttributes().containsKey(ModuleDefinition.MODULE_ID)) {
                message +=
                        (": "
                                + moduleContext
                                        .getAttributes()
                                        .getUniqueMap()
                                        .get(ModuleDefinition.MODULE_ID));
            }
            log(message);
            mListener.testModuleStarted(moduleContext);
        } catch (InvalidProtocolBufferException e) {
            throw new RuntimeException(e);
        }
    }

    private void handleModuleEnded(TestRecord moduleProto) {
        handleLogs(moduleProto);
        log("Test module ended proto");
        mListener.testModuleEnded();
    }

    /** Handles the test run level of the invocation. */
    private void handleTestRun(TestRecord runProto) {
        // If the proto end-time is present we are evaluating the end of a test run.
        if (runProto.hasEndTime()) {
            handleTestRunEnd(runProto);
            mCurrentRunName = null;
        } else {
            // If the end-time is not populated yet we are dealing with the start of a run.
            mCurrentRunName = runProto.getTestRecordId();
            handleTestRunStart(runProto);
        }
    }

    private void handleTestRunStart(TestRecord runProto) {
        String id = runProto.getTestRecordId();
        log(
                "Test run started proto: %s. Expected tests: %s. Attempt: %s",
                id, runProto.getNumExpectedChildren(), runProto.getAttemptId());
        mListener.testRunStarted(
                id,
                (int) runProto.getNumExpectedChildren(),
                (int) runProto.getAttemptId(),
                timeStampToMillis(runProto.getStartTime()));
    }

    private void handleTestRunEnd(TestRecord runProto) {
        // If we find debugging information, the test run failed and we reflect it.
        if (runProto.hasDebugInfo()) {
            mListener.testRunFailed(runProto.getDebugInfo().getErrorMessage());
        }
        handleLogs(runProto);
        log("Test run ended proto: %s", runProto.getTestRecordId());
        long elapsedTime =
                timeStampToMillis(runProto.getEndTime())
                        - timeStampToMillis(runProto.getStartTime());
        HashMap<String, Metric> metrics = new HashMap<>(runProto.getMetrics());
        mListener.testRunEnded(elapsedTime, metrics);
    }

    /** Handles the test cases level of the invocation. */
    private void handleTestCase(TestRecord testcaseProto) {
        String[] info = testcaseProto.getTestRecordId().split("#");
        TestDescription description = new TestDescription(info[0], info[1]);
        if (testcaseProto.hasEndTime()) {
            handleTestCaseEnd(description, testcaseProto);
        } else {
            log("Test case started proto: %s", description.toString());
            mListener.testStarted(description, timeStampToMillis(testcaseProto.getStartTime()));
        }
    }

    private void handleTestCaseEnd(TestDescription description, TestRecord testcaseProto) {
        switch (testcaseProto.getStatus()) {
            case FAIL:
                mListener.testFailed(description, testcaseProto.getDebugInfo().getErrorMessage());
                log(
                        "Test case failed proto: %s - %s",
                        description.toString(), testcaseProto.getDebugInfo().getErrorMessage());
                break;
            case ASSUMPTION_FAILURE:
                mListener.testAssumptionFailure(
                        description, testcaseProto.getDebugInfo().getTrace());
                log(
                        "Test case assumption failure proto: %s - %s",
                        description.toString(), testcaseProto.getDebugInfo().getTrace());
                break;
            case IGNORED:
                mListener.testIgnored(description);
                log("Test case ignored proto: %s", description.toString());
                break;
            case PASS:
                break;
            default:
                throw new RuntimeException(
                        String.format(
                                "Received unexpected test status %s.", testcaseProto.getStatus()));
        }
        handleLogs(testcaseProto);
        HashMap<String, Metric> metrics = new HashMap<>(testcaseProto.getMetrics());
        log("Test case ended proto: %s", description.toString());
        mListener.testEnded(description, timeStampToMillis(testcaseProto.getEndTime()), metrics);
    }

    private long timeStampToMillis(Timestamp stamp) {
        return stamp.getSeconds() * 1000L + (stamp.getNanos() / 1000000L);
    }

    private void handleLogs(TestRecord proto) {
        if (!(mListener instanceof ILogSaverListener)) {
            return;
        }
        ILogSaverListener logger = (ILogSaverListener) mListener;
        for (Entry<String, Any> entry : proto.getArtifacts().entrySet()) {
            try {
                LogFileInfo info = entry.getValue().unpack(LogFileInfo.class);
                LogFile file =
                        new LogFile(
                                info.getPath(),
                                info.getUrl(),
                                info.getIsCompressed(),
                                LogDataType.valueOf(info.getLogType()),
                                info.getSize());
                if (file.getPath() == null) {
                    CLog.e("Log '%s' was registered but without a path.", entry.getKey());
                    return;
                }
                File path = new File(file.getPath());
                if (Strings.isNullOrEmpty(file.getUrl()) && path.exists()) {
                    try (InputStreamSource source = new FileInputStreamSource(path)) {
                        LogDataType type = file.getType();
                        // File might have already been compressed
                        if (file.getPath().endsWith(LogDataType.ZIP.getFileExt())) {
                            type = LogDataType.ZIP;
                        }
                        log("Logging %s from subprocess: %s ", entry.getKey(), file.getPath());
                        logger.testLog(mFilePrefix + entry.getKey(), type, source);
                    }
                } else {
                    log("Logging %s from subprocess: %s", entry.getKey(), file.getUrl());
                    logger.logAssociation(mFilePrefix + entry.getKey(), file);
                }
            } catch (InvalidProtocolBufferException e) {
                CLog.e("Couldn't unpack %s as a LogFileInfo", entry.getKey());
                CLog.e(e);
            }
        }
    }

    /**
     * Copy the build info and invocation attributes from the proto context to the current
     * invocation context
     *
     * @param receiverContext The context receiving the attributes
     * @param endInvocationContext The context providing the attributes
     */
    private void mergeInvocationContext(
            IInvocationContext receiverContext, IInvocationContext endInvocationContext) {
        if (receiverContext == null) {
            return;
        }
        // Gather attributes of build infos
        for (IBuildInfo info : receiverContext.getBuildInfos()) {
            String name = receiverContext.getBuildInfoName(info);
            IBuildInfo endInvocationInfo = endInvocationContext.getBuildInfo(name);
            if (endInvocationInfo == null) {
                CLog.e("No build info named: %s", name);
                continue;
            }
            info.addBuildAttributes(endInvocationInfo.getBuildAttributes());
        }

        try {
            Method unlock = InvocationContext.class.getDeclaredMethod("unlock");
            unlock.setAccessible(true);
            unlock.invoke(receiverContext);
            unlock.setAccessible(false);
        } catch (NoSuchMethodException
                | SecurityException
                | IllegalAccessException
                | IllegalArgumentException
                | InvocationTargetException e) {
            CLog.e("Couldn't unlock the main context. Skip copying attributes");
            return;
        }
        // Copy invocation attributes
        receiverContext.addInvocationAttributes(endInvocationContext.getAttributes());
    }

    private void log(String format, Object... obj) {
        if (!mQuietParsing) {
            CLog.d(format, obj);
        }
    }
}