Skip to content

Commit

Permalink
Clean up posix_logger.h.
Browse files Browse the repository at this point in the history
General cleanup principles:
* Use override when applicable.
* Use const on class members where possible.
* Renames where clarity can be improved.
* Qualify standard library names with std:: when possible, to
  distinguish from POSIX names.
* Qualify POSIX names with the global namespace (::) when possible, to
  distinguish from standard library names.

This also revamps the logic for putting together a message into the
in-memory buffer before that is passed to fwrite(). While correct in
practice, the current implementation advances a char pointer past the
size of its buffer, which is technically undefined behavior.

-------------
Created by MOE: https://github.com/google/moe
MOE_MIGRATED_REVID=211472570
  • Loading branch information
pwnall committed Sep 4, 2018
1 parent 89af27b commit 7b945f2
Showing 1 changed file with 94 additions and 64 deletions.
158 changes: 94 additions & 64 deletions util/posix_logger.h
Original file line number Diff line number Diff line change
Expand Up @@ -8,89 +8,119 @@
#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 <cinttypes>
#include <cstdarg>
#include <cstdio>
#include <ctime>

#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_);
PosixLogger(FILE* fp, uint64_t (*gettid)()) : fp_(fp), gettid_(gettid) {
assert(fp != nullptr);
}

~PosixLogger() override {
std::fclose(fp_);
}
virtual void Logv(const char* format, va_list ap) {

void Logv(const char* format, 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);

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, nullptr);
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);
}
// 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++");

// Truncate to available space if necessary
if (p >= limit) {
if (iter == 0) {
continue; // Try again with larger buffer
} else {
p = limit - 1;
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 = snprintf(
buffer, buffer_size,
"%04d/%02d/%02d-%02d:%02d:%02d.%06d %" PRIx64 " ",
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);

// The header can be at most 48 characters (10 date + 15 time + 3 spacing
// + 20 thread ID), which should fit comfortably into the static buffer.
assert(buffer_offset <= 48);
static_assert(48 < 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 (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_;
uint64_t (* const gettid_)(); // Return the thread id for the current thread.
};

} // namespace leveldb
Expand Down

0 comments on commit 7b945f2

Please sign in to comment.