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

Commit 8caccfbc authored by Mohamad Mahmoud's avatar Mohamad Mahmoud
Browse files

Refactor logcat collection in ActivityManagerService

- Fixed inconsistent log truncation between GMS and ActivityManager by
  respecting Dropbox max file size
- Moved logcat fetching logic out of AMS, to a dedicated `LogcatFetcher` class.
- Replaced AMS logcat retrieval with `LogcatFetcher.appendLogcatLogs()`.
- Improved logcat collection by adding a timestamp and considering dropbox size to limit logs in dropbox error entries.

Flag: com.android.server.am.limit_logcat_collection
Bug: 354138103
Test: atest FrameworksServicesTests:LogcatFetcherTest && manual testing
Change-Id: I720202c31a38a20e4d7eaf30b5f80ecdfcb4bf0f
parent 1b8815ba
Loading
Loading
Loading
Loading
+26 −16
Original line number Diff line number Diff line
@@ -164,6 +164,8 @@ import static com.android.server.am.ActivityManagerDebugConfig.POSTFIX_SERVICE;
import static com.android.server.am.ActivityManagerDebugConfig.POSTFIX_UID_OBSERVERS;
import static com.android.server.am.ActivityManagerDebugConfig.TAG_AM;
import static com.android.server.am.ActivityManagerDebugConfig.TAG_WITH_CLASS_NAME;
import static com.android.server.am.LogcatFetcher.LOGCAT_TIMEOUT_SEC;
import static com.android.server.am.LogcatFetcher.RESERVED_BYTES_PER_LOGCAT_LINE;
import static com.android.server.am.MemoryStatUtil.hasMemcg;
import static com.android.server.am.ProcessList.ProcStartHandler;
import static com.android.server.flags.Flags.disableSystemCompaction;
@@ -587,12 +589,6 @@ public class ActivityManagerService extends IActivityManager.Stub
    // How many bytes to write into the dropbox log before truncating
    static final int DROPBOX_DEFAULT_MAX_SIZE = 192 * 1024;
    // Assumes logcat entries average around 100 bytes; that's not perfect stack traces count
    // as one line, but close enough for now.
    static final int RESERVED_BYTES_PER_LOGCAT_LINE = 100;
    // How many seconds should the system wait before terminating the spawned logcat process.
    static final int LOGCAT_TIMEOUT_SEC = Flags.logcatLongerTimeout() ? 15 : 10;
    // Necessary ApplicationInfo flags to mark an app as persistent
    static final int PERSISTENT_MASK =
@@ -9839,9 +9835,17 @@ public class ActivityManagerService extends IActivityManager.Stub
                sb.append("Process-Runtime: ").append(runtimeMillis).append("\n");
            }
        }
        final Instant errorTimestamp;
        if (volatileStates != null && volatileStates.getTimestamp() != null) {
            errorTimestamp = volatileStates.getTimestamp().toInstant();
        } else {
            errorTimestamp = Instant.now();
        }
        if (eventType.equals("crash")) {
            String formattedTime = DROPBOX_TIME_FORMATTER.format(
                    Instant.now().atZone(ZoneId.systemDefault()));
                    errorTimestamp.atZone(ZoneId.systemDefault()));
            sb.append("Timestamp: ").append(formattedTime).append("\n");
        }
        if (activityShortComponentName != null) {
@@ -9927,8 +9931,7 @@ public class ActivityManagerService extends IActivityManager.Stub
                    int maxDataFileSize = dropboxMaxSize
                            - sb.length()
                            - logcatLines * RESERVED_BYTES_PER_LOGCAT_LINE
                            - kernelLogLines * RESERVED_BYTES_PER_LOGCAT_LINE
                            - (logcatLines + kernelLogLines) * RESERVED_BYTES_PER_LOGCAT_LINE
                            - DATA_FILE_PATH_FOOTER.length();
                    if (maxDataFileSize > 0) {
@@ -9948,10 +9951,16 @@ public class ActivityManagerService extends IActivityManager.Stub
                if (crashInfo != null && crashInfo.stackTrace != null) {
                    sb.append(crashInfo.stackTrace);
                }
                boolean shouldAddLogs = (logcatLines > 0 || kernelLogLines > 0)
                        && (Flags.collectLogcatOnRunSynchronously() || !runSynchronously);
                if (shouldAddLogs) {
                    sb.append("\n");
                    if (Flags.limitLogcatCollection()) {
                        LogcatFetcher.appendLogcatLogs(sb, dropboxMaxSize -  sb.length(),
                                errorTimestamp, logcatLines, kernelLogLines);
                    } else {
                        if (logcatLines > 0) {
                            fetchLogcatBuffers(sb, logcatLines, LOGCAT_TIMEOUT_SEC,
                                    List.of("events", "system", "main", "crash"));
@@ -9961,6 +9970,7 @@ public class ActivityManagerService extends IActivityManager.Stub
                                    List.of("kernel"));
                        }
                    }
                }
                dbox.addText(dropboxTag, sb.toString());
            }
+222 −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.server.am;

import static com.android.server.am.ActivityManagerDebugConfig.TAG_WITH_CLASS_NAME;
import static com.android.server.am.ActivityManagerDebugConfig.TAG_AM;

import android.util.Slog;

import com.android.internal.annotations.VisibleForTesting;

import java.io.BufferedReader;
import java.io.IOException;
import java.io.InputStreamReader;
import java.time.Instant;
import java.time.ZoneOffset;
import java.time.format.DateTimeFormatter;
import java.util.ArrayList;
import java.util.Collections;
import java.util.List;
import java.util.stream.Stream;

final class LogcatFetcher {

    static final String TAG = TAG_WITH_CLASS_NAME ? "LogcatFetcher" : TAG_AM;

    // Assumes logcat entries average around 100 bytes; that's not perfect stack traces count
    // as one line, but close enough for now.
    static final int RESERVED_BYTES_PER_LOGCAT_LINE = 100;

    // How many seconds should the system wait before terminating the spawned logcat process.
    static final int LOGCAT_TIMEOUT_SEC = Flags.logcatLongerTimeout() ? 15 : 10;

    // The minimum allowed size for calling logcat, accounting for a reserved line and a header.
    private static final int MIN_LOGCAT_FILE_SIZE = 2 * RESERVED_BYTES_PER_LOGCAT_LINE;

    // The divisor used for the aggregated logs
    private static final String LOGCAT_AGGREGATED_DIVISOR = "--------- beginning of logcat";

    // The divisor prefix used to identify logcat divisors
    private static final String LOGCAT_DIVISOR_PREFIX = "---------";

    // List of logcat buffers to fetch from the Android system logs
    private static final List<String> CORE_BUFFERS =
            List.of("events", "system", "main", "crash");

    // List of full log buffers to fetch system kernel logs
    private static final List<String> ALL_BUFFERS =
            Stream.concat(CORE_BUFFERS.stream(), Stream.of("kernel")).toList();

    // Date formatter that is consistent with logcat's format
    private static final DateTimeFormatter LOGCAT_FORMATTER = DateTimeFormatter
            .ofPattern("MM-dd HH:mm:ss.SSS")
            .withZone(ZoneOffset.UTC);

    // Maximum number of log lines allowed to prevent potential OOM issues.
    private static final int MAX_ALLOWED_CORE_LOG_LINES = 8_000;

    /**
     * Retrieves and appends logcat output from certain buffers into the StringBuilder,
     * respecting a maximum buffer size and a timestamp. First, It first attempts to
     * include general logs, then kernel logs if space remains.
     *
     * @param sb             The StringBuilder where logs will be appended.
     * @param maxBufferSize  Maximum buffer size in characters.
     * @param maxTimestamp      The latest allowed log timestamp to include.
     * @param logcatLines    Number of logcat lines to fetch.
     * @param kernelLogLines Number of kernel log lines to fetch.
     */
    public static void appendLogcatLogs(StringBuilder sb, int maxBufferSize, Instant maxTimestamp,
            int logcatLines, int kernelLogLines) {

        String formattedTimestamp = LOGCAT_FORMATTER.format(maxTimestamp);
        int lines = Math.min(logcatLines + kernelLogLines, MAX_ALLOWED_CORE_LOG_LINES);
        // Check if we can at least include two lines (a header and a log line), otherwise,
        // we shouldn't call logcat
        if (lines > 0 && maxBufferSize >= MIN_LOGCAT_FILE_SIZE) {
            List<String> logs = fetchLogcatBuffers(lines, LOGCAT_TIMEOUT_SEC, formattedTimestamp,
                    kernelLogLines > 0  ? ALL_BUFFERS : CORE_BUFFERS);
            trimAndAppendLogs(sb, logs, maxBufferSize);
        }
    }

    /**
     * Fetches logcat logs from the specified buffers and returns them as a list of strings.
     *
     * @param lines   Number of lines to retrieve.
     * @param timeout Maximum time allowed for logcat to run (in seconds).
     * @param timestampUtc The latest allowed log timestamp to include, as a formatted string.
     * @param buffers List of log buffers to retrieve logs from.
     * @return A list of logcat output lines.
     */
    private static List<String> fetchLogcatBuffers(int lines, int timeout, String timestampUtc,
            List<String> buffers) {
        if (buffers.isEmpty() || lines <= 0 || timeout <= 0) {
            return Collections.emptyList();
        }
        List<String> result = new ArrayList<>(lines);
        List<String> command = new ArrayList<>(10 + (2 * buffers.size()));
        // Time out after 10s of inactivity, but kill logcat with ABRT
        // so we can investigate why it didn't finish.
        command.add("/system/bin/timeout");
        command.add("-i");
        command.add("-s");
        command.add("ABRT");
        command.add(timeout + "s");

        // Merge several logcat streams, and take the last N lines.
        command.add("/system/bin/logcat");
        command.add("-v");
        // This adds a timestamp and thread info to each log line.
        // Also change the timestamps to use UTC time.
        command.add("threadtime,UTC");
        for (String buffer : buffers) {
            command.add("-b");
            command.add(buffer);
        }
        // Limit the output to the last N lines.
        command.add("-t");
        command.add(String.valueOf(lines));
        try {
            java.lang.Process proc =
                    new ProcessBuilder(command).redirectErrorStream(true).start();

            // Close the output stream immediately as we do not send input to the process.
            try {
                proc.getOutputStream().close();
            } catch (IOException e) {
            }
            // Read all lines from the child process
            try (BufferedReader reader =
                        new BufferedReader(new InputStreamReader(proc.getInputStream()), 8192)) {
                String line;
                while ((line = reader.readLine()) != null
                        // Only include logs up to the provided timestamp
                        && extractLogTimestamp(line).compareTo(timestampUtc) <= 0) {
                    // Skip divisors, as we don't care about buffer starting markers
                    if (!line.startsWith(LOGCAT_DIVISOR_PREFIX)) {
                        result.add(line);
                    }
                }
            }
        } catch (IOException e) {
            Slog.e(TAG, "Error running logcat", e);
        }

        return result;
    }

    /**
     * Extracts the timestamp from the beginning of a log line.
     * Assumes the timestamp is in the first 18 characters.
     * Returns the full line if it is shorter than 18 characters.
     *
     * @param line the log line to extract the timestamp from
     * @return the extracted timestamp or the original line if too short
     */
    @VisibleForTesting
    static String extractLogTimestamp(String line) {
        if (line.length() < 18) {
            // fallback if line is too short
            return line;
        }
        return line.substring(0, 18);
    }

    /**
     * Appends as many log lines as possible from the provided list into the StringBuilder,
     * without exceeding the specified maxBufferSize. The first element of the list
     * is treated as a special "header" or "divider" line and is always included if logs
     * are non-empty.
     *
     * @param sb            The StringBuilder to append logs into.
     * @param logs          The list of log lines (with logs.get(0) assumed to be a header).
     * @param maxBufferSize The maximum allowable size (in characters) to consume.
     * @return The total number of characters (including newlines) appended to the StringBuilder.
     */
    @VisibleForTesting
    static int trimAndAppendLogs(StringBuilder sb, List<String> logs, int maxBufferSize) {

        if (logs.isEmpty()) return 0;

        // Start from the last log entry and move backward to see what fits.
        int preStartIndex = logs.size() - 1;
        // Reserve space for the first line
        int logSize = LOGCAT_AGGREGATED_DIVISOR.length() + 1;

        // Calculate our starting point by moving backwards.
        while (preStartIndex >= 0
                && logSize + logs.get(preStartIndex).length() + 1 <= maxBufferSize) {
            logSize += logs.get(preStartIndex).length() + 1;
            preStartIndex--;
        }

        // If no logs were included, return 0
        if (preStartIndex == logs.size() - 1) return 0;

        // Append the header first
        sb.append(LOGCAT_AGGREGATED_DIVISOR).append("\n");
        // Then add the logs in the correct (non-decreasing) order
        for (int i = preStartIndex + 1; i < logs.size(); i++) {
            sb.append(logs.get(i)).append("\n");
        }

        return logSize;
    }

}
+7 −0
Original line number Diff line number Diff line
@@ -323,3 +323,10 @@ flag {
        purpose: PURPOSE_BUGFIX
    }
}

flag {
    name: "limit_logcat_collection"
    namespace: "stability"
    description: "Limit the number of logcat logs included to fit in dropbox entries"
    bug: "354138103"
}
 No newline at end of file
+130 −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.server.am;

import static org.junit.Assert.assertEquals;
import static org.junit.Assert.assertFalse;
import static org.junit.Assert.assertTrue;

import androidx.test.filters.SmallTest;

import org.junit.Test;

import java.util.Collections;
import java.util.List;

/**
 * Test class for {@link LogcatFetcher}.
 *
 * Build/Install/Run:
 *  atest FrameworksServicesTests:LogcatFetcherTest
 */
@SmallTest
public class LogcatFetcherTest {

    @Test
    public void testTrimAndAppendLogs_basic() {
        StringBuilder sb = new StringBuilder();
        List<String> logs = List.of(
                "03-12 14:55:18.080 +0000 22912 22934 E tag_a: Some log line 1",
                "03-12 14:56:18.080 +0000 34143 22934 I tag_b: Some log line 2"
        );

        int appendedSize = LogcatFetcher.trimAndAppendLogs(sb, logs, 1000);

        assertFalse(sb.toString().isEmpty());
        assertTrue(sb.toString().contains("Some log line 1"));
        assertTrue(sb.toString().contains("Some log line 2"));
        assertEquals(logs.size() + 1 /* header */, sb.toString().split("\n").length);
        assertTrue(appendedSize > 0);
    }

    @Test
    public void testTrimAndAppendLogs_emptyLogs() {
        StringBuilder sb = new StringBuilder();
        List<String> logs = Collections.emptyList();

        int size = LogcatFetcher.trimAndAppendLogs(sb, logs, 1000);

        assertEquals(0, size);
        assertTrue(sb.toString().isEmpty());
    }

    @Test
    public void testTrimAndAppendLogs_insufficientBuffer() {
        StringBuilder sb = new StringBuilder();
        List<String> logs = List.of("--------- beginning of divider", "Short log", "Another log");

        int size = LogcatFetcher.trimAndAppendLogs(sb, logs, 5);

        assertEquals(0, size);
        assertTrue(sb.toString().isEmpty());
    }

    @Test
    public void testTrimAndAppendLogs_onlyHeaderFits() {
        StringBuilder sb = new StringBuilder();
        List<String> logs = List.of("--------- divider", "A very very long log message");

        int size = LogcatFetcher.trimAndAppendLogs(sb, logs, 20);

        assertEquals(0, size);
        assertTrue(sb.toString().isEmpty());
    }

    @Test
    public void testTrimAndAppendLogs_exactBufferMatch() {
        StringBuilder sb = new StringBuilder();
        List<String> logs = List.of("--------- beginning of header", "log1", "log2", "log3");
        int exactBufferSize = "--------- beginning of header\nlog2\nlog3\n".length();

        int size = LogcatFetcher.trimAndAppendLogs(sb, logs, exactBufferSize);

        assertTrue(sb.toString().contains("log2"));
        assertTrue(sb.toString().contains("log3"));
        assertFalse(sb.toString().contains("log1"));
    }

    @Test
    public void testExtractLogTimestamp() {
        String timestamp = LogcatFetcher.extractLogTimestamp("03-12 12:34:56.789 a log message");
        assertEquals("03-12 12:34:56.789", timestamp);
    }

    @Test
    public void testExtractLogTimestamp_variedFormats() {
        String logLine = "12-31 23:59:59.999 Random log message";
        String timestamp = LogcatFetcher.extractLogTimestamp(logLine);
        assertEquals("12-31 23:59:59.999", timestamp);

        logLine = "Invalid line without timestamp";
        timestamp = LogcatFetcher.extractLogTimestamp(logLine);
        assertEquals("12-31 23:59:59.999".length(), timestamp.length());
    }

    @Test
    public void testTrimAndAppendLogs_headerOnlyFitsExactly() {
        StringBuilder sb = new StringBuilder();
        List<String> logs = List.of("--------- header", "A log entry");

        int size = LogcatFetcher.trimAndAppendLogs(sb, logs, "--------- header\n".length());

        assertEquals(0, size);
        assertTrue(sb.isEmpty());
    }

}