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

Commit f5962b1b authored by Tom Cherry's avatar Tom Cherry Committed by Automerger Merge Worker
Browse files

Merge "logd: record and replay log messages" am: 7a6191ce

Original change: https://android-review.googlesource.com/c/platform/system/core/+/1358702

Change-Id: Id90a98ca4c701b98c37528bee034d879e44bb732
parents 8584d416 7a6191ce
Loading
Loading
Loading
Loading
+20 −0
Original line number Diff line number Diff line
@@ -180,3 +180,23 @@ cc_test {
        "vts10",
    ],
}

cc_binary {
    name: "replay_messages",
    defaults: ["logd_defaults"],
    host_supported: true,

    srcs: [
        "ReplayMessages.cpp",
    ],

    static_libs: [
        "libbase",
        "libcutils",
        "liblog",
        "liblogd",
        "libselinux",
        "libz",
        "libzstd",
    ],
}
+36 −3
Original line number Diff line number Diff line
@@ -26,8 +26,10 @@
#include <unistd.h>

#include <list>
#include <vector>

#include <android-base/logging.h>
#include <android-base/strings.h>
#include <private/android_logger.h>

#include "LogBufferElement.h"
@@ -61,7 +63,8 @@ static std::string TagNameKey(const LogStatisticsElement& element) {
    return std::string(msg, len);
}

LogStatistics::LogStatistics(bool enable_statistics, bool track_total_size)
LogStatistics::LogStatistics(bool enable_statistics, bool track_total_size,
                             std::optional<log_time> start_time)
    : enable(enable_statistics), track_total_size_(track_total_size) {
    log_time now(CLOCK_REALTIME);
    log_id_for_each(id) {
@@ -70,8 +73,13 @@ LogStatistics::LogStatistics(bool enable_statistics, bool track_total_size)
        mDroppedElements[id] = 0;
        mSizesTotal[id] = 0;
        mElementsTotal[id] = 0;
        if (start_time) {
            mOldest[id] = *start_time;
            mNewest[id] = *start_time;
        } else {
            mOldest[id] = now;
            mNewest[id] = now;
        }
        mNewestDropped[id] = now;
    }
}
@@ -784,6 +792,31 @@ std::string LogStatistics::FormatTable(const LogHashtable<TKey, TEntry>& table,
    return output;
}

std::string LogStatistics::ReportInteresting() const {
    auto lock = std::lock_guard{lock_};

    std::vector<std::string> items;

    log_id_for_each(i) { items.emplace_back(std::to_string(mElements[i])); }

    log_id_for_each(i) { items.emplace_back(std::to_string(mSizes[i])); }

    log_id_for_each(i) {
        items.emplace_back(std::to_string(overhead_[i] ? *overhead_[i] : mSizes[i]));
    }

    log_id_for_each(i) {
        uint64_t oldest = mOldest[i].msec() / 1000;
        uint64_t newest = mNewest[i].msec() / 1000;

        int span = newest - oldest;

        items.emplace_back(std::to_string(span));
    }

    return android::base::Join(items, ",");
}

std::string LogStatistics::Format(uid_t uid, pid_t pid, unsigned int logMask) const {
    auto lock = std::lock_guard{lock_};

+3 −1
Original line number Diff line number Diff line
@@ -515,7 +515,8 @@ class LogStatistics {
    }

  public:
    LogStatistics(bool enable_statistics, bool track_total_size);
    LogStatistics(bool enable_statistics, bool track_total_size,
                  std::optional<log_time> start_time = {});

    void AddTotal(log_id_t log_id, uint16_t size) EXCLUDES(lock_);

@@ -556,6 +557,7 @@ class LogStatistics {
        return SizesTotal;
    }

    std::string ReportInteresting() const EXCLUDES(lock_);
    std::string Format(uid_t uid, pid_t pid, unsigned int logMask) const EXCLUDES(lock_);

    const char* PidToName(pid_t pid) const EXCLUDES(lock_);

logd/README.replay.md

0 → 100644
+46 −0
Original line number Diff line number Diff line
logd can record and replay log messages for offline analysis.

Recording Messages
------------------

logd has a `RecordingLogBuffer` buffer that records messages to /data/misc/logd/recorded-messages.
It stores messages in memory until that file is accessible, in order to capture all messages since
the beginning of boot.  It is only meant for logging developers to use and must be manually enabled
in by adding `RecordingLogBuffer.cpp` to `Android.bp` and setting
`log_buffer = new SimpleLogBuffer(&reader_list, &log_tags, &log_statistics);` in `main.cpp`.

Recording messages may delay the Log() function from completing and it is highly recommended to make
the logd socket in `liblog` blocking, by removing `SOCK_NONBLOCK` from the `socket()` call in
`liblog/logd_writer.cpp`.

Replaying Messages
------------------

Recorded messages can be replayed offline with the `replay_messages` tool.  It runs on host and
device and supports the following options:

1. `interesting` - this prints 'interesting' statistics for each of the log buffer types (simple,
   chatty, serialized).  The statistics are:
    1. Log Entry Count
    2. Size (the uncompressed size of the log messages in bytes)
    3. Overhead (the total cost of the log messages in memory in bytes)
    4. Range (the range of time that the logs cover in seconds)
2. `memory_usage BUFFER_TYPE` - this prints the memory usage (sum of private dirty pages of the
  `replay_messages` process).  Note that the input file is mmap()'ed as RO/Shared so it does not
  appear in these dirty pages, and a baseline is taken before allocating the log buffers, so only
  their contributions are measured.  The tool outputs the memory usage every 100,000 messages.
3. `latency BUFFER_TYPE` - this prints statistics of the latency of the Log() function for the given
  buffer type.  It specifically prints the 1st, 2nd, and 3rd quartiles; the 95th, 99th, and 99.99th
  percentiles; and the maximum latency.
4. `print_logs BUFFER_TYPE [buffers] [print_point]` - this prints the logs as processed by the given
  buffer_type from the buffers specified by `buffers` starting after the number of logs specified by
  `print_point` have been logged.  This acts as if a user called `logcat` immediately after the
  specified logs have been logged, which is particularly useful since it will show the chatty
  pruning messages at that point.  It additionally prints the statistics from `logcat -S` after the
  logs.
  `buffers` is a comma separated list of the numeric buffer id values from `<android/log.h>`.  For
  example, `0,1,3` represents the main, radio, and system buffers.  It can can also be `all`.
  `print_point` is an positive integer.  If it is unspecified, logs are printed after the entire
  input file is consumed.
5. `nothing BUFFER_TYPE` - this does nothing other than read the input file and call Log() for the
  given buffer type.  This is used for profiling CPU usage of strictly the log buffer.
+30 −0
Original line number Diff line number Diff line
/*
 * Copyright (C) 2020 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.
 */

#pragma once

#include <inttypes.h>

#include <log/log_time.h>

struct __attribute__((packed)) RecordedLogMessage {
    uint32_t uid;
    uint32_t pid;
    uint32_t tid;
    log_time realtime;
    uint16_t msg_len;
    uint8_t log_id;
};
Loading