1b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson// Copyright 2009 Google Inc. All Rights Reserved.
2b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson
3b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson// Licensed under the Apache License, Version 2.0 (the "License");
4b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson// you may not use this file except in compliance with the License.
5b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson// You may obtain a copy of the License at
6b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson
7b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson//      http://www.apache.org/licenses/LICENSE-2.0
8b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson
9b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson// Unless required by applicable law or agreed to in writing, software
10b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson// distributed under the License is distributed on an "AS IS" BASIS,
11b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
12b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson// See the License for the specific language governing permissions and
13b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson// limitations under the License.
14b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson
15b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson#include "logger.h"
16b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson
17b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson#include <pthread.h>
18b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson#include <stdarg.h>
19b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson#include <stdio.h>
20241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders#include <time.h>
21b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson#include <unistd.h>
22b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson
23b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson#include <string>
24b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson#include <vector>
25b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson
26b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson// This file must work with autoconf on its public version,
27b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson// so these includes are correct.
28b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson#include "sattypes.h"
29b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson
30b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson
31b0114cb9f332db144f65291211ae65f7f0e814e6Scott AndersonLogger *Logger::GlobalLogger() {
32b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  static Logger logger;
33b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  return &logger;
34b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson}
35b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson
36b0114cb9f332db144f65291211ae65f7f0e814e6Scott Andersonvoid Logger::VLogF(int priority, const char *format, va_list args) {
37b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  if (priority > verbosity_) {
38b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson    return;
39b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  }
40b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  char buffer[4096];
41241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders  size_t length = 0;
42241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders  if (log_timestamps_) {
43241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders    time_t raw_time;
44241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders    time(&raw_time);
45241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders    struct tm time_struct;
46241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders    localtime_r(&raw_time, &time_struct);
47241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders    length = strftime(buffer, sizeof(buffer), "%Y/%m/%d-%H:%M:%S(%Z) ",
48241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders                      &time_struct);
49241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders    LOGGER_ASSERT(length);  // Catch if the buffer is set too small.
50241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders  }
51241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders  length += vsnprintf(buffer + length, sizeof(buffer) - length, format, args);
52241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders  if (length >= sizeof(buffer)) {
53241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders    length = sizeof(buffer);
54241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders    buffer[sizeof(buffer) - 1] = '\n';
55b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  }
56b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  QueueLogLine(new string(buffer, length));
57b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson}
58b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson
59b0114cb9f332db144f65291211ae65f7f0e814e6Scott Andersonvoid Logger::StartThread() {
60b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  LOGGER_ASSERT(!thread_running_);
61b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  thread_running_ = true;
62b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  LOGGER_ASSERT(0 == pthread_create(&thread_, NULL, &StartRoutine, this));
63b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson}
64b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson
65b0114cb9f332db144f65291211ae65f7f0e814e6Scott Andersonvoid Logger::StopThread() {
66241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders  // Allow this to be called before the thread has started.
67241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders  if (!thread_running_) {
68241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders    return;
69241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders  }
70b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  thread_running_ = false;
71241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders  int retval = pthread_mutex_lock(&queued_lines_mutex_);
72241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders  LOGGER_ASSERT(0 == retval);
73b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  bool need_cond_signal = queued_lines_.empty();
74b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  queued_lines_.push_back(NULL);
75241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders  retval = pthread_mutex_unlock(&queued_lines_mutex_);
76241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders  LOGGER_ASSERT(0 == retval);
77b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  if (need_cond_signal) {
78241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders    retval = pthread_cond_signal(&queued_lines_cond_);
79241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders    LOGGER_ASSERT(0 == retval);
80b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  }
81241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders  retval = pthread_join(thread_, NULL);
82241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders  LOGGER_ASSERT(0 == retval);
83b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson}
84b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson
85241f33a3e958842e3db803c03300764bd2ee9c19Nick SandersLogger::Logger()
86241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders    : verbosity_(20),
87241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders      log_fd_(-1),
88241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders      thread_running_(false),
89241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders      log_timestamps_(true) {
90b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  LOGGER_ASSERT(0 == pthread_mutex_init(&queued_lines_mutex_, NULL));
91b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  LOGGER_ASSERT(0 == pthread_cond_init(&queued_lines_cond_, NULL));
92b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  LOGGER_ASSERT(0 == pthread_cond_init(&full_queue_cond_, NULL));
93b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson}
94b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson
95b0114cb9f332db144f65291211ae65f7f0e814e6Scott AndersonLogger::~Logger() {
96b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  LOGGER_ASSERT(0 == pthread_mutex_destroy(&queued_lines_mutex_));
97b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  LOGGER_ASSERT(0 == pthread_cond_destroy(&queued_lines_cond_));
98b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  LOGGER_ASSERT(0 == pthread_cond_destroy(&full_queue_cond_));
99b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson}
100b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson
101b0114cb9f332db144f65291211ae65f7f0e814e6Scott Andersonvoid Logger::QueueLogLine(string *line) {
102b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  LOGGER_ASSERT(line != NULL);
103b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  LOGGER_ASSERT(0 == pthread_mutex_lock(&queued_lines_mutex_));
104b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  if (thread_running_) {
105b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson    if (queued_lines_.size() >= kMaxQueueSize) {
106b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson      LOGGER_ASSERT(0 == pthread_cond_wait(&full_queue_cond_,
107b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson                                           &queued_lines_mutex_));
108b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson    }
109b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson    if (queued_lines_.empty()) {
110b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson      LOGGER_ASSERT(0 == pthread_cond_signal(&queued_lines_cond_));
111b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson    }
112b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson    queued_lines_.push_back(line);
113b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  } else {
114b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson    WriteAndDeleteLogLine(line);
115b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  }
116b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  LOGGER_ASSERT(0 == pthread_mutex_unlock(&queued_lines_mutex_));
117b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson}
118b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson
119b0114cb9f332db144f65291211ae65f7f0e814e6Scott Andersonvoid Logger::WriteAndDeleteLogLine(string *line) {
120b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  LOGGER_ASSERT(line != NULL);
121241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders  ssize_t bytes_written;
122b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  if (log_fd_ >= 0) {
123241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders    bytes_written = write(log_fd_, line->data(), line->size());
124241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders    LOGGER_ASSERT(bytes_written == static_cast<ssize_t>(line->size()));
125b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  }
126241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders  bytes_written = write(STDOUT_FILENO, line->data(), line->size());
127241f33a3e958842e3db803c03300764bd2ee9c19Nick Sanders  LOGGER_ASSERT(bytes_written == static_cast<ssize_t>(line->size()));
128b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  delete line;
129b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson}
130b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson
131b0114cb9f332db144f65291211ae65f7f0e814e6Scott Andersonvoid *Logger::StartRoutine(void *ptr) {
132b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  Logger *self = static_cast<Logger*>(ptr);
133b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  self->ThreadMain();
134b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  return NULL;
135b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson}
136b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson
137b0114cb9f332db144f65291211ae65f7f0e814e6Scott Andersonvoid Logger::ThreadMain() {
138b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  vector<string*> local_queue;
139b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  LOGGER_ASSERT(0 == pthread_mutex_lock(&queued_lines_mutex_));
140b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson
141b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  for (;;) {
142b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson    if (queued_lines_.empty()) {
143b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson      LOGGER_ASSERT(0 == pthread_cond_wait(&queued_lines_cond_,
144b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson                                           &queued_lines_mutex_));
145b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson      continue;
146b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson    }
147b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson
148b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson    // We move the log lines into a local queue so we can release the lock
149b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson    // while writing them to disk, preventing other threads from blocking on
150b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson    // our writes.
151b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson    local_queue.swap(queued_lines_);
152b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson    if (local_queue.size() >= kMaxQueueSize) {
153b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson      LOGGER_ASSERT(0 == pthread_cond_broadcast(&full_queue_cond_));
154b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson    }
155b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson
156b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson    // Unlock while we process our local queue.
157b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson    LOGGER_ASSERT(0 == pthread_mutex_unlock(&queued_lines_mutex_));
158b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson    for (vector<string*>::const_iterator it = local_queue.begin();
159b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson         it != local_queue.end(); ++it) {
160b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson      if (*it == NULL) {
161b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson        // NULL is guaranteed to be at the end.
162b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson        return;
163b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson      }
164b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson      WriteAndDeleteLogLine(*it);
165b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson    }
166b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson    local_queue.clear();
167b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson    // We must hold the lock at the start of each iteration of this for loop.
168b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson    LOGGER_ASSERT(0 == pthread_mutex_lock(&queued_lines_mutex_));
169b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson  }
170b0114cb9f332db144f65291211ae65f7f0e814e6Scott Anderson}
171