1 //  Copyright (c) 2011-present, Facebook, Inc.  All rights reserved.
2 //  This source code is licensed under both the GPLv2 (found in the
3 //  COPYING file in the root directory) and Apache 2.0 License
4 //  (found in the LICENSE.Apache file in the root directory).
5 //
6 // Copyright (c) 2011 The LevelDB Authors. All rights reserved.
7 // Use of this source code is governed by a BSD-style license that can be
8 // found in the LICENSE file. See the AUTHORS file for names of contributors.
9 //
10 // Logger implementation that can be shared by all environments
11 // where enough posix functionality is available.
12 
13 #pragma once
14 #include <algorithm>
15 #include <stdio.h>
16 #include "port/sys_time.h"
17 #include <time.h>
18 #include <fcntl.h>
19 
20 #ifdef OS_LINUX
21 #ifndef FALLOC_FL_KEEP_SIZE
22 #include <linux/falloc.h>
23 #endif
24 #endif
25 
26 #include <atomic>
27 #include "env/io_posix.h"
28 #include "monitoring/iostats_context_imp.h"
29 #include "rocksdb/env.h"
30 #include "test_util/sync_point.h"
31 
32 namespace ROCKSDB_NAMESPACE {
33 
34 class PosixLogger : public Logger {
35  private:
PosixCloseHelper()36   Status PosixCloseHelper() {
37     int ret;
38 
39     ret = fclose(file_);
40     if (ret) {
41       return IOError("Unable to close log file", "", ret);
42     }
43     return Status::OK();
44   }
45   FILE* file_;
46   uint64_t (*gettid_)();  // Return the thread id for the current thread
47   std::atomic_size_t log_size_;
48   int fd_;
49   const static uint64_t flush_every_seconds_ = 5;
50   std::atomic_uint_fast64_t last_flush_micros_;
51   Env* env_;
52   std::atomic<bool> flush_pending_;
53 
54  protected:
CloseImpl()55   virtual Status CloseImpl() override { return PosixCloseHelper(); }
56 
57  public:
58   PosixLogger(FILE* f, uint64_t (*gettid)(), Env* env,
59               const InfoLogLevel log_level = InfoLogLevel::ERROR_LEVEL)
Logger(log_level)60       : Logger(log_level),
61         file_(f),
62         gettid_(gettid),
63         log_size_(0),
64         fd_(fileno(f)),
65         last_flush_micros_(0),
66         env_(env),
67         flush_pending_(false) {}
~PosixLogger()68   virtual ~PosixLogger() {
69     if (!closed_) {
70       closed_ = true;
71       PosixCloseHelper().PermitUncheckedError();
72     }
73   }
Flush()74   virtual void Flush() override {
75     TEST_SYNC_POINT("PosixLogger::Flush:Begin1");
76     TEST_SYNC_POINT("PosixLogger::Flush:Begin2");
77     if (flush_pending_) {
78       flush_pending_ = false;
79       fflush(file_);
80     }
81     last_flush_micros_ = env_->NowMicros();
82   }
83 
84   using Logger::Logv;
Logv(const char * format,va_list ap)85   virtual void Logv(const char* format, va_list ap) override {
86     IOSTATS_TIMER_GUARD(logger_nanos);
87 
88     const uint64_t thread_id = (*gettid_)();
89 
90     // We try twice: the first time with a fixed-size stack allocated buffer,
91     // and the second time with a much larger dynamically allocated buffer.
92     char buffer[500];
93     for (int iter = 0; iter < 2; iter++) {
94       char* base;
95       int bufsize;
96       if (iter == 0) {
97         bufsize = sizeof(buffer);
98         base = buffer;
99       } else {
100         bufsize = 65536;
101         base = new char[bufsize];
102       }
103       char* p = base;
104       char* limit = base + bufsize;
105 
106       struct timeval now_tv;
107       gettimeofday(&now_tv, nullptr);
108       const time_t seconds = now_tv.tv_sec;
109       struct tm t;
110       localtime_r(&seconds, &t);
111       p += snprintf(p, limit - p,
112                     "%04d/%02d/%02d-%02d:%02d:%02d.%06d %llx ",
113                     t.tm_year + 1900,
114                     t.tm_mon + 1,
115                     t.tm_mday,
116                     t.tm_hour,
117                     t.tm_min,
118                     t.tm_sec,
119                     static_cast<int>(now_tv.tv_usec),
120                     static_cast<long long unsigned int>(thread_id));
121 
122       // Print the message
123       if (p < limit) {
124         va_list backup_ap;
125         va_copy(backup_ap, ap);
126         p += vsnprintf(p, limit - p, format, backup_ap);
127         va_end(backup_ap);
128       }
129 
130       // Truncate to available space if necessary
131       if (p >= limit) {
132         if (iter == 0) {
133           continue;       // Try again with larger buffer
134         } else {
135           p = limit - 1;
136         }
137       }
138 
139       // Add newline if necessary
140       if (p == base || p[-1] != '\n') {
141         *p++ = '\n';
142       }
143 
144       assert(p <= limit);
145       const size_t write_size = p - base;
146 
147 #ifdef ROCKSDB_FALLOCATE_PRESENT
148       const int kDebugLogChunkSize = 128 * 1024;
149 
150       // If this write would cross a boundary of kDebugLogChunkSize
151       // space, pre-allocate more space to avoid overly large
152       // allocations from filesystem allocsize options.
153       const size_t log_size = log_size_;
154       const size_t last_allocation_chunk =
155         ((kDebugLogChunkSize - 1 + log_size) / kDebugLogChunkSize);
156       const size_t desired_allocation_chunk =
157         ((kDebugLogChunkSize - 1 + log_size + write_size) /
158            kDebugLogChunkSize);
159       if (last_allocation_chunk != desired_allocation_chunk) {
160         fallocate(
161             fd_, FALLOC_FL_KEEP_SIZE, 0,
162             static_cast<off_t>(desired_allocation_chunk * kDebugLogChunkSize));
163       }
164 #endif
165 
166       size_t sz = fwrite(base, 1, write_size, file_);
167       flush_pending_ = true;
168       if (sz > 0) {
169         log_size_ += write_size;
170       }
171       uint64_t now_micros = static_cast<uint64_t>(now_tv.tv_sec) * 1000000 +
172         now_tv.tv_usec;
173       if (now_micros - last_flush_micros_ >= flush_every_seconds_ * 1000000) {
174         Flush();
175       }
176       if (base != buffer) {
177         delete[] base;
178       }
179       break;
180     }
181   }
GetLogFileSize()182   size_t GetLogFileSize() const override { return log_size_; }
183 };
184 
185 }  // namespace ROCKSDB_NAMESPACE
186