From 06e111a148dc40a0bbd2b93d8659291c73a37121 Mon Sep 17 00:00:00 2001 From: Tom Cherry Date: Wed, 5 Aug 2020 11:22:44 -0700 Subject: [PATCH 1/2] Add android_logger_get_log_consumed_size() and report it in logcat There is an existing API, android_logger_get_log_readable_size() which historically reported the consumed amount of data for the chatty log buffer, since consumed and readable are synonymous with that buffer type. With log compression, readable and consumed are not synonymous, since the readable log size is the uncompressed log size whereas the consumed log size is the compressed log size. This change adds android_logger_get_log_consumed_size() which returns the consumed log size and makes android_logger_get_log_readable_size() return the readable log size. Note that these values are identical if compression is not used. It adds both statistics to logcat: main: ring buffer is 1 MiB (429 KiB consumed, 817 KiB readable) radio: ring buffer is 1 MiB (339 KiB consumed, 715 KiB readable) ... Test: logcat prints the right values with compression and chatty Change-Id: I8b9688a987736204e2e6026e8635fbd1a5e68bb7 --- liblog/include/log/log_read.h | 7 ++++ liblog/logd_reader.cpp | 66 +++++++++++++++++++---------------- logcat/logcat.cpp | 10 +++--- logd/CommandListener.cpp | 21 +++++++++++ logd/CommandListener.h | 1 + logd/LogStatistics.h | 9 ++++- 6 files changed, 79 insertions(+), 35 deletions(-) diff --git a/liblog/include/log/log_read.h b/liblog/include/log/log_read.h index 23d76f485..173693472 100644 --- a/liblog/include/log/log_read.h +++ b/liblog/include/log/log_read.h @@ -81,10 +81,17 @@ struct logger; log_id_t android_logger_get_id(struct logger* logger); +/* Clears the given log buffer. */ int android_logger_clear(struct logger* logger); +/* Return the allotted size for the given log buffer. */ long android_logger_get_log_size(struct logger* logger); +/* Set the allotted size for the given log buffer. */ int android_logger_set_log_size(struct logger* logger, unsigned long size); +/* Return the actual, uncompressed size that can be read from the given log buffer. */ long android_logger_get_log_readable_size(struct logger* logger); +/* Return the actual, compressed size that the given log buffer is consuming. */ +long android_logger_get_log_consumed_size(struct logger* logger); +/* Deprecated. Always returns '4' regardless of input. */ int android_logger_get_log_version(struct logger* logger); struct logger_list; diff --git a/liblog/logd_reader.cpp b/liblog/logd_reader.cpp index 7123f602a..611caedd8 100644 --- a/liblog/logd_reader.cpp +++ b/liblog/logd_reader.cpp @@ -35,6 +35,7 @@ #include +#include #include #include "logger.h" @@ -160,26 +161,56 @@ int android_logger_clear(struct logger* logger) { return check_log_success(buf, SendLogdControlMessage(buf, sizeof(buf))); } -/* returns the total size of the log's ring buffer */ -long android_logger_get_log_size(struct logger* logger) { +enum class LogSizeType : uint32_t { + kAllotted = 0, + kReadable, + kConsumed, +}; + +static long GetLogSize(struct logger* logger, LogSizeType type) { if (!android_logger_is_logd(logger)) { return -EINVAL; } uint32_t log_id = android_logger_get_id(logger); char buf[512]; - snprintf(buf, sizeof(buf), "getLogSize %" PRIu32, log_id); + switch (type) { + case LogSizeType::kAllotted: + snprintf(buf, sizeof(buf), "getLogSize %" PRIu32, log_id); + break; + case LogSizeType::kReadable: + snprintf(buf, sizeof(buf), "getLogSizeReadable %" PRIu32, log_id); + break; + case LogSizeType::kConsumed: + snprintf(buf, sizeof(buf), "getLogSizeUsed %" PRIu32, log_id); + break; + default: + abort(); + } ssize_t ret = SendLogdControlMessage(buf, sizeof(buf)); if (ret < 0) { return ret; } - if ((buf[0] < '0') || ('9' < buf[0])) { + long size; + if (!android::base::ParseInt(buf, &size)) { return -1; } - return atol(buf); + return size; +} + +long android_logger_get_log_size(struct logger* logger) { + return GetLogSize(logger, LogSizeType::kAllotted); +} + +long android_logger_get_log_readable_size(struct logger* logger) { + return GetLogSize(logger, LogSizeType::kReadable); +} + +long android_logger_get_log_consumed_size(struct logger* logger) { + return GetLogSize(logger, LogSizeType::kConsumed); } int android_logger_set_log_size(struct logger* logger, unsigned long size) { @@ -194,31 +225,6 @@ int android_logger_set_log_size(struct logger* logger, unsigned long size) { return check_log_success(buf, SendLogdControlMessage(buf, sizeof(buf))); } -/* - * returns the readable size of the log's ring buffer (that is, amount of the - * log consumed) - */ -long android_logger_get_log_readable_size(struct logger* logger) { - if (!android_logger_is_logd(logger)) { - return -EINVAL; - } - - uint32_t log_id = android_logger_get_id(logger); - char buf[512]; - snprintf(buf, sizeof(buf), "getLogSizeUsed %" PRIu32, log_id); - - ssize_t ret = SendLogdControlMessage(buf, sizeof(buf)); - if (ret < 0) { - return ret; - } - - if ((buf[0] < '0') || ('9' < buf[0])) { - return -1; - } - - return atol(buf); -} - int android_logger_get_log_version(struct logger*) { return 4; } diff --git a/logcat/logcat.cpp b/logcat/logcat.cpp index c7d16347b..b5d2aa44a 100644 --- a/logcat/logcat.cpp +++ b/logcat/logcat.cpp @@ -1064,18 +1064,20 @@ int Logcat::Run(int argc, char** argv) { if (getLogSize) { long size = android_logger_get_log_size(logger); long readable = android_logger_get_log_readable_size(logger); + long consumed = android_logger_get_log_consumed_size(logger); if (size < 0 || readable < 0) { ReportErrorName(buffer_name, security_buffer_selected, &get_size_failures); } else { auto size_format = format_of_size(size); auto readable_format = format_of_size(readable); + auto consumed_format = format_of_size(consumed); std::string str = android::base::StringPrintf( - "%s: ring buffer is %lu %sB (%lu %sB consumed)," + "%s: ring buffer is %lu %sB (%lu %sB consumed, %lu %sB readable)," " max entry is %d B, max payload is %d B\n", - buffer_name, size_format.first, size_format.second, readable_format.first, - readable_format.second, (int)LOGGER_ENTRY_MAX_LEN, - (int)LOGGER_ENTRY_MAX_PAYLOAD); + buffer_name, size_format.first, size_format.second, consumed_format.first, + consumed_format.second, readable_format.first, readable_format.second, + (int)LOGGER_ENTRY_MAX_LEN, (int)LOGGER_ENTRY_MAX_PAYLOAD); TEMP_FAILURE_RETRY(write(output_fd_.get(), str.data(), str.length())); } } diff --git a/logd/CommandListener.cpp b/logd/CommandListener.cpp index 2eeb0d977..6381ffaca 100644 --- a/logd/CommandListener.cpp +++ b/logd/CommandListener.cpp @@ -46,6 +46,7 @@ CommandListener::CommandListener(LogBuffer* buf, LogTags* tags, PruneList* prune registerCmd(new ClearCmd(this)); registerCmd(new GetBufSizeCmd(this)); registerCmd(new SetBufSizeCmd(this)); + registerCmd(new GetBufSizeReadableCmd(this)); registerCmd(new GetBufSizeUsedCmd(this)); registerCmd(new GetStatisticsCmd(this)); registerCmd(new SetPruneListCmd(this)); @@ -136,6 +137,26 @@ int CommandListener::SetBufSizeCmd::runCommand(SocketClient* cli, int argc, return 0; } +int CommandListener::GetBufSizeReadableCmd::runCommand(SocketClient* cli, int argc, char** argv) { + setname(); + if (argc < 2) { + cli->sendMsg("Missing Argument"); + return 0; + } + + int id = atoi(argv[1]); + if (id < LOG_ID_MIN || LOG_ID_MAX <= id) { + cli->sendMsg("Range Error"); + return 0; + } + + unsigned long size = stats()->SizeReadable((log_id_t)id); + char buf[512]; + snprintf(buf, sizeof(buf), "%lu", size); + cli->sendMsg(buf); + return 0; +} + int CommandListener::GetBufSizeUsedCmd::runCommand(SocketClient* cli, int argc, char** argv) { setname(); diff --git a/logd/CommandListener.h b/logd/CommandListener.h index c3080ab97..8e12634af 100644 --- a/logd/CommandListener.h +++ b/logd/CommandListener.h @@ -57,6 +57,7 @@ class CommandListener : public FrameworkListener { LogCmd(Clear, clear); LogCmd(GetBufSize, getLogSize); LogCmd(SetBufSize, setLogSize); + LogCmd(GetBufSizeReadable, getLogSizeReadable); LogCmd(GetBufSizeUsed, getLogSizeUsed); LogCmd(GetStatistics, getStatistics); LogCmd(GetPruneList, getPruneList); diff --git a/logd/LogStatistics.h b/logd/LogStatistics.h index e222d3f24..faf928397 100644 --- a/logd/LogStatistics.h +++ b/logd/LogStatistics.h @@ -544,7 +544,7 @@ class LogStatistics { bool ShouldPrune(log_id id, unsigned long max_size, unsigned long* prune_rows) const EXCLUDES(lock_); - // Snapshot of the sizes for a given log buffer. + // Return the consumed size of the given buffer. size_t Sizes(log_id_t id) const EXCLUDES(lock_) { auto lock = std::lock_guard{lock_}; if (overhead_[id]) { @@ -552,6 +552,13 @@ class LogStatistics { } return mSizes[id]; } + + // Return the uncompressed size of the contents of the given buffer. + size_t SizeReadable(log_id_t id) const EXCLUDES(lock_) { + auto lock = std::lock_guard{lock_}; + return mSizes[id]; + } + // TODO: Get rid of this entirely. static size_t sizesTotal() { return SizesTotal; From 3e970d430f8cf8f7794d2901381846ae9df88c56 Mon Sep 17 00:00:00 2001 From: Tom Cherry Date: Wed, 5 Aug 2020 14:01:11 -0700 Subject: [PATCH 2/2] logcat: replace write() calls with WriteFully() There is a possibility of data loss if an interrupt occurs in the middle of these write() calls. Test: logcat -g/-S/-B work correctly Change-Id: I2dd4ec10771714fc49b61538d3028983516e106c --- logcat/logcat.cpp | 16 +++++++++++----- 1 file changed, 11 insertions(+), 5 deletions(-) diff --git a/logcat/logcat.cpp b/logcat/logcat.cpp index b5d2aa44a..6b7e016a4 100644 --- a/logcat/logcat.cpp +++ b/logcat/logcat.cpp @@ -64,6 +64,7 @@ using android::base::ParseByteCount; using android::base::ParseUint; using android::base::Split; using android::base::StringPrintf; +using android::base::WriteFully; class Logcat { public: @@ -864,8 +865,7 @@ int Logcat::Run(int argc, char** argv) { if (consolePipe) { // need the trailing '\0' - if (!android::base::WriteFully(fd, pipePurpose.c_str(), - pipePurpose.size() + 1)) { + if (!WriteFully(fd, pipePurpose.c_str(), pipePurpose.size() + 1)) { close(fd); return EXIT_FAILURE; } @@ -1078,7 +1078,9 @@ int Logcat::Run(int argc, char** argv) { buffer_name, size_format.first, size_format.second, consumed_format.first, consumed_format.second, readable_format.first, readable_format.second, (int)LOGGER_ENTRY_MAX_LEN, (int)LOGGER_ENTRY_MAX_PAYLOAD); - TEMP_FAILURE_RETRY(write(output_fd_.get(), str.data(), str.length())); + if (!WriteFully(output_fd_, str.data(), str.length())) { + error(EXIT_FAILURE, errno, "Failed to write to output fd"); + } } } } @@ -1148,7 +1150,9 @@ int Logcat::Run(int argc, char** argv) { if (*cp == '\n') ++cp; size_t len = strlen(cp); - TEMP_FAILURE_RETRY(write(output_fd_.get(), cp, len)); + if (!WriteFully(output_fd_, cp, len)) { + error(EXIT_FAILURE, errno, "Failed to write to output fd"); + } return EXIT_SUCCESS; } @@ -1192,7 +1196,9 @@ If you have enabled significant logging, look into using the -G option to increa PrintDividers(log_msg.id(), printDividers); if (print_binary_) { - TEMP_FAILURE_RETRY(write(output_fd_.get(), &log_msg, log_msg.len())); + if (!WriteFully(output_fd_, &log_msg, log_msg.len())) { + error(EXIT_FAILURE, errno, "Failed to write to output fd"); + } } else { ProcessBuffer(&log_msg); }