Merge //aos/linux_code/logging into //aos/common/logging
Shuffling files+targets to clean it up further is coming next.
Change-Id: Iae716b07b340a66502f8e0964281c10fae0fcb7a
diff --git a/aos/common/logging/BUILD b/aos/common/logging/BUILD
index 78d1cbd..b3e358d 100644
--- a/aos/common/logging/BUILD
+++ b/aos/common/logging/BUILD
@@ -1,5 +1,108 @@
package(default_visibility = ['//visibility:public'])
+cc_library(
+ name = 'log_replay',
+ srcs = [
+ 'log_replay.cc',
+ ],
+ hdrs = [
+ 'log_replay.h',
+ ],
+ deps = [
+ ':binary_log_file',
+ '//aos/common:queues',
+ '//aos/common/logging',
+ '//aos/linux_code/ipc_lib:queue',
+ ],
+)
+
+cc_binary(
+ name = 'binary_log_writer',
+ srcs = [
+ 'binary_log_writer.cc',
+ ],
+ deps = [
+ '//aos/common/logging',
+ '//aos/linux_code:init',
+ '//aos/linux_code:configuration',
+ '//aos/common:die',
+ ':binary_log_file',
+ '//aos/common:queue_types',
+ ],
+)
+
+cc_binary(
+ name = 'log_streamer',
+ srcs = [
+ 'log_streamer.cc',
+ ],
+ deps = [
+ '//aos/common/logging',
+ '//aos/linux_code:init',
+ '//aos/common:time',
+ '//aos/linux_code/ipc_lib:queue',
+ ],
+)
+
+cc_binary(
+ name = 'log_displayer',
+ srcs = [
+ 'log_displayer.cc',
+ ],
+ deps = [
+ '//aos/common/logging',
+ '//aos/linux_code:init',
+ ':binary_log_file',
+ '//aos/common:queue_types',
+ '//aos/linux_code:configuration',
+ '//aos/common/util:string_to_num',
+ ],
+)
+
+cc_library(
+ name = 'binary_log_file',
+ srcs = [
+ 'binary_log_file.cc',
+ ],
+ hdrs = [
+ 'binary_log_file.h',
+ ],
+ deps = [
+ '//aos/common/logging',
+ ],
+)
+
+cc_library(
+ name = 'linux_interface',
+ visibility = ['//aos/common/logging:__pkg__'],
+ srcs = [
+ 'linux_interface.cc',
+ ],
+ deps = [
+ '//aos/linux_code:complex_thread_local',
+ '//aos/common:die',
+ '//aos/common/logging:context',
+ ],
+)
+
+cc_library(
+ name = 'linux_logging',
+ visibility = [
+ '//aos/linux_code:__subpackages__'
+ ],
+ hdrs = [
+ 'linux_logging.h',
+ ],
+ srcs = [
+ 'linux_logging.cc',
+ ],
+ deps = [
+ '//aos/linux_code/ipc_lib:queue',
+ '//aos/common:time',
+ '//aos/common/logging:logging',
+ ],
+)
+
cc_test(
name = 'logging_impl_test',
srcs = [
@@ -74,7 +177,7 @@
deps = [
'//aos/common:die',
'//aos/common/libc:aos_strerror',
- '//aos/linux_code/logging:linux_interface',
+ '//aos/common/logging:linux_interface',
'//aos/common:macros',
],
)
diff --git a/aos/common/logging/binary_log_file.cc b/aos/common/logging/binary_log_file.cc
new file mode 100644
index 0000000..be58e11
--- /dev/null
+++ b/aos/common/logging/binary_log_file.cc
@@ -0,0 +1,263 @@
+#include "aos/common/logging/binary_log_file.h"
+
+#include <stdio.h>
+#include <string.h>
+#include <sys/mman.h>
+#include <sys/stat.h>
+#include <unistd.h>
+#include <signal.h>
+#include <setjmp.h>
+
+namespace aos {
+namespace logging {
+namespace linux_code {
+namespace {
+
+unsigned long SystemPageSize() {
+ static unsigned long r = sysconf(_SC_PAGESIZE);
+ return r;
+}
+
+} // namespace
+
+LogFileAccessor::LogFileAccessor(int fd, bool writable)
+ : fd_(fd), writable_(writable), offset_(0), current_(0), position_(0) {
+ // Check to make sure that mmap will allow mmaping in chunks of kPageSize.
+ if (SystemPageSize() > kPageSize || (kPageSize % SystemPageSize()) != 0) {
+ LOG(FATAL, "system page size (%lu) not factor of kPageSize (%zd).\n",
+ SystemPageSize(), kPageSize);
+ }
+
+ MapNextPage();
+}
+
+void LogFileAccessor::Sync() const {
+ msync(current_, kPageSize, MS_ASYNC | MS_INVALIDATE);
+}
+
+void LogFileAccessor::SkipToLastSeekablePage() {
+ CHECK(definitely_use_mmap());
+
+ struct stat info;
+ if (fstat(fd_, &info) == -1) {
+ PLOG(FATAL, "fstat(%d, %p) failed", fd_, &info);
+ }
+
+ CHECK((info.st_size % kPageSize) == 0);
+ const auto last_readable_page_number = (info.st_size / kPageSize) - 1;
+ const auto last_seekable_page_number =
+ last_readable_page_number / kSeekPages * kSeekPages;
+ const off_t new_offset = last_seekable_page_number * kPageSize;
+ // We don't want to go backwards...
+ if (new_offset > offset_) {
+ Unmap(current_);
+ offset_ = new_offset;
+ MapNextPage();
+ }
+}
+
+// The only way to tell is using fstat, but we don't really want to be making a
+// syscall every single time somebody wants to know the answer, so it gets
+// cached in is_last_page_.
+bool LogFileAccessor::IsLastPage() {
+ if (is_last_page_ != Maybe::kUnknown) {
+ return is_last_page_ == Maybe::kYes;
+ }
+
+ struct stat info;
+ if (fstat(fd_, &info) == -1) {
+ PLOG(FATAL, "fstat(%d, %p) failed", fd_, &info);
+ }
+ bool r = offset_ == static_cast<off_t>(info.st_size - kPageSize);
+ is_last_page_ = r ? Maybe::kYes : Maybe::kNo;
+ return r;
+}
+
+void LogFileAccessor::MapNextPage() {
+ if (writable_) {
+ if (ftruncate(fd_, offset_ + kPageSize) == -1) {
+ PLOG(FATAL, "ftruncate(%d, %zd) failed", fd_, kPageSize);
+ }
+ }
+
+ if (use_read_ == Maybe::kYes) {
+ ssize_t todo = kPageSize;
+ while (todo > 0) {
+ ssize_t result = read(fd_, current_ + (kPageSize - todo), todo);
+ if (result == -1) {
+ PLOG(FATAL, "read(%d, %p, %zu) failed", fd_,
+ current_ + (kPageSize - todo), todo);
+ } else if (result == 0) {
+ memset(current_, 0, todo);
+ result = todo;
+ }
+ todo -= result;
+ }
+ CHECK_EQ(0, todo);
+ } else {
+ current_ = static_cast<char *>(
+ mmap(NULL, kPageSize, PROT_READ | (writable_ ? PROT_WRITE : 0),
+ MAP_SHARED, fd_, offset_));
+ if (current_ == MAP_FAILED) {
+ if (!writable_ && use_read_ == Maybe::kUnknown && errno == ENODEV) {
+ LOG(INFO, "Falling back to reading the file using read(2).\n");
+ use_read_ = Maybe::kYes;
+ current_ = new char[kPageSize];
+ MapNextPage();
+ return;
+ } else {
+ PLOG(FATAL,
+ "mmap(NULL, %zd, PROT_READ [ | PROT_WRITE], MAP_SHARED, %d, %jd)"
+ " failed",
+ kPageSize, fd_, static_cast<intmax_t>(offset_));
+ }
+ } else {
+ use_read_ = Maybe::kNo;
+ }
+ if (madvise(current_, kPageSize, MADV_SEQUENTIAL | MADV_WILLNEED) == -1) {
+ PLOG(WARNING, "madvise(%p, %zd, MADV_SEQUENTIAL | MADV_WILLNEED) failed",
+ current_, kPageSize);
+ }
+ }
+ offset_ += kPageSize;
+}
+
+void LogFileAccessor::Unmap(void *location) {
+ CHECK_NE(Maybe::kUnknown, use_read_);
+
+ if (use_read_ == Maybe::kNo) {
+ if (munmap(location, kPageSize) == -1) {
+ PLOG(FATAL, "munmap(%p, %zd) failed", location, kPageSize);
+ }
+ }
+ is_last_page_ = Maybe::kUnknown;
+ position_ = 0;
+}
+
+const LogFileMessageHeader *LogFileReader::ReadNextMessage(bool wait) {
+ LogFileMessageHeader *r;
+ do {
+ r = static_cast<LogFileMessageHeader *>(
+ static_cast<void *>(¤t()[position()]));
+ if (wait) {
+ CHECK(definitely_use_mmap());
+ if (futex_wait(&r->marker) != 0) continue;
+ }
+ if (r->marker == 2) {
+ Unmap(current());
+ MapNextPage();
+ CheckCurrentPageReadable();
+ r = static_cast<LogFileMessageHeader *>(static_cast<void *>(current()));
+ }
+ } while (wait && r->marker == 0);
+ if (r->marker == 0) {
+ return NULL;
+ }
+ IncrementPosition(sizeof(LogFileMessageHeader) + r->name_size +
+ r->message_size);
+ if (position() >= kPageSize) {
+ // It's a lot better to blow up here rather than getting SIGBUS errors the
+ // next time we try to read...
+ LOG(FATAL, "corrupt log file running over page size\n");
+ }
+ return r;
+}
+
+// This mess is because the only not completely hackish way to do this is to set
+// up a handler for SIGBUS/SIGSEGV that siglongjmps out to avoid either the
+// instruction being repeated infinitely (and more signals being delivered) or
+// (with SA_RESETHAND) the signal killing the process.
+namespace {
+
+void *volatile fault_address;
+sigjmp_buf jump_context;
+
+void CheckCurrentPageReadableHandler(int /*signal*/, siginfo_t *info, void *) {
+ fault_address = info->si_addr;
+
+ siglongjmp(jump_context, 1);
+}
+
+} // namespace
+void LogFileReader::CheckCurrentPageReadable() {
+ if (definitely_use_read()) return;
+
+ if (sigsetjmp(jump_context, 1) == 0) {
+ struct sigaction action;
+ action.sa_sigaction = CheckCurrentPageReadableHandler;
+ sigemptyset(&action.sa_mask);
+ action.sa_flags = SA_RESETHAND | SA_SIGINFO;
+ struct sigaction previous_bus, previous_segv;
+ if (sigaction(SIGBUS, &action, &previous_bus) == -1) {
+ PLOG(FATAL, "sigaction(SIGBUS(=%d), %p, %p) failed",
+ SIGBUS, &action, &previous_bus);
+ }
+ if (sigaction(SIGSEGV, &action, &previous_segv) == -1) {
+ PLOG(FATAL, "sigaction(SIGSEGV(=%d), %p, %p) failed",
+ SIGSEGV, &action, &previous_segv);
+ }
+
+ char __attribute__((unused)) c = current()[0];
+
+ if (sigaction(SIGBUS, &previous_bus, NULL) == -1) {
+ PLOG(FATAL, "sigaction(SIGBUS(=%d), %p, NULL) failed",
+ SIGBUS, &previous_bus);
+ }
+ if (sigaction(SIGSEGV, &previous_segv, NULL) == -1) {
+ PLOG(FATAL, "sigaction(SIGSEGV(=%d), %p, NULL) failed",
+ SIGSEGV, &previous_segv);
+ }
+ } else {
+ if (fault_address == current()) {
+ LOG(FATAL, "could not read 1 byte at offset 0x%jx into log file\n",
+ static_cast<uintmax_t>(offset()));
+ } else {
+ LOG(FATAL, "faulted at %p, not %p like we were (maybe) supposed to\n",
+ fault_address, current());
+ }
+ }
+}
+
+LogFileMessageHeader *LogFileWriter::GetWritePosition(size_t message_size) {
+ if (NeedNewPageFor(message_size)) ForceNewPage();
+ LogFileMessageHeader *const r = static_cast<LogFileMessageHeader *>(
+ static_cast<void *>(¤t()[position()]));
+ IncrementPosition(message_size);
+ return r;
+}
+
+// A number of seekable pages, not the actual file offset, is stored in *cookie.
+bool LogFileWriter::ShouldClearSeekableData(off_t *cookie,
+ size_t next_message_size) const {
+ off_t next_message_page = (offset() / kPageSize) - 1;
+ if (NeedNewPageFor(next_message_size)) {
+ ++next_message_page;
+ }
+ const off_t current_seekable_page = next_message_page / kSeekPages;
+ CHECK_LE(*cookie, current_seekable_page);
+ const bool r = *cookie != current_seekable_page;
+ *cookie = current_seekable_page;
+ return r;
+}
+
+bool LogFileWriter::NeedNewPageFor(size_t bytes) const {
+ return position() + bytes + (kAlignment - (bytes % kAlignment)) +
+ sizeof(aos_futex) >
+ kPageSize;
+}
+
+void LogFileWriter::ForceNewPage() {
+ char *const temp = current();
+ MapNextPage();
+ if (futex_set_value(
+ static_cast<aos_futex *>(static_cast<void *>(&temp[position()])),
+ 2) == -1) {
+ PLOG(WARNING, "readers will hang because futex_set_value(%p, 2) failed",
+ &temp[position()]);
+ }
+ Unmap(temp);
+}
+
+} // namespace linux_code
+} // namespace logging
+} // namespace aos
diff --git a/aos/common/logging/binary_log_file.h b/aos/common/logging/binary_log_file.h
new file mode 100644
index 0000000..b753699
--- /dev/null
+++ b/aos/common/logging/binary_log_file.h
@@ -0,0 +1,207 @@
+#ifndef AOS_COMMON_LOGGING_BINARY_LOG_FILE_H_
+#define AOS_COMMON_LOGGING_BINARY_LOG_FILE_H_
+
+#include <sys/types.h>
+#include <stddef.h>
+#include <stdint.h>
+
+#include <algorithm>
+
+#include "aos/common/logging/logging_impl.h"
+
+namespace aos {
+namespace logging {
+namespace linux_code {
+
+// What to align messages to. A macro because it gets used in attributes.
+// This definition gets #undefed later. Use LogFileAccessor::kAlignment instead.
+#define MESSAGE_ALIGNMENT 8
+
+// File format: {
+// LogFileMessageHeader header;
+// char *name; // of the process that wrote the message
+// void *message;
+// } not crossing kPageSize boundaries into the file and aligned to
+// MESSAGE_ALIGNMENT.
+//
+// Field sizes designed to fit the various values from LogMessage even on
+// other machines (hopefully) because they're baked into the files. They are
+// layed out so that all of the fields are aligned even though the whole thing
+// is packed.
+//
+// A lot of the fields don't have comments because they're the same as the
+// identically named fields in LogMessage.
+struct __attribute__((aligned(MESSAGE_ALIGNMENT))) __attribute__((packed))
+ LogFileMessageHeader {
+ // Represents the type of an individual message.
+ enum class MessageType : uint16_t {
+ // char[] (no '\0' on the end).
+ kString,
+ kStructType,
+ kStruct,
+ kMatrix,
+ };
+
+ // Gets futex_set once this one has been written
+ // for readers keeping up with a live writer.
+ //
+ // Gets initialized to 0 by ftruncate.
+ //
+ // There will be something here after the last message on a "page" set to 2
+ // (by the futex_set) to indicate that the next message is on the next page.
+ aos_futex marker;
+ static_assert(sizeof(marker) == 4, "mutex changed size!");
+ static_assert(MESSAGE_ALIGNMENT >= alignof(aos_futex),
+ "MESSAGE_ALIGNMENT is too small");
+
+ uint32_t time_sec;
+ static_assert(sizeof(time_sec) >= sizeof(LogMessage::seconds),
+ "tv_sec won't fit");
+ uint32_t time_nsec;
+ static_assert(sizeof(time_nsec) >= sizeof(LogMessage::nseconds),
+ "tv_nsec won't fit");
+
+ int32_t source;
+ static_assert(sizeof(source) >= sizeof(LogMessage::source), "PIDs won't fit");
+
+ // Both including all of the bytes in that part of the message.
+ uint32_t name_size, message_size;
+
+ uint16_t sequence;
+ static_assert(sizeof(sequence) == sizeof(LogMessage::sequence),
+ "something changed");
+
+ MessageType type;
+
+ log_level level;
+ static_assert(sizeof(level) == 1, "log_level changed size!");
+};
+static_assert(std::is_pod<LogFileMessageHeader>::value,
+ "LogFileMessageHeader will to get dumped to a file");
+static_assert(offsetof(LogFileMessageHeader, marker) == 0,
+ "marker has to be at the start so readers can find it");
+
+// Handles the mmapping and munmapping for reading and writing log files.
+class LogFileAccessor {
+ public:
+ LogFileAccessor(int fd, bool writable);
+ ~LogFileAccessor() {
+ if (use_read_ == Maybe::kYes) {
+ delete[] current_;
+ }
+ }
+
+ // Asynchronously syncs all open mappings.
+ void Sync() const;
+
+ // Returns true iff we currently have the last page in the file mapped.
+ // This is fundamentally a racy question, so the return value may not be
+ // accurate by the time this method returns.
+ bool IsLastPage();
+
+ // Skips to the last page which is an even multiple of kSeekPages.
+ // This is fundamentally racy, so it may not actually be on the very last
+ // possible multiple of kSeekPages when it returns, but it should be close.
+ // This will never move backwards.
+ void SkipToLastSeekablePage();
+
+ size_t file_offset(const void *msg) {
+ return offset() + (static_cast<const char *>(msg) - current());
+ }
+
+ protected:
+ // The size of the chunks that get mmaped/munmapped together. Large enough so
+ // that not too much space is wasted and it's hopefully bigger than and a
+ // multiple of the system page size but small enough so that really large
+ // chunks of memory don't have to get mapped at the same time.
+ static const size_t kPageSize = 16384;
+ // What to align messages to, copied into an actual constant.
+ static const size_t kAlignment = MESSAGE_ALIGNMENT;
+#undef MESSAGE_ALIGNMENT
+ // Pages which are multiples of this from the beginning of a file start with
+ // no saved state (ie struct types). This allows seeking immediately to the
+ // largest currently written interval of this number when following.
+ static const size_t kSeekPages = 256;
+
+ char *current() const { return current_; }
+ size_t position() const { return position_; }
+ off_t offset() const { return offset_; }
+
+ void IncrementPosition(size_t size) {
+ position_ += size;
+ AlignPosition();
+ }
+
+ void MapNextPage();
+ void Unmap(void *location);
+
+ // Advances position to the next (aligned) location.
+ void AlignPosition() {
+ position_ += kAlignment - (position_ % kAlignment);
+ }
+
+ protected:
+ bool definitely_use_read() const { return use_read_ == Maybe::kYes; }
+ bool definitely_use_mmap() const { return use_read_ == Maybe::kNo; }
+
+ private:
+ // Used for representing things that we might know to be true/false or we
+ // might not know (yet).
+ enum class Maybe { kUnknown, kYes, kNo };
+
+ const int fd_;
+ const bool writable_;
+
+ // Into the file. Always a multiple of kPageSize.
+ off_t offset_;
+ char *current_;
+ size_t position_;
+
+ Maybe is_last_page_ = Maybe::kUnknown;
+
+ // Use read instead of mmap (necessary for fds that don't support mmap).
+ Maybe use_read_ = Maybe::kUnknown;
+};
+
+class LogFileReader : public LogFileAccessor {
+ public:
+ LogFileReader(int fd) : LogFileAccessor(fd, false) {}
+
+ // May return NULL iff wait is false.
+ const LogFileMessageHeader *ReadNextMessage(bool wait);
+
+ private:
+ // Tries reading from the current page to see if it fails because the file
+ // isn't big enough.
+ void CheckCurrentPageReadable();
+};
+
+class LogFileWriter : public LogFileAccessor {
+ public:
+ LogFileWriter(int fd) : LogFileAccessor(fd, true) {}
+
+ // message_size should be the total number of bytes needed for the message.
+ LogFileMessageHeader *GetWritePosition(size_t message_size);
+
+ // Returns true exactly once for each unique cookie on each page where cached
+ // data should be cleared.
+ // Call with a non-zero next_message_size to determine if cached data should
+ // be forgotten before writing a next_message_size-sized message.
+ // cookie should be initialized to 0.
+ bool ShouldClearSeekableData(off_t *cookie, size_t next_message_size) const;
+
+ // Forces a move to a new page for the next message.
+ // This is important when there is cacheable data that needs to be re-written
+ // before a message which will spill over onto the next page but the cacheable
+ // message being refreshed is smaller and won't get to a new page by itself.
+ void ForceNewPage();
+
+ private:
+ bool NeedNewPageFor(size_t bytes) const;
+};
+
+} // namespace linux_code
+} // namespace logging
+} // namespace aos
+
+#endif // AOS_COMMON_LOGGING_BINARY_LOG_FILE_H_
diff --git a/aos/common/logging/binary_log_writer.cc b/aos/common/logging/binary_log_writer.cc
new file mode 100644
index 0000000..d4e6685
--- /dev/null
+++ b/aos/common/logging/binary_log_writer.cc
@@ -0,0 +1,311 @@
+#include <stdio.h>
+#include <stdlib.h>
+#include <errno.h>
+#include <time.h>
+#include <string.h>
+#include <string>
+#include <unistd.h>
+#include <sys/types.h>
+#include <pwd.h>
+#include <fcntl.h>
+#include <dirent.h>
+#include <mntent.h>
+
+#include <map>
+#include <unordered_set>
+
+#include "aos/common/logging/linux_logging.h"
+#include "aos/common/logging/binary_log_file.h"
+#include "aos/linux_code/init.h"
+#include "aos/linux_code/configuration.h"
+#include "aos/common/queue_types.h"
+#include "aos/common/die.h"
+
+namespace aos {
+namespace logging {
+namespace linux_code {
+namespace {
+
+void CheckTypeWritten(uint32_t type_id, LogFileWriter *writer,
+ ::std::unordered_set<uint32_t> *written_type_ids) {
+ if (written_type_ids->count(type_id) > 0) return;
+ if (MessageType::IsPrimitive(type_id)) return;
+
+ const MessageType &type = type_cache::Get(type_id);
+ for (int i = 0; i < type.number_fields; ++i) {
+ CheckTypeWritten(type.fields[i]->type, writer, written_type_ids);
+ }
+
+ char buffer[1024];
+ ssize_t size = type.Serialize(buffer, sizeof(buffer));
+ if (size == -1) {
+ LOG(WARNING, "%zu-byte buffer is too small to serialize type %s\n",
+ sizeof(buffer), type.name.c_str());
+ return;
+ }
+ LogFileMessageHeader *const output =
+ writer->GetWritePosition(sizeof(LogFileMessageHeader) + size);
+
+ output->time_sec = output->time_nsec = 0;
+ output->source = getpid();
+ output->name_size = 0;
+ output->sequence = 0;
+ output->level = FATAL;
+
+ memcpy(output + 1, buffer, size);
+ output->message_size = size;
+
+ output->type = LogFileMessageHeader::MessageType::kStructType;
+ futex_set(&output->marker);
+
+ written_type_ids->insert(type_id);
+}
+
+void AllocateLogName(char **filename, const char *directory) {
+ int fileindex = 0;
+ DIR *const d = opendir(directory);
+ if (d == nullptr) {
+ PDie("could not open directory %s", directory);
+ }
+ int index = 0;
+ while (true) {
+ errno = 0;
+ struct dirent *const dir = readdir(d);
+ if (dir == nullptr) {
+ if (errno == 0) {
+ break;
+ } else {
+ PLOG(FATAL, "readdir(%p) failed", d);
+ }
+ } else {
+ if (sscanf(dir->d_name, "aos_log-%d", &index) == 1) {
+ if (index >= fileindex) {
+ fileindex = index + 1;
+ }
+ }
+ }
+ }
+ closedir(d);
+
+ char previous[512];
+ ::std::string path = ::std::string(directory) + "/aos_log-current";
+ ssize_t len = ::readlink(path.c_str(), previous, sizeof(previous));
+ if (len != -1) {
+ previous[len] = '\0';
+ } else {
+ previous[0] = '\0';
+ LOG(INFO, "Could not find aos_log-current\n");
+ printf("Could not find aos_log-current\n");
+ }
+ if (asprintf(filename, "%s/aos_log-%03d", directory, fileindex) == -1) {
+ PDie("couldn't create final name");
+ }
+ LOG(INFO, "Created log file (aos_log-%d) in directory (%s). Previous file "
+ "was (%s).\n",
+ fileindex, directory, previous);
+ printf("Created log file (aos_log-%d) in directory (%s). Previous file was "
+ "(%s).\n",
+ fileindex, directory, previous);
+}
+
+#ifdef AOS_ARCHITECTURE_arm_frc
+bool FoundThumbDrive(const char *path) {
+ FILE *mnt_fp = setmntent("/etc/mtab", "r");
+ if (mnt_fp == nullptr) {
+ Die("Could not open /etc/mtab");
+ }
+
+ bool found = false;
+ struct mntent mntbuf;
+ char buf[256];
+ while (!found) {
+ struct mntent *mount_list = getmntent_r(mnt_fp, &mntbuf, buf, sizeof(buf));
+ if (mount_list == nullptr) {
+ break;
+ }
+ if (strcmp(mount_list->mnt_dir, path) == 0) {
+ found = true;
+ }
+ }
+ endmntent(mnt_fp);
+ return found;
+}
+
+bool FindDevice(char *device, size_t device_size) {
+ char test_device[10];
+ for (char i = 'a'; i < 'z'; ++i) {
+ snprintf(test_device, sizeof(test_device), "/dev/sd%c", i);
+ LOG(INFO, "Trying to access %s\n", test_device);
+ if (access(test_device, F_OK) != -1) {
+ snprintf(device, device_size, "sd%c", i);
+ return true;
+ }
+ }
+ return false;
+}
+#endif
+
+int BinaryLogReaderMain() {
+ InitNRT();
+
+#ifdef AOS_ARCHITECTURE_arm_frc
+ char folder[128];
+
+ {
+ char dev_name[8];
+ while (!FindDevice(dev_name, sizeof(dev_name))) {
+ LOG(INFO, "Waiting for a device\n");
+ printf("Waiting for a device\n");
+ sleep(5);
+ }
+ snprintf(folder, sizeof(folder), "/media/%s1", dev_name);
+ while (!FoundThumbDrive(folder)) {
+ LOG(INFO, "Waiting for %s\n", folder);
+ printf("Waiting for %s\n", folder);
+ sleep(1);
+ }
+ snprintf(folder, sizeof(folder), "/media/%s1/", dev_name);
+ }
+
+ if (access(folder, F_OK) == -1) {
+#else
+ const char *folder = configuration::GetLoggingDirectory();
+ if (access(folder, R_OK | W_OK) == -1) {
+#endif
+ LOG(FATAL, "folder '%s' does not exist. please create it\n", folder);
+ }
+ LOG(INFO, "logging to folder '%s'\n", folder);
+
+ char *tmp;
+ AllocateLogName(&tmp, folder);
+ char *tmp2;
+ if (asprintf(&tmp2, "%s/aos_log-current", folder) == -1) {
+ PLOG(WARNING, "couldn't create current symlink name");
+ } else {
+ if (unlink(tmp2) == -1 && (errno != EROFS && errno != ENOENT)) {
+ LOG(WARNING, "unlink('%s') failed", tmp2);
+ }
+ if (symlink(tmp, tmp2) == -1) {
+ PLOG(WARNING, "symlink('%s', '%s') failed", tmp, tmp2);
+ }
+ free(tmp2);
+ }
+ int fd = open(tmp, O_SYNC | O_APPEND | O_RDWR | O_CREAT,
+ S_IRUSR | S_IWUSR | S_IRGRP | S_IWGRP | S_IROTH | S_IWOTH);
+ free(tmp);
+ if (fd == -1) {
+ PLOG(FATAL, "opening file '%s' failed", tmp);
+ }
+ LogFileWriter writer(fd);
+
+ ::std::unordered_set<uint32_t> written_type_ids;
+ off_t clear_type_ids_cookie = 0;
+
+ while (true) {
+ const LogMessage *const msg = ReadNext();
+ if (msg == NULL) continue;
+
+ const size_t raw_output_length =
+ sizeof(LogFileMessageHeader) + msg->name_length + msg->message_length;
+ size_t output_length = raw_output_length;
+ if (msg->type == LogMessage::Type::kStruct) {
+ output_length += sizeof(msg->structure.type_id) + sizeof(uint32_t) +
+ msg->structure.string_length;
+ if (writer.ShouldClearSeekableData(&clear_type_ids_cookie,
+ output_length)) {
+ writer.ForceNewPage();
+ written_type_ids.clear();
+ }
+ CheckTypeWritten(msg->structure.type_id, &writer, &written_type_ids);
+ } else if (msg->type == LogMessage::Type::kMatrix) {
+ output_length +=
+ sizeof(msg->matrix.type) + sizeof(uint32_t) + sizeof(uint16_t) +
+ sizeof(uint16_t) + msg->matrix.string_length;
+ CHECK(MessageType::IsPrimitive(msg->matrix.type));
+ }
+ LogFileMessageHeader *const output = writer.GetWritePosition(output_length);
+ char *output_strings = reinterpret_cast<char *>(output) + sizeof(*output);
+ output->name_size = msg->name_length;
+ output->message_size = msg->message_length;
+ output->source = msg->source;
+ output->level = msg->level;
+ output->time_sec = msg->seconds;
+ output->time_nsec = msg->nseconds;
+ output->sequence = msg->sequence;
+ memcpy(output_strings, msg->name, msg->name_length);
+
+ switch (msg->type) {
+ case LogMessage::Type::kString:
+ memcpy(output_strings + msg->name_length, msg->message,
+ msg->message_length);
+ output->type = LogFileMessageHeader::MessageType::kString;
+ break;
+ case LogMessage::Type::kStruct: {
+ char *position = output_strings + msg->name_length;
+
+ memcpy(position, &msg->structure.type_id,
+ sizeof(msg->structure.type_id));
+ position += sizeof(msg->structure.type_id);
+ output->message_size += sizeof(msg->structure.type_id);
+
+ const uint32_t length = msg->structure.string_length;
+ memcpy(position, &length, sizeof(length));
+ position += sizeof(length);
+ memcpy(position, msg->structure.serialized,
+ length + msg->message_length);
+ position += length + msg->message_length;
+ output->message_size += sizeof(length) + length;
+
+ output->type = LogFileMessageHeader::MessageType::kStruct;
+ } break;
+ case LogMessage::Type::kMatrix: {
+ char *position = output_strings + msg->name_length;
+
+ memcpy(position, &msg->matrix.type, sizeof(msg->matrix.type));
+ position += sizeof(msg->matrix.type);
+ output->message_size += sizeof(msg->matrix.type);
+
+ uint32_t length = msg->matrix.string_length;
+ memcpy(position, &length, sizeof(length));
+ position += sizeof(length);
+ output->message_size += sizeof(length);
+
+ uint16_t rows = msg->matrix.rows, cols = msg->matrix.cols;
+ memcpy(position, &rows, sizeof(rows));
+ position += sizeof(rows);
+ memcpy(position, &cols, sizeof(cols));
+ position += sizeof(cols);
+ output->message_size += sizeof(rows) + sizeof(cols);
+ CHECK_EQ(msg->message_length,
+ MessageType::Sizeof(msg->matrix.type) * rows * cols);
+
+ memcpy(position, msg->matrix.data, msg->message_length + length);
+ output->message_size += length;
+
+ output->type = LogFileMessageHeader::MessageType::kMatrix;
+ } break;
+ }
+
+ if (output->message_size - msg->message_length !=
+ output_length - raw_output_length) {
+ LOG(FATAL, "%zu != %zu\n", output->message_size - msg->message_length,
+ output_length - raw_output_length);
+ }
+
+ futex_set(&output->marker);
+
+ logging::linux_code::Free(msg);
+ }
+
+ Cleanup();
+ return 0;
+}
+
+} // namespace
+} // namespace linux_code
+} // namespace logging
+} // namespace aos
+
+int main() {
+ return ::aos::logging::linux_code::BinaryLogReaderMain();
+}
diff --git a/aos/common/logging/linux_interface.cc b/aos/common/logging/linux_interface.cc
new file mode 100644
index 0000000..dff48e1
--- /dev/null
+++ b/aos/common/logging/linux_interface.cc
@@ -0,0 +1,89 @@
+#include "aos/common/logging/context.h"
+
+#include <string>
+#include <string.h>
+#include <sys/prctl.h>
+#include <sys/types.h>
+#include <unistd.h>
+
+#include "aos/linux_code/complex_thread_local.h"
+#include "aos/common/die.h"
+
+namespace aos {
+namespace logging {
+namespace internal {
+namespace {
+
+// TODO(brians): Differentiate between threads with the same name in the same
+// process.
+
+::std::string GetMyName() {
+ // The maximum number of characters that can make up a thread name.
+ // The docs are unclear if it can be 16 characters with no '\0', so we'll be
+ // safe by adding our own where necessary.
+ static const size_t kThreadNameLength = 16;
+
+ ::std::string process_name(program_invocation_short_name);
+
+ char thread_name_array[kThreadNameLength + 1];
+ if (prctl(PR_GET_NAME, thread_name_array) != 0) {
+ PDie("prctl(PR_GET_NAME, %p) failed", thread_name_array);
+ }
+ thread_name_array[sizeof(thread_name_array) - 1] = '\0';
+ ::std::string thread_name(thread_name_array);
+
+ // If the first bunch of characters are the same.
+ // We cut off comparing at the shorter of the 2 strings because one or the
+ // other often ends up cut off.
+ if (strncmp(thread_name.c_str(), process_name.c_str(),
+ ::std::min(thread_name.length(), process_name.length())) == 0) {
+ // This thread doesn't have an actual name.
+ return process_name;
+ }
+
+ return process_name + '.' + thread_name;
+}
+
+::aos::ComplexThreadLocal<Context> my_context;
+
+// True if we're going to delete the current Context object ASAP. The
+// reason for doing this instead of just deleting them is that tsan (at least)
+// doesn't like it when pthread_atfork handlers do complicated stuff and it's
+// not a great idea anyways.
+thread_local bool delete_current_context(false);
+
+} // namespace
+
+// Used in aos/linux_code/init.cc when a thread's name is changed.
+void ReloadThreadName() {
+ if (my_context.created()) {
+ ::std::string my_name = GetMyName();
+ if (my_name.size() + 1 > sizeof(Context::name)) {
+ Die("logging: process/thread name '%s' is too long\n",
+ my_name.c_str());
+ }
+ strcpy(my_context->name, my_name.c_str());
+ my_context->name_size = my_name.size();
+ }
+}
+
+Context *Context::Get() {
+ if (__builtin_expect(delete_current_context, false)) {
+ my_context.Clear();
+ delete_current_context = false;
+ }
+ if (__builtin_expect(!my_context.created(), false)) {
+ my_context.Create();
+ ReloadThreadName();
+ my_context->source = getpid();
+ }
+ return my_context.get();
+}
+
+void Context::Delete() {
+ delete_current_context = true;
+}
+
+} // namespace internal
+} // namespace logging
+} // namespace aos
diff --git a/aos/common/logging/linux_logging.cc b/aos/common/logging/linux_logging.cc
new file mode 100644
index 0000000..14ce72b
--- /dev/null
+++ b/aos/common/logging/linux_logging.cc
@@ -0,0 +1,145 @@
+#include "aos/common/logging/linux_logging.h"
+
+#include <stdarg.h>
+#include <stdio.h>
+#include <string.h>
+#include <time.h>
+#include <sys/types.h>
+#include <errno.h>
+#include <unistd.h>
+#include <limits.h>
+#include <inttypes.h>
+
+#include <algorithm>
+
+#include "aos/common/die.h"
+#include "aos/common/logging/logging_interface.h"
+#include "aos/linux_code/ipc_lib/queue.h"
+#include "aos/common/time.h"
+
+namespace aos {
+namespace logging {
+namespace linux_code {
+namespace {
+
+RawQueue *queue = NULL;
+
+int dropped_messages = 0;
+::aos::time::Time dropped_start, backoff_start;
+// Wait this long after dropping a message before even trying to write any more.
+constexpr ::aos::time::Time kDropBackoff = ::aos::time::Time::InSeconds(0.1);
+
+LogMessage *GetMessageOrDie() {
+ LogMessage *message = static_cast<LogMessage *>(queue->GetMessage());
+ if (message == NULL) {
+ LOG(FATAL, "%p->GetMessage() failed\n", queue);
+ } else {
+ return message;
+ }
+}
+
+class LinuxQueueLogImplementation : public LogImplementation {
+ __attribute__((format(GOOD_PRINTF_FORMAT_TYPE, 3, 0)))
+ virtual void DoLog(log_level level, const char *format, va_list ap) override {
+ LogMessage *message = GetMessageOrDie();
+ internal::FillInMessage(level, format, ap, message);
+ Write(message);
+ }
+
+ virtual void LogStruct(log_level level, const ::std::string &message_string,
+ size_t size, const MessageType *type,
+ const ::std::function<size_t(char *)> &serialize)
+ override {
+ LogMessage *message = GetMessageOrDie();
+ internal::FillInMessageStructure(level, message_string, size, type,
+ serialize, message);
+ Write(message);
+ }
+
+ virtual void LogMatrix(log_level level, const ::std::string &message_string,
+ uint32_t type_id, int rows, int cols, const void *data)
+ override {
+ LogMessage *message = GetMessageOrDie();
+ internal::FillInMessageMatrix(level, message_string, type_id, rows, cols,
+ data, message);
+ Write(message);
+ }
+};
+
+} // namespace
+
+void Register() {
+ Init();
+
+ queue = RawQueue::Fetch("LoggingQueue", sizeof(LogMessage), 1323, 40000);
+ if (queue == NULL) {
+ Die("logging: couldn't fetch queue\n");
+ }
+
+ AddImplementation(new LinuxQueueLogImplementation());
+}
+
+const LogMessage *ReadNext(Options<RawQueue> flags, int *index) {
+ return static_cast<const LogMessage *>(queue->ReadMessageIndex(flags, index));
+}
+
+const LogMessage *ReadNext() {
+ return ReadNext(RawQueue::kBlock);
+}
+
+const LogMessage *ReadNext(Options<RawQueue> flags) {
+ const LogMessage *r = NULL;
+ do {
+ r = static_cast<const LogMessage *>(queue->ReadMessage(flags));
+ // not blocking means return a NULL if that's what it gets
+ } while ((flags & RawQueue::kBlock) && r == NULL);
+ return r;
+}
+
+LogMessage *Get() {
+ return static_cast<LogMessage *>(queue->GetMessage());
+}
+
+void Free(const LogMessage *msg) {
+ queue->FreeMessage(msg);
+}
+
+void Write(LogMessage *msg) {
+ if (__builtin_expect(dropped_messages > 0, false)) {
+ ::aos::time::Time message_time =
+ ::aos::time::Time(msg->seconds, msg->nseconds);
+ if (message_time - backoff_start < kDropBackoff) {
+ ++dropped_messages;
+ queue->FreeMessage(msg);
+ return;
+ }
+
+ LogMessage *dropped_message = GetMessageOrDie();
+ internal::FillInMessageVarargs(
+ ERROR, dropped_message,
+ "%d logs starting at %" PRId32 ".%" PRId32 " dropped\n",
+ dropped_messages, dropped_start.sec(), dropped_start.nsec());
+ if (queue->WriteMessage(dropped_message, RawQueue::kNonBlock)) {
+ dropped_messages = 0;
+ } else {
+ // Don't even bother trying to write this message because it's not likely
+ // to work and it would be confusing to have one log in the middle of a
+ // string of failures get through.
+ ++dropped_messages;
+ backoff_start = message_time;
+ queue->FreeMessage(msg);
+ return;
+ }
+ }
+ if (!queue->WriteMessage(msg, RawQueue::kNonBlock)) {
+ if (dropped_messages == 0) {
+ dropped_start = backoff_start =
+ ::aos::time::Time(msg->seconds, msg->nseconds);
+ }
+ ++dropped_messages;
+ }
+}
+
+} // namespace linux_code
+} // namespace logging
+} // namespace aos
diff --git a/aos/common/logging/linux_logging.h b/aos/common/logging/linux_logging.h
new file mode 100644
index 0000000..3f74fa8
--- /dev/null
+++ b/aos/common/logging/linux_logging.h
@@ -0,0 +1,34 @@
+#ifndef AOS_COMMON_LOGGING_LINUX_LOGGING_H_
+#define AOS_COMMON_LOGGING_LINUX_LOGGING_H_
+
+#include "aos/common/logging/logging_impl.h"
+#include "aos/common/util/options.h"
+
+namespace aos {
+
+class RawQueue;
+
+namespace logging {
+namespace linux_code {
+
+// Calls AddImplementation to register the usual linux logging implementation
+// which sends the messages through a queue. This implementation relies on
+// another process(es) to read the log messages that it puts into the queue.
+// This function is usually called by aos::Init*.
+void Register();
+
+// Fairly simple wrappers around the raw queue calls.
+
+// This one never returns NULL if flags contains BLOCK.
+const LogMessage *ReadNext(Options<RawQueue> flags);
+const LogMessage *ReadNext(Options<RawQueue> flags, int *index);
+const LogMessage *ReadNext();
+LogMessage *Get();
+void Free(const LogMessage *msg);
+void Write(LogMessage *msg);
+
+} // namespace linux_code
+} // namespace logging
+} // namespace aos
+
+#endif // AOS_COMMON_LOGGING_LINUX_LOGGING_H_
diff --git a/aos/common/logging/log_displayer.cc b/aos/common/logging/log_displayer.cc
new file mode 100644
index 0000000..70d2ad5
--- /dev/null
+++ b/aos/common/logging/log_displayer.cc
@@ -0,0 +1,410 @@
+#include <stdio.h>
+#include <stdlib.h>
+#include <string.h>
+#include <getopt.h>
+#include <sys/types.h>
+#include <sys/stat.h>
+#include <fcntl.h>
+#include <inttypes.h>
+
+#include <algorithm>
+#include <memory>
+#include <string>
+
+#include "aos/linux_code/configuration.h"
+#include "aos/common/logging/binary_log_file.h"
+#include "aos/common/queue_types.h"
+#include "aos/common/logging/logging_impl.h"
+#include "aos/common/logging/logging_printf_formats.h"
+#include "aos/common/util/string_to_num.h"
+
+using ::aos::logging::linux_code::LogFileMessageHeader;
+
+namespace {
+
+const char *kArgsHelp = "[OPTION]... [FILE]\n"
+ "Display log file FILE (created by BinaryLogReader) to stdout.\n"
+ "FILE is \"aos_log-current\" by default.\n"
+ "FILE can also be \"-\" to read from standard input.\n"
+ "\n"
+ " -n, --name-prefix NAME "
+ "only display entries from processes which share NAME as a prefix\n"
+ " -N, --name NAME only display entries from processes named NAME\n"
+ " -l, --level LEVEL "
+ "only display log entries at least as important as LEVEL\n"
+ " -p, --pid PID only display log entries from process PID\n"
+ " -f, --follow "
+ "wait when the end of the file is reached (implies --end)\n"
+ " -t, --terminate stop when the end of file is reached (default)\n"
+ " -b, --beginning start at the beginning of the file (default)\n"
+ " -e, --end start at the end of the file\n"
+ " -s, --skip NUMBER skip NUMBER matching logs\n"
+ " -m, --max NUMBER only display up to NUMBER logs\n"
+ " // -o, --format FORMAT use FORMAT to display log entries\n"
+ " -h, --help display this help and exit\n"
+ "\n"
+ "LEVEL must be DEBUG, INFO, WARNING, ERROR, or FATAL.\n"
+ " It defaults to INFO.\n"
+ "\n"
+ "TODO(brians) implement the commented out ones.\n";
+
+const char *kExampleUsages = "To view logs from the shooter:\n"
+ "\t`log_displayer -n shooter`\n"
+ "To view debug logs from the shooter:\n"
+ "\t`log_displayer -n shooter -l DEBUG`\n"
+ "To view what the shooter is logging in realtime:\n"
+ "\t`log_displayer -f -n shooter`\n"
+ "To view shooter logs from an old log file:\n"
+ "\t`log_displayer aos_log-<number> -n shooter`\n"
+ "To view the statuses of the shooter hall effects in realtime:\n"
+ "\t`log_displayer -f -n shooter -l DEBUG | grep .Position`\n";
+
+void PrintHelpAndExit() {
+ fprintf(stderr, "Usage: %s %s", program_invocation_name, kArgsHelp);
+ fprintf(stderr, "\nExample usages:\n\n%s", kExampleUsages);
+
+ // Get the possible executables from start_list.txt.
+ FILE *start_list = fopen("start_list.txt", "r");
+ if (!start_list) {
+ ::std::string path(::aos::configuration::GetRootDirectory());
+ path += "/start_list.txt";
+ start_list = fopen(path.c_str(), "r");
+ if (!start_list) {
+ printf("\nCannot open start_list.txt. This means that the\n"
+ "possible arguments for the -n option cannot be shown. log_displayer\n"
+ "looks for start_list.txt in the current working directory and in\n"
+ "%s.\n\n", ::aos::configuration::GetRootDirectory());
+ PLOG(FATAL, "Unable to open start_list.txt");
+ }
+ }
+
+ // Get file size.
+ if (fseek(start_list, 0, SEEK_END)) {
+ PLOG(FATAL, "fseek() failed while reading start_list.txt");
+ }
+ int size = ftell(start_list);
+ if (size < 0) {
+ PLOG(FATAL, "ftell() failed while reading start_list.txt");
+ }
+ rewind(start_list);
+
+ ::std::unique_ptr<char[]> contents(new char[size + 1]);
+ if (contents == NULL) {
+ LOG(FATAL, "malloc() failed while reading start_list.txt.\n");
+ }
+ size_t bytes_read = fread(contents.get(), 1, size, start_list);
+ if (bytes_read < static_cast<size_t>(size)) {
+ LOG(FATAL, "Read %zu bytes from start_list.txt, expected %d.\n",
+ bytes_read, size);
+ }
+
+ // printf doesn't like strings without the \0.
+ contents[size] = '\0';
+ fprintf(stderr, "\nPossible arguments for the -n option:\n%s", contents.get());
+
+ if (fclose(start_list)) {
+ LOG(FATAL, "fclose() failed.\n");
+ }
+
+ exit(EXIT_SUCCESS);
+}
+
+} // namespace
+
+int main(int argc, char **argv) {
+ const char *filter_name = nullptr, *filter_exact_name = nullptr;
+ size_t filter_length = 0;
+ log_level filter_level = INFO;
+ bool follow = false;
+ // Whether we need to skip everything until we get to the end of the file.
+ bool skip_to_end = false;
+ const char *filename = "aos_log-current";
+ int display_max = 0;
+ int32_t source_pid = -1;
+
+ ::aos::logging::Init();
+ ::aos::logging::AddImplementation(
+ new ::aos::logging::StreamLogImplementation(stdout));
+
+ while (true) {
+ static struct option long_options[] = {
+ {"name-prefix", required_argument, NULL, 'n'},
+ {"name", required_argument, NULL, 'N'},
+ {"level", required_argument, NULL, 'l'},
+ {"pid", required_argument, NULL, 'p'},
+
+ {"follow", no_argument, NULL, 'f'},
+ {"terminate", no_argument, NULL, 't'},
+ {"beginning", no_argument, NULL, 'b'},
+ {"end", no_argument, NULL, 'e'},
+ {"skip", required_argument, NULL, 's'},
+ {"max", required_argument, NULL, 'm'},
+
+ {"format", required_argument, NULL, 'o'},
+
+ {"help", no_argument, NULL, 'h'},
+ {0, 0, 0, 0}
+ };
+ int option_index = 0;
+
+ const int c = getopt_long(argc, argv, "N:n:l:p:fts:m:o:h",
+ long_options, &option_index);
+ if (c == -1) { // if we're at the end
+ break;
+ }
+ switch (c) {
+ case 0:
+ fputs("LogDisplayer: got a 0 option but didn't set up any\n", stderr);
+ abort();
+ case 'n':
+ filter_name = optarg;
+ filter_exact_name = nullptr;
+ filter_length = strlen(filter_name);
+ break;
+ case 'N':
+ filter_exact_name = optarg;
+ filter_name = nullptr;
+ filter_length = strlen(filter_name);
+ break;
+ case 'l':
+ filter_level = ::aos::logging::str_log(optarg);
+ if (filter_level == LOG_UNKNOWN) {
+ fprintf(stderr, "LogDisplayer: unknown log level '%s'\n", optarg);
+ exit(EXIT_FAILURE);
+ }
+ break;
+ case 'p':
+ if (!::aos::util::StringToNumber(::std::string(optarg), &source_pid)) {
+ fprintf(stderr, "ERROR: -p expects a number, not '%s'.\n", optarg);
+ exit(EXIT_FAILURE);
+ }
+ if (source_pid < 0) {
+ fprintf(stderr, "LogDisplayer: invalid pid '%s'\n", optarg);
+ exit(EXIT_FAILURE);
+ }
+ break;
+ case 'f':
+ follow = true;
+ skip_to_end = true;
+ break;
+ case 't':
+ follow = false;
+ break;
+ case 'b':
+ skip_to_end = false;
+ break;
+ case 'e':
+ skip_to_end = true;
+ break;
+ case 'm':
+ if (!::aos::util::StringToNumber(::std::string(optarg), &display_max)) {
+ fprintf(stderr, "ERROR: -m expects a number, not '%s'.\n", optarg);
+ exit(EXIT_FAILURE);
+ }
+ if (display_max <= 0) {
+ fprintf(stderr, "LogDisplayer: invalid max log number '%s'\n",
+ optarg);
+ exit(EXIT_FAILURE);
+ }
+ break;
+ case 'o':
+ abort();
+ break;
+ case 'h':
+ PrintHelpAndExit();
+ break;
+ case '?':
+ break;
+ default:
+ fprintf(stderr, "LogDisplayer: in a bad spot (%s: %d)\n",
+ __FILE__, __LINE__);
+ abort();
+ }
+ }
+
+ if (optind < argc) {
+ // We got a filename.
+ filename = argv[optind++];
+ }
+ if (optind < argc) {
+ fputs("non-option ARGV-elements: ", stderr);
+ while (optind < argc) {
+ fprintf(stderr, "%s\n", argv[optind++]);
+ }
+ }
+
+ int fd;
+ if (strcmp(filename, "-") == 0) {
+ if (skip_to_end) {
+ fputs("Can't skip to end of stdin!\n", stderr);
+ return EXIT_FAILURE;
+ }
+ fd = STDIN_FILENO;
+ } else {
+ fd = open(filename, O_RDONLY);
+ }
+
+ fprintf(stderr, "displaying down to level %s from file '%s'\n",
+ ::aos::logging::log_str(filter_level), filename);
+
+ if (fd == -1) {
+ PLOG(FATAL, "couldn't open file '%s' for reading", filename);
+ }
+ ::aos::logging::linux_code::LogFileReader reader(fd);
+
+ if (skip_to_end) {
+ fputs("skipping old logs...\n", stderr);
+ reader.SkipToLastSeekablePage();
+ }
+
+ const LogFileMessageHeader *msg;
+ int displayed = 0;
+ do {
+ msg = reader.ReadNextMessage(follow);
+ if (msg == NULL) {
+ fputs("reached end of file\n", stderr);
+ return 0;
+ }
+
+ if (msg->type == LogFileMessageHeader::MessageType::kStructType) {
+ size_t bytes = msg->message_size;
+ ::aos::MessageType *type = ::aos::MessageType::Deserialize(
+ reinterpret_cast<const char *>(msg + 1), &bytes);
+ if (type == nullptr) {
+ LOG(INFO, "Trying old version of type decoding.\n");
+ bytes = msg->message_size;
+ type = ::aos::MessageType::Deserialize(
+ reinterpret_cast<const char *>(msg + 1), &bytes, false);
+ }
+
+ if (type == nullptr) {
+ LOG(WARNING, "Error deserializing MessageType of size %" PRIx32
+ " starting at %zx.\n",
+ msg->message_size, reader.file_offset(msg + 1));
+ } else {
+ ::aos::type_cache::Add(*type);
+ }
+ continue;
+ }
+
+ if (source_pid >= 0 && msg->source != source_pid) {
+ // Message is from the wrong process.
+ continue;
+ }
+
+ if (skip_to_end) {
+ if (reader.IsLastPage()) {
+ fputs("done skipping old logs\n", stderr);
+ skip_to_end = false;
+ } else {
+ continue;
+ }
+ }
+
+ if (::aos::logging::log_gt_important(filter_level, msg->level)) continue;
+
+ const char *position =
+ reinterpret_cast<const char *>(msg + 1);
+
+ if (filter_name != nullptr) {
+ const size_t compare_length =
+ ::std::min<size_t>(filter_length, msg->name_size);
+ if (memcmp(filter_name, position, compare_length) != 0) {
+ continue;
+ }
+ if (compare_length < msg->name_size) {
+ if (position[compare_length] != '.') continue;
+ }
+ }
+
+ if (filter_exact_name != nullptr) {
+ if (filter_length != msg->name_size) continue;
+ if (memcmp(filter_exact_name, position, filter_length) != 0) {
+ continue;
+ }
+ }
+
+ if (display_max && displayed++ >= display_max) {
+ fputs("Not displaying the rest of the messages.\n", stderr);
+ return 0;
+ }
+
+ position += msg->name_size;
+
+#define BASE_ARGS \
+ AOS_LOGGING_BASE_ARGS( \
+ msg->name_size, reinterpret_cast<const char *>(msg + 1), msg->source, \
+ msg->sequence, msg->level, msg->time_sec, msg->time_nsec)
+ switch (msg->type) {
+ case LogFileMessageHeader::MessageType::kString:
+ fprintf(stdout, AOS_LOGGING_BASE_FORMAT "%.*s", BASE_ARGS,
+ static_cast<int>(msg->message_size), position);
+ break;
+ case LogFileMessageHeader::MessageType::kStruct: {
+ uint32_t type_id;
+ memcpy(&type_id, position, sizeof(type_id));
+ position += sizeof(type_id);
+
+ uint32_t string_length;
+ memcpy(&string_length, position, sizeof(string_length));
+ position += sizeof(string_length);
+
+ char buffer[2048];
+ size_t output_length = sizeof(buffer);
+ size_t input_length =
+ msg->message_size -
+ (sizeof(type_id) + sizeof(uint32_t) + string_length);
+ if (!PrintMessage(buffer, &output_length, position + string_length,
+ &input_length, ::aos::type_cache::Get(type_id))) {
+ LOG(FATAL, "printing message (%.*s) of type %s into %zu-byte buffer "
+ "failed\n",
+ static_cast<int>(string_length), position,
+ ::aos::type_cache::Get(type_id).name.c_str(), sizeof(buffer));
+ }
+ if (input_length > 0) {
+ LOG(WARNING, "%zu extra bytes on message of type %s\n",
+ input_length, ::aos::type_cache::Get(type_id).name.c_str());
+ }
+ fprintf(stdout, AOS_LOGGING_BASE_FORMAT "%.*s: %.*s\n", BASE_ARGS,
+ static_cast<int>(string_length), position,
+ static_cast<int>(sizeof(buffer) - output_length), buffer);
+ } break;
+ case LogFileMessageHeader::MessageType::kMatrix: {
+ uint32_t type;
+ memcpy(&type, position, sizeof(type));
+ position += sizeof(type);
+
+ uint32_t string_length;
+ memcpy(&string_length, position, sizeof(string_length));
+ position += sizeof(string_length);
+
+ uint16_t rows;
+ memcpy(&rows, position, sizeof(rows));
+ position += sizeof(rows);
+ uint16_t cols;
+ memcpy(&cols, position, sizeof(cols));
+ position += sizeof(cols);
+
+ const size_t matrix_bytes =
+ msg->message_size -
+ (sizeof(type) + sizeof(uint32_t) + sizeof(uint16_t) +
+ sizeof(uint16_t) + string_length);
+ CHECK_EQ(matrix_bytes, ::aos::MessageType::Sizeof(type) * rows * cols);
+ char buffer[2048];
+ size_t output_length = sizeof(buffer);
+ if (!::aos::PrintMatrix(buffer, &output_length,
+ position + string_length, type, rows, cols)) {
+ LOG(FATAL, "printing %dx%d matrix of type %" PRIu32 " failed\n", rows,
+ cols, type);
+ }
+ fprintf(stdout, AOS_LOGGING_BASE_FORMAT "%.*s: %.*s\n", BASE_ARGS,
+ static_cast<int>(string_length), position,
+ static_cast<int>(sizeof(buffer) - output_length), buffer);
+ } break;
+ case LogFileMessageHeader::MessageType::kStructType:
+ LOG(FATAL, "shouldn't get here\n");
+ break;
+ }
+#undef BASE_ARGS
+ } while (msg != NULL);
+}
diff --git a/aos/common/logging/log_replay.cc b/aos/common/logging/log_replay.cc
new file mode 100644
index 0000000..a1efcca
--- /dev/null
+++ b/aos/common/logging/log_replay.cc
@@ -0,0 +1,44 @@
+#include "aos/common/logging/log_replay.h"
+
+namespace aos {
+namespace logging {
+namespace linux_code {
+
+bool LogReplayer::ProcessMessage() {
+ const LogFileMessageHeader *message = reader_->ReadNextMessage(false);
+ if (message == nullptr) return true;
+ if (message->type != LogFileMessageHeader::MessageType::kStruct) return false;
+
+ const char *position = reinterpret_cast<const char *>(message + 1);
+
+ ::std::string process(position, message->name_size);
+ position += message->name_size;
+
+ uint32_t type_id;
+ memcpy(&type_id, position, sizeof(type_id));
+ position += sizeof(type_id);
+
+ uint32_t message_length;
+ memcpy(&message_length, position, sizeof(message_length));
+ position += sizeof(message_length);
+ ::std::string message_text(position, message_length);
+ position += message_length;
+
+ size_t split_index = message_text.find_first_of(':') + 2;
+ split_index = message_text.find_first_of(':', split_index) + 2;
+ message_text = message_text.substr(split_index);
+
+ auto handler = handlers_.find(Key(process, message_text));
+ if (handler == handlers_.end()) return false;
+
+ handler->second->HandleStruct(
+ ::aos::time::Time(message->time_sec, message->time_nsec), type_id,
+ position,
+ message->message_size -
+ (sizeof(type_id) + sizeof(message_length) + message_length));
+ return false;
+}
+
+} // namespace linux_code
+} // namespace logging
+} // namespace aos
diff --git a/aos/common/logging/log_replay.h b/aos/common/logging/log_replay.h
new file mode 100644
index 0000000..6fb230c
--- /dev/null
+++ b/aos/common/logging/log_replay.h
@@ -0,0 +1,164 @@
+#ifndef AOS_COMMON_LOGGING_LOG_REPLAY_H_
+#define AOS_COMMON_LOGGING_LOG_REPLAY_H_
+
+#include <unordered_map>
+#include <string>
+#include <functional>
+#include <memory>
+
+#include "aos/common/logging/binary_log_file.h"
+#include "aos/common/queue.h"
+#include "aos/common/logging/logging.h"
+#include "aos/common/macros.h"
+#include "aos/linux_code/ipc_lib/queue.h"
+#include "aos/common/queue_types.h"
+
+namespace aos {
+namespace logging {
+namespace linux_code {
+
+// Manages pulling logged queue messages out of log files.
+//
+// Basic usage:
+// - Use the Add* methods to register handlers for various message sources.
+// - Call OpenFile to open a log file.
+// - Call ProcessMessage repeatedly until it returns true.
+//
+// This code could do something to adapt similar-but-not-identical
+// messages to the current versions, but currently it will LOG(FATAL) if any of
+// the messages don't match up exactly.
+class LogReplayer {
+ public:
+ LogReplayer() {}
+
+ // Gets ready to read messages from fd.
+ // Does not take ownership of fd.
+ void OpenFile(int fd) {
+ reader_.reset(new LogFileReader(fd));
+ }
+ // Closes the currently open file.
+ void CloseCurrentFile() { reader_.reset(); }
+ // Returns true if we have a file which is currently open.
+ bool HasCurrentFile() const { return reader_.get() != nullptr; }
+
+ // Processes a single message from the currently open file.
+ // Returns true if there are no more messages in the file.
+ // This will not call any of the handlers if the next message either has no
+ // registered handlers or is not a queue message.
+ bool ProcessMessage();
+
+ // Adds a handler for messages with a certain string from a certain process.
+ // T must be a Message with the same format as the messages generated by
+ // the .q files.
+ // LOG(FATAL)s for duplicate handlers.
+ template <class T>
+ void AddHandler(const ::std::string &process_name,
+ const ::std::string &log_message,
+ ::std::function<void(const T &message)> handler) {
+ CHECK(handlers_.emplace(
+ ::std::piecewise_construct,
+ ::std::forward_as_tuple(process_name, log_message),
+ ::std::forward_as_tuple(::std::unique_ptr<StructHandlerInterface>(
+ new TypedStructHandler<T>(handler)))).second);
+ }
+
+ // Adds a handler which takes messages and places them directly on a queue.
+ // T must be a Message with the same format as the messages generated by
+ // the .q files.
+ template <class T>
+ void AddDirectQueueSender(const ::std::string &process_name,
+ const ::std::string &log_message,
+ const ::aos::Queue<T> &queue) {
+ AddHandler(process_name, log_message,
+ ::std::function<void(const T &)>(
+ QueueDumpStructHandler<T>(queue.name())));
+ }
+
+ private:
+ // A generic handler of struct log messages.
+ class StructHandlerInterface {
+ public:
+ virtual ~StructHandlerInterface() {}
+
+ virtual void HandleStruct(::aos::time::Time log_time, uint32_t type_id,
+ const void *data, size_t data_size) = 0;
+ };
+
+ // Converts struct log messages to a message type and passes it to an
+ // ::std::function.
+ template <class T>
+ class TypedStructHandler : public StructHandlerInterface {
+ public:
+ TypedStructHandler(::std::function<void(const T &message)> handler)
+ : handler_(handler) {}
+
+ void HandleStruct(::aos::time::Time log_time, uint32_t type_id,
+ const void *data, size_t data_size) override {
+ CHECK_EQ(type_id, T::GetType()->id);
+ T message;
+ CHECK_EQ(data_size, T::Size());
+ CHECK_EQ(data_size, message.Deserialize(static_cast<const char *>(data)));
+ message.sent_time = log_time;
+ handler_(message);
+ }
+
+ private:
+ const ::std::function<void(T message)> handler_;
+ };
+
+ // A callable class which dumps messages straight to a queue.
+ template <class T>
+ class QueueDumpStructHandler {
+ public:
+ QueueDumpStructHandler(const ::std::string &queue_name)
+ : queue_(RawQueue::Fetch(queue_name.c_str(), sizeof(T), T::kHash,
+ T::kQueueLength)) {}
+
+ void operator()(const T &message) {
+ LOG_STRUCT(DEBUG, "re-sending", message);
+ void *raw_message = queue_->GetMessage();
+ CHECK_NOTNULL(raw_message);
+ memcpy(raw_message, &message, sizeof(message));
+ CHECK(queue_->WriteMessage(raw_message, RawQueue::kOverride));
+ }
+
+ private:
+ ::aos::RawQueue *const queue_;
+ };
+
+ // A key for specifying log messages to give to a certain handler.
+ struct Key {
+ Key(const ::std::string &process_name, const ::std::string &log_message)
+ : process_name(process_name), log_message(log_message) {}
+
+ ::std::string process_name;
+ ::std::string log_message;
+ };
+
+ struct KeyHash {
+ size_t operator()(const Key &key) const {
+ return string_hash(key.process_name) ^
+ (string_hash(key.log_message) << 1);
+ }
+
+ private:
+ const ::std::hash<::std::string> string_hash = ::std::hash<::std::string>();
+ };
+ struct KeyEqual {
+ bool operator()(const Key &a, const Key &b) const {
+ return a.process_name == b.process_name && a.log_message == b.log_message;
+ }
+ };
+
+ ::std::unordered_map<const Key, ::std::unique_ptr<StructHandlerInterface>,
+ KeyHash, KeyEqual> handlers_;
+ ::std::unique_ptr<LogFileReader> reader_;
+
+ DISALLOW_COPY_AND_ASSIGN(LogReplayer);
+};
+
+} // namespace linux_code
+} // namespace logging
+} // namespace aos
+
+#endif // AOS_COMMON_LOGGING_LOG_REPLAY_H_
diff --git a/aos/common/logging/log_streamer.cc b/aos/common/logging/log_streamer.cc
new file mode 100644
index 0000000..506a92b
--- /dev/null
+++ b/aos/common/logging/log_streamer.cc
@@ -0,0 +1,51 @@
+#include <stdio.h>
+#include <stdlib.h>
+#include <errno.h>
+#include <time.h>
+#include <string.h>
+#include <string>
+#include <unistd.h>
+#include <sys/types.h>
+#include <pwd.h>
+#include <fcntl.h>
+#include <inttypes.h>
+
+#include "aos/common/logging/linux_logging.h"
+#include "aos/linux_code/init.h"
+#include "aos/linux_code/ipc_lib/queue.h"
+#include "aos/common/logging/logging_impl.h"
+#include "aos/common/time.h"
+
+namespace aos {
+namespace logging {
+namespace linux_code {
+namespace {
+
+int LogStreamerMain() {
+ InitNRT();
+
+ const time::Time now = time::Time::Now();
+ printf("starting at %" PRId32 "s%" PRId32 "ns-----------------------------\n",
+ now.sec(), now.nsec());
+
+ while (true) {
+ const LogMessage *const msg = ReadNext();
+ if (msg == NULL) continue;
+
+ internal::PrintMessage(stdout, *msg);
+
+ logging::linux_code::Free(msg);
+ }
+
+ Cleanup();
+ return 0;
+}
+
+} // namespace
+} // namespace linux_code
+} // namespace logging
+} // namespace aos
+
+int main() {
+ return ::aos::logging::linux_code::LogStreamerMain();
+}