logd: record and replay log messages
To profile different log buffer types and configuration, this change
adds the ability to record log messages and adds a tool that will
replay those log messages through different log buffer implementations
and collect stats about the execution.
Test: log messages replay correctly
Change-Id: I0dc6c545b782fa7732e325dde109c496b137d0dd
diff --git a/logd/Android.bp b/logd/Android.bp
index 036cb7e..fe97871 100644
--- a/logd/Android.bp
+++ b/logd/Android.bp
@@ -180,3 +180,23 @@
"vts10",
],
}
+
+cc_binary {
+ name: "replay_messages",
+ defaults: ["logd_defaults"],
+ host_supported: true,
+
+ srcs: [
+ "ReplayMessages.cpp",
+ ],
+
+ static_libs: [
+ "libbase",
+ "libcutils",
+ "liblog",
+ "liblogd",
+ "libselinux",
+ "libz",
+ "libzstd",
+ ],
+}
diff --git a/logd/LogStatistics.cpp b/logd/LogStatistics.cpp
index 1705d48..87069b3 100644
--- a/logd/LogStatistics.cpp
+++ b/logd/LogStatistics.cpp
@@ -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 @@
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 @@
mDroppedElements[id] = 0;
mSizesTotal[id] = 0;
mElementsTotal[id] = 0;
- mOldest[id] = now;
- mNewest[id] = now;
+ 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 @@
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_};
diff --git a/logd/LogStatistics.h b/logd/LogStatistics.h
index d440a8c..e222d3f 100644
--- a/logd/LogStatistics.h
+++ b/logd/LogStatistics.h
@@ -515,7 +515,8 @@
}
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 @@
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_);
diff --git a/logd/README.replay.md b/logd/README.replay.md
new file mode 100644
index 0000000..5f7ec9e
--- /dev/null
+++ b/logd/README.replay.md
@@ -0,0 +1,46 @@
+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.
diff --git a/logd/RecordedLogMessage.h b/logd/RecordedLogMessage.h
new file mode 100644
index 0000000..f18c422
--- /dev/null
+++ b/logd/RecordedLogMessage.h
@@ -0,0 +1,30 @@
+/*
+ * 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;
+};
diff --git a/logd/RecordingLogBuffer.cpp b/logd/RecordingLogBuffer.cpp
new file mode 100644
index 0000000..f5991f3
--- /dev/null
+++ b/logd/RecordingLogBuffer.cpp
@@ -0,0 +1,62 @@
+/*
+ * 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.
+ */
+
+#include "RecordingLogBuffer.h"
+
+#include <android-base/file.h>
+
+static void WriteLogMessage(int fd, const RecordedLogMessage& meta, const std::string& msg) {
+ android::base::WriteFully(fd, &meta, sizeof(meta));
+ android::base::WriteFully(fd, msg.c_str(), meta.msg_len);
+}
+
+void RecordingLogBuffer::RecordLogMessage(log_id_t log_id, log_time realtime, uid_t uid, pid_t pid,
+ pid_t tid, const char* msg, uint16_t len) {
+ auto lock = std::lock_guard{lock_};
+ if (len > LOGGER_ENTRY_MAX_PAYLOAD) {
+ len = LOGGER_ENTRY_MAX_PAYLOAD;
+ }
+
+ RecordedLogMessage recorded_log_message = {
+ .uid = uid,
+ .pid = static_cast<uint32_t>(pid),
+ .tid = static_cast<uint32_t>(tid),
+ .realtime = realtime,
+ .msg_len = len,
+ .log_id = static_cast<uint8_t>(log_id),
+ };
+
+ if (!fd_.ok()) {
+ fd_.reset(open("/data/misc/logd/recorded-messages",
+ O_WRONLY | O_CREAT | O_APPEND | O_CLOEXEC, 0666));
+ if (!fd_.ok()) {
+ since_boot_messages_.emplace_back(recorded_log_message, std::string(msg, len));
+ return;
+ } else {
+ for (const auto& [meta, msg] : since_boot_messages_) {
+ WriteLogMessage(fd_.get(), meta, msg);
+ }
+ }
+ }
+
+ WriteLogMessage(fd_.get(), recorded_log_message, std::string(msg, len));
+}
+
+int RecordingLogBuffer::Log(log_id_t log_id, log_time realtime, uid_t uid, pid_t pid, pid_t tid,
+ const char* msg, uint16_t len) {
+ RecordLogMessage(log_id, realtime, uid, pid, tid, msg, len);
+ return SimpleLogBuffer::Log(log_id, realtime, uid, pid, tid, msg, len);
+}
\ No newline at end of file
diff --git a/logd/RecordingLogBuffer.h b/logd/RecordingLogBuffer.h
new file mode 100644
index 0000000..49a0aba
--- /dev/null
+++ b/logd/RecordingLogBuffer.h
@@ -0,0 +1,43 @@
+/*
+ * 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 "SimpleLogBuffer.h"
+
+#include <string>
+#include <tuple>
+#include <vector>
+
+#include <android-base/unique_fd.h>
+
+#include "RecordedLogMessage.h"
+
+class RecordingLogBuffer : public SimpleLogBuffer {
+ public:
+ RecordingLogBuffer(LogReaderList* reader_list, LogTags* tags, LogStatistics* stats)
+ : SimpleLogBuffer(reader_list, tags, stats) {}
+
+ int Log(log_id_t log_id, log_time realtime, uid_t uid, pid_t pid, pid_t tid, const char* msg,
+ uint16_t len) override;
+
+ private:
+ void RecordLogMessage(log_id_t log_id, log_time realtime, uid_t uid, pid_t pid, pid_t tid,
+ const char* msg, uint16_t len);
+
+ std::vector<std::pair<RecordedLogMessage, std::string>> since_boot_messages_;
+ android::base::unique_fd fd_;
+};
diff --git a/logd/ReplayMessages.cpp b/logd/ReplayMessages.cpp
new file mode 100644
index 0000000..73b0bd0
--- /dev/null
+++ b/logd/ReplayMessages.cpp
@@ -0,0 +1,454 @@
+/*
+ * 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.
+ */
+
+#include <inttypes.h>
+
+#include <chrono>
+#include <map>
+
+#include <android-base/file.h>
+#include <android-base/mapped_file.h>
+#include <android-base/parseint.h>
+#include <android-base/strings.h>
+#include <android-base/unique_fd.h>
+#include <android/log.h>
+#include <log/log_time.h>
+#include <log/logprint.h>
+
+#include "ChattyLogBuffer.h"
+#include "LogBuffer.h"
+#include "LogStatistics.h"
+#include "RecordedLogMessage.h"
+#include "SerializedLogBuffer.h"
+#include "SimpleLogBuffer.h"
+
+using android::base::MappedFile;
+using android::base::ParseInt;
+using android::base::ParseUint;
+using android::base::Split;
+
+#ifndef __ANDROID__
+// This is hard coded to 1MB on host. On device use persist.logd.size to configure.
+unsigned long __android_logger_get_buffer_size(log_id_t) {
+ return 1 * 1024 * 1024;
+}
+
+bool __android_logger_valid_buffer_size(unsigned long) {
+ return true;
+}
+#endif
+
+char* android::uidToName(uid_t) {
+ return nullptr;
+}
+
+static size_t GetPrivateDirty() {
+ // Allocate once and hope that we don't need to reallocate >40000, to prevent heap fragmentation
+ static std::string smaps(40000, '\0');
+ android::base::ReadFileToString("/proc/self/smaps", &smaps);
+
+ size_t result = 0;
+ size_t base = 0;
+ size_t found;
+ while (true) {
+ found = smaps.find("Private_Dirty:", base);
+ if (found == smaps.npos) break;
+
+ found += sizeof("Private_Dirty:");
+
+ result += atoi(&smaps[found]);
+
+ base = found + 1;
+ }
+
+ return result;
+}
+
+static AndroidLogFormat* GetLogFormat() {
+ static AndroidLogFormat* format = [] {
+ auto* format = android_log_format_new();
+ android_log_setPrintFormat(format, android_log_formatFromString("threadtime"));
+ android_log_setPrintFormat(format, android_log_formatFromString("uid"));
+ return format;
+ }();
+ return format;
+}
+
+static void PrintMessage(struct log_msg* buf) {
+ bool is_binary =
+ buf->id() == LOG_ID_EVENTS || buf->id() == LOG_ID_STATS || buf->id() == LOG_ID_SECURITY;
+
+ AndroidLogEntry entry;
+ int err;
+ if (is_binary) {
+ char binaryMsgBuf[1024];
+ err = android_log_processBinaryLogBuffer(&buf->entry, &entry, nullptr, binaryMsgBuf,
+ sizeof(binaryMsgBuf));
+ } else {
+ err = android_log_processLogBuffer(&buf->entry, &entry);
+ }
+ if (err < 0) {
+ fprintf(stderr, "Error parsing log message\n");
+ }
+
+ android_log_printLogLine(GetLogFormat(), STDOUT_FILENO, &entry);
+}
+
+static log_time GetFirstTimeStamp(const MappedFile& recorded_messages) {
+ if (sizeof(RecordedLogMessage) >= recorded_messages.size()) {
+ fprintf(stderr, "At least one log message must be present in the input\n");
+ exit(1);
+ }
+
+ auto* meta = reinterpret_cast<RecordedLogMessage*>(recorded_messages.data());
+ return meta->realtime;
+}
+
+class StdoutWriter : public LogWriter {
+ public:
+ StdoutWriter() : LogWriter(0, true) {}
+ bool Write(const logger_entry& entry, const char* message) override {
+ struct log_msg log_msg;
+ log_msg.entry = entry;
+ if (log_msg.entry.len > LOGGER_ENTRY_MAX_PAYLOAD) {
+ fprintf(stderr, "payload too large %" PRIu16, log_msg.entry.len);
+ exit(1);
+ }
+ memcpy(log_msg.msg(), message, log_msg.entry.len);
+
+ PrintMessage(&log_msg);
+
+ return true;
+ }
+
+ std::string name() const override { return "stdout writer"; }
+};
+
+class Operation {
+ public:
+ virtual ~Operation() {}
+
+ virtual void Begin() {}
+ virtual void Log(const RecordedLogMessage& meta, const char* msg) = 0;
+ virtual void End() {}
+};
+
+class PrintInteresting : public Operation {
+ public:
+ PrintInteresting(log_time first_log_timestamp)
+ : stats_simple_{false, false, first_log_timestamp},
+ stats_chatty_{false, false, first_log_timestamp},
+ stats_serialized_{false, true, first_log_timestamp} {}
+
+ void Begin() override {
+ printf("message_count,simple_main_lines,simple_radio_lines,simple_events_lines,simple_"
+ "system_lines,simple_crash_lines,simple_stats_lines,simple_security_lines,simple_"
+ "kernel_lines,simple_main_size,simple_radio_size,simple_events_size,simple_system_"
+ "size,simple_crash_size,simple_stats_size,simple_security_size,simple_kernel_size,"
+ "simple_main_overhead,simple_radio_overhead,simple_events_overhead,simple_system_"
+ "overhead,simple_crash_overhead,simple_stats_overhead,simple_security_overhead,"
+ "simple_kernel_overhead,simple_main_range,simple_radio_range,simple_events_range,"
+ "simple_system_range,simple_crash_range,simple_stats_range,simple_security_range,"
+ "simple_kernel_range,chatty_main_lines,chatty_radio_lines,chatty_events_lines,"
+ "chatty_system_lines,chatty_crash_lines,chatty_stats_lines,chatty_security_lines,"
+ "chatty_"
+ "kernel_lines,chatty_main_size,chatty_radio_size,chatty_events_size,chatty_system_"
+ "size,chatty_crash_size,chatty_stats_size,chatty_security_size,chatty_kernel_size,"
+ "chatty_main_overhead,chatty_radio_overhead,chatty_events_overhead,chatty_system_"
+ "overhead,chatty_crash_overhead,chatty_stats_overhead,chatty_security_overhead,"
+ "chatty_kernel_overhead,chatty_main_range,chatty_radio_range,chatty_events_range,"
+ "chatty_system_range,chatty_crash_range,chatty_stats_range,chatty_security_range,"
+ "chatty_kernel_range,serialized_main_lines,serialized_radio_lines,serialized_events_"
+ "lines,serialized_"
+ "system_lines,serialized_crash_lines,serialized_stats_lines,serialized_security_"
+ "lines,serialized_"
+ "kernel_lines,serialized_main_size,serialized_radio_size,serialized_events_size,"
+ "serialized_system_"
+ "size,serialized_crash_size,serialized_stats_size,serialized_security_size,"
+ "serialized_kernel_size,"
+ "serialized_main_overhead,serialized_radio_overhead,serialized_events_overhead,"
+ "serialized_system_"
+ "overhead,serialized_crash_overhead,serialized_stats_overhead,serialized_security_"
+ "overhead,"
+ "serialized_kernel_overhead,serialized_main_range,serialized_radio_range,serialized_"
+ "events_range,"
+ "serialized_system_range,serialized_crash_range,serialized_stats_range,serialized_"
+ "security_range,"
+ "serialized_kernel_range\n");
+ }
+
+ void Log(const RecordedLogMessage& meta, const char* msg) override {
+ simple_log_buffer_.Log(static_cast<log_id_t>(meta.log_id), meta.realtime, meta.uid,
+ meta.pid, meta.tid, msg, meta.msg_len);
+
+ chatty_log_buffer_.Log(static_cast<log_id_t>(meta.log_id), meta.realtime, meta.uid,
+ meta.pid, meta.tid, msg, meta.msg_len);
+
+ serialized_log_buffer_.Log(static_cast<log_id_t>(meta.log_id), meta.realtime, meta.uid,
+ meta.pid, meta.tid, msg, meta.msg_len);
+
+ if (num_message_ % 10000 == 0) {
+ printf("%" PRIu64 ",%s,%s,%s\n", num_message_,
+ stats_simple_.ReportInteresting().c_str(),
+ stats_chatty_.ReportInteresting().c_str(),
+ stats_serialized_.ReportInteresting().c_str());
+ }
+
+ num_message_++;
+ }
+
+ private:
+ uint64_t num_message_ = 1;
+
+ LogReaderList reader_list_;
+ LogTags tags_;
+ PruneList prune_list_;
+
+ LogStatistics stats_simple_;
+ SimpleLogBuffer simple_log_buffer_{&reader_list_, &tags_, &stats_simple_};
+
+ LogStatistics stats_chatty_;
+ ChattyLogBuffer chatty_log_buffer_{&reader_list_, &tags_, &prune_list_, &stats_chatty_};
+
+ LogStatistics stats_serialized_;
+ SerializedLogBuffer serialized_log_buffer_{&reader_list_, &tags_, &stats_serialized_};
+};
+
+class SingleBufferOperation : public Operation {
+ public:
+ SingleBufferOperation(log_time first_log_timestamp, const char* buffer) {
+ if (!strcmp(buffer, "simple")) {
+ stats_.reset(new LogStatistics{false, false, first_log_timestamp});
+ log_buffer_.reset(new SimpleLogBuffer(&reader_list_, &tags_, stats_.get()));
+ } else if (!strcmp(buffer, "chatty")) {
+ stats_.reset(new LogStatistics{false, false, first_log_timestamp});
+ log_buffer_.reset(
+ new ChattyLogBuffer(&reader_list_, &tags_, &prune_list_, stats_.get()));
+ } else if (!strcmp(buffer, "serialized")) {
+ stats_.reset(new LogStatistics{false, true, first_log_timestamp});
+ log_buffer_.reset(new SerializedLogBuffer(&reader_list_, &tags_, stats_.get()));
+ } else {
+ fprintf(stderr, "invalid log buffer type '%s'\n", buffer);
+ abort();
+ }
+ }
+
+ void Log(const RecordedLogMessage& meta, const char* msg) override {
+ PreOperation();
+ log_buffer_->Log(static_cast<log_id_t>(meta.log_id), meta.realtime, meta.uid, meta.pid,
+ meta.tid, msg, meta.msg_len);
+
+ Operation();
+
+ num_message_++;
+ }
+
+ virtual void PreOperation() {}
+ virtual void Operation() {}
+
+ protected:
+ uint64_t num_message_ = 1;
+
+ LogReaderList reader_list_;
+ LogTags tags_;
+ PruneList prune_list_;
+
+ std::unique_ptr<LogStatistics> stats_;
+ std::unique_ptr<LogBuffer> log_buffer_;
+};
+
+class PrintMemory : public SingleBufferOperation {
+ public:
+ PrintMemory(log_time first_log_timestamp, const char* buffer)
+ : SingleBufferOperation(first_log_timestamp, buffer) {}
+
+ void Operation() override {
+ if (num_message_ % 100000 == 0) {
+ printf("%" PRIu64 ",%s\n", num_message_,
+ std::to_string(GetPrivateDirty() - baseline_memory_).c_str());
+ }
+ }
+
+ private:
+ size_t baseline_memory_ = GetPrivateDirty();
+};
+
+class PrintLogs : public SingleBufferOperation {
+ public:
+ PrintLogs(log_time first_log_timestamp, const char* buffer, const char* buffers,
+ const char* print_point)
+ : SingleBufferOperation(first_log_timestamp, buffer) {
+ if (buffers != nullptr) {
+ if (strcmp(buffers, "all") != 0) {
+ std::vector<int> buffer_ids;
+ auto string_ids = Split(buffers, ",");
+ for (const auto& string_id : string_ids) {
+ int result;
+ if (!ParseInt(string_id, &result, 0, 7)) {
+ fprintf(stderr, "Could not parse buffer_id '%s'\n", string_id.c_str());
+ exit(1);
+ }
+ buffer_ids.emplace_back(result);
+ }
+ mask_ = 0;
+ for (const auto& buffer_id : buffer_ids) {
+ mask_ |= 1 << buffer_id;
+ }
+ }
+ }
+ if (print_point != nullptr) {
+ uint64_t result = 0;
+ if (!ParseUint(print_point, &result)) {
+ fprintf(stderr, "Could not parse print point '%s'\n", print_point);
+ exit(1);
+ }
+ print_point_ = result;
+ }
+ }
+
+ void Operation() override {
+ if (print_point_ && num_message_ >= *print_point_) {
+ End();
+ exit(0);
+ }
+ }
+
+ void End() {
+ std::unique_ptr<LogWriter> test_writer(new StdoutWriter());
+ std::unique_ptr<FlushToState> flush_to_state = log_buffer_->CreateFlushToState(1, mask_);
+ log_buffer_->FlushTo(test_writer.get(), *flush_to_state, nullptr);
+
+ auto stats_string = stats_->Format(0, 0, mask_);
+ printf("%s\n", stats_string.c_str());
+ }
+
+ private:
+ LogMask mask_ = kLogMaskAll;
+ std::optional<uint64_t> print_point_;
+};
+
+class PrintLatency : public SingleBufferOperation {
+ public:
+ PrintLatency(log_time first_log_timestamp, const char* buffer)
+ : SingleBufferOperation(first_log_timestamp, buffer) {}
+
+ void PreOperation() override { operation_start_ = std::chrono::steady_clock::now(); }
+
+ void Operation() override {
+ auto end = std::chrono::steady_clock::now();
+ auto duration = (end - operation_start_).count();
+ durations_.emplace_back(duration);
+ }
+
+ void End() {
+ std::sort(durations_.begin(), durations_.end());
+ auto q1 = durations_.size() / 4;
+ auto q2 = durations_.size() / 2;
+ auto q3 = 3 * durations_.size() / 4;
+
+ auto p95 = 95 * durations_.size() / 100;
+ auto p99 = 99 * durations_.size() / 100;
+ auto p9999 = 9999 * durations_.size() / 10000;
+
+ printf("q1: %lld q2: %lld q3: %lld p95: %lld p99: %lld p99.99: %lld max: %lld\n",
+ durations_[q1], durations_[q2], durations_[q3], durations_[p95], durations_[p99],
+ durations_[p9999], durations_.back());
+ }
+
+ private:
+ std::chrono::steady_clock::time_point operation_start_;
+ std::vector<long long> durations_;
+};
+
+int main(int argc, char** argv) {
+ if (argc < 3) {
+ fprintf(stderr, "Usage: %s FILE OPERATION [BUFFER] [OPTIONS]\n", argv[0]);
+ return 1;
+ }
+
+ if (strcmp(argv[2], "interesting") != 0 && argc < 4) {
+ fprintf(stderr, "Operations other than 'interesting' require a BUFFER argument\n");
+ return 1;
+ }
+
+ int recorded_messages_fd = open(argv[1], O_RDONLY);
+ if (recorded_messages_fd == -1) {
+ fprintf(stderr, "Couldn't open input file\n");
+ return 1;
+ }
+ struct stat fd_stat;
+ if (fstat(recorded_messages_fd, &fd_stat) != 0) {
+ fprintf(stderr, "Couldn't fstat input file\n");
+ return 1;
+ }
+ auto recorded_messages = MappedFile::FromFd(recorded_messages_fd, 0,
+ static_cast<size_t>(fd_stat.st_size), PROT_READ);
+ if (recorded_messages == nullptr) {
+ fprintf(stderr, "Couldn't mmap input file\n");
+ return 1;
+ }
+
+ // LogStatistics typically uses 'now()' to initialize its log range state, but this doesn't work
+ // when replaying older logs, so we instead give it the timestamp from the first log.
+ log_time first_log_timestamp = GetFirstTimeStamp(*recorded_messages);
+
+ std::unique_ptr<Operation> operation;
+ if (!strcmp(argv[2], "interesting")) {
+ operation.reset(new PrintInteresting(first_log_timestamp));
+ } else if (!strcmp(argv[2], "memory_usage")) {
+ operation.reset(new PrintMemory(first_log_timestamp, argv[3]));
+ } else if (!strcmp(argv[2], "latency")) {
+ operation.reset(new PrintLatency(first_log_timestamp, argv[3]));
+ } else if (!strcmp(argv[2], "print_logs")) {
+ operation.reset(new PrintLogs(first_log_timestamp, argv[3], argc > 4 ? argv[4] : nullptr,
+ argc > 5 ? argv[5] : nullptr));
+ } else if (!strcmp(argv[2], "nothing")) {
+ operation.reset(new SingleBufferOperation(first_log_timestamp, argv[3]));
+ } else {
+ fprintf(stderr, "unknown operation '%s'\n", argv[2]);
+ return 1;
+ }
+
+ // LogBuffer::Log() won't log without this on host.
+ __android_log_set_minimum_priority(ANDROID_LOG_VERBOSE);
+ // But we still want to suppress messages <= error to not interrupt the rest of the output.
+ __android_log_set_logger([](const struct __android_log_message* log_message) {
+ if (log_message->priority < ANDROID_LOG_ERROR) {
+ return;
+ }
+ __android_log_stderr_logger(log_message);
+ });
+
+ operation->Begin();
+
+ uint64_t read_position = 0;
+ while (read_position + sizeof(RecordedLogMessage) < recorded_messages->size()) {
+ auto* meta =
+ reinterpret_cast<RecordedLogMessage*>(recorded_messages->data() + read_position);
+ if (read_position + sizeof(RecordedLogMessage) + meta->msg_len >=
+ recorded_messages->size()) {
+ break;
+ }
+ char* msg = recorded_messages->data() + read_position + sizeof(RecordedLogMessage);
+ read_position += sizeof(RecordedLogMessage) + meta->msg_len;
+
+ operation->Log(*meta, msg);
+ }
+
+ operation->End();
+
+ return 0;
+}