diff options
Diffstat (limited to 'util/posix_logger.h')
| -rw-r--r-- | util/posix_logger.h | 166 |
1 files changed, 99 insertions, 67 deletions
diff --git a/util/posix_logger.h b/util/posix_logger.h index 9741b1a..6bbc1a0 100644 --- a/util/posix_logger.h +++ b/util/posix_logger.h @@ -8,89 +8,121 @@ #ifndef STORAGE_LEVELDB_UTIL_POSIX_LOGGER_H_ #define STORAGE_LEVELDB_UTIL_POSIX_LOGGER_H_ -#include <algorithm> -#include <stdio.h> #include <sys/time.h> -#include <time.h> + +#include <cassert> +#include <cstdarg> +#include <cstdio> +#include <ctime> +#include <sstream> +#include <thread> + #include "leveldb/env.h" namespace leveldb { -class PosixLogger : public Logger { - private: - FILE* file_; - uint64_t (*gettid_)(); // Return the thread id for the current thread +class PosixLogger final : public Logger { public: - PosixLogger(FILE* f, uint64_t (*gettid)()) : file_(f), gettid_(gettid) { } - virtual ~PosixLogger() { - fclose(file_); - } - virtual void Logv(const char* format, va_list ap) { - const uint64_t thread_id = (*gettid_)(); - - // We try twice: the first time with a fixed-size stack allocated buffer, - // and the second time with a much larger dynamically allocated buffer. - char buffer[500]; - for (int iter = 0; iter < 2; iter++) { - char* base; - int bufsize; - if (iter == 0) { - bufsize = sizeof(buffer); - base = buffer; - } else { - bufsize = 30000; - base = new char[bufsize]; - } - char* p = base; - char* limit = base + bufsize; - - struct timeval now_tv; - gettimeofday(&now_tv, NULL); - const time_t seconds = now_tv.tv_sec; - struct tm t; - localtime_r(&seconds, &t); - p += snprintf(p, limit - p, - "%04d/%02d/%02d-%02d:%02d:%02d.%06d %llx ", - t.tm_year + 1900, - t.tm_mon + 1, - t.tm_mday, - t.tm_hour, - t.tm_min, - t.tm_sec, - static_cast<int>(now_tv.tv_usec), - static_cast<long long unsigned int>(thread_id)); - - // Print the message - if (p < limit) { - va_list backup_ap; - va_copy(backup_ap, ap); - p += vsnprintf(p, limit - p, format, backup_ap); - va_end(backup_ap); - } + // Creates a logger that writes to the given file. + // + // The PosixLogger instance takes ownership of the file handle. + explicit PosixLogger(std::FILE* fp) : fp_(fp) { assert(fp != nullptr); } + + ~PosixLogger() override { std::fclose(fp_); } + + void Logv(const char* format, std::va_list arguments) override { + // Record the time as close to the Logv() call as possible. + struct ::timeval now_timeval; + ::gettimeofday(&now_timeval, nullptr); + const std::time_t now_seconds = now_timeval.tv_sec; + struct std::tm now_components; + ::localtime_r(&now_seconds, &now_components); + + // Record the thread ID. + constexpr const int kMaxThreadIdSize = 32; + std::ostringstream thread_stream; + thread_stream << std::this_thread::get_id(); + std::string thread_id = thread_stream.str(); + if (thread_id.size() > kMaxThreadIdSize) { + thread_id.resize(kMaxThreadIdSize); + } - // Truncate to available space if necessary - if (p >= limit) { - if (iter == 0) { - continue; // Try again with larger buffer - } else { - p = limit - 1; + // We first attempt to print into a stack-allocated buffer. If this attempt + // fails, we make a second attempt with a dynamically allocated buffer. + constexpr const int kStackBufferSize = 512; + char stack_buffer[kStackBufferSize]; + static_assert(sizeof(stack_buffer) == static_cast<size_t>(kStackBufferSize), + "sizeof(char) is expected to be 1 in C++"); + + int dynamic_buffer_size = 0; // Computed in the first iteration. + for (int iteration = 0; iteration < 2; ++iteration) { + const int buffer_size = + (iteration == 0) ? kStackBufferSize : dynamic_buffer_size; + char* const buffer = + (iteration == 0) ? stack_buffer : new char[dynamic_buffer_size]; + + // Print the header into the buffer. + int buffer_offset = std::snprintf( + buffer, buffer_size, "%04d/%02d/%02d-%02d:%02d:%02d.%06d %s ", + now_components.tm_year + 1900, now_components.tm_mon + 1, + now_components.tm_mday, now_components.tm_hour, now_components.tm_min, + now_components.tm_sec, static_cast<int>(now_timeval.tv_usec), + thread_id.c_str()); + + // The header can be at most 28 characters (10 date + 15 time + + // 3 delimiters) plus the thread ID, which should fit comfortably into the + // static buffer. + assert(buffer_offset <= 28 + kMaxThreadIdSize); + static_assert(28 + kMaxThreadIdSize < kStackBufferSize, + "stack-allocated buffer may not fit the message header"); + assert(buffer_offset < buffer_size); + + // Print the message into the buffer. + std::va_list arguments_copy; + va_copy(arguments_copy, arguments); + buffer_offset += + std::vsnprintf(buffer + buffer_offset, buffer_size - buffer_offset, + format, arguments_copy); + va_end(arguments_copy); + + // The code below may append a newline at the end of the buffer, which + // requires an extra character. + if (buffer_offset >= buffer_size - 1) { + // The message did not fit into the buffer. + if (iteration == 0) { + // Re-run the loop and use a dynamically-allocated buffer. The buffer + // will be large enough for the log message, an extra newline and a + // null terminator. + dynamic_buffer_size = buffer_offset + 2; + continue; } + + // The dynamically-allocated buffer was incorrectly sized. This should + // not happen, assuming a correct implementation of std::(v)snprintf. + // Fail in tests, recover by truncating the log message in production. + assert(false); + buffer_offset = buffer_size - 1; } - // Add newline if necessary - if (p == base || p[-1] != '\n') { - *p++ = '\n'; + // Add a newline if necessary. + if (buffer[buffer_offset - 1] != '\n') { + buffer[buffer_offset] = '\n'; + ++buffer_offset; } - assert(p <= limit); - fwrite(base, 1, p - base, file_); - fflush(file_); - if (base != buffer) { - delete[] base; + assert(buffer_offset <= buffer_size); + std::fwrite(buffer, 1, buffer_offset, fp_); + std::fflush(fp_); + + if (iteration != 0) { + delete[] buffer; } break; } } + + private: + std::FILE* const fp_; }; } // namespace leveldb |