Merge "logd: record and replay log messages" am: 7a6191ce2e am: f5962b1bb5 am:... (2c34a4c1) · Commits · e / os / android_system_core

logd/Android.bp

+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",
		],
		}

logd/LogStatistics.cpp

+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_};

logd/LogStatistics.h

+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.

logd/RecordedLogMessage.h

0 → 100644

+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;
		};