Google Cloud C++ Client  2.0.0
C++ Client Library for Google Cloud Platform
log.h
Go to the documentation of this file.
1 // Copyright 2018 Google LLC
2 //
3 // Licensed under the Apache License, Version 2.0 (the "License");
4 // you may not use this file except in compliance with the License.
5 // You may obtain a copy of the License at
6 //
7 // https://www.apache.org/licenses/LICENSE-2.0
8 //
9 // Unless required by applicable law or agreed to in writing, software
10 // distributed under the License is distributed on an "AS IS" BASIS,
11 // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
12 // See the License for the specific language governing permissions and
13 // limitations under the License.
14 
15 #ifndef GOOGLE_CLOUD_CPP_GOOGLE_CLOUD_LOG_H
16 #define GOOGLE_CLOUD_CPP_GOOGLE_CLOUD_LOG_H
17 
18 /**
19  * @file log.h
20  *
21  * Google Cloud Platform C++ Libraries logging framework.
22  *
23  * Some of the libraries need to log information to simplify troubleshooting.
24  * The functions and macros used for logging are defined in this file. In
25  * general, we abide by the following principles:
26  *
27  * - Logging should controlled by the application developer. Unless explicitly
28  * instructed, the libraries produce no output to the console, except
29  * to emit a message to `std::clog` immediately before a GCP_LOG(FATAL)
30  * terminates the process.
31  * - Logging should have very low cost:
32  * - It should be possible to disable logs at compile time, they should
33  * disappear as-if there were `#%ifdef`/`#%endif` directives around them.
34  * - A log line at a disabled log level should be about as expensive as an
35  * extra if() statement. At the very least it should not incur additional
36  * memory allocations or locks.
37  * - It should be easy to log complex objects: the logging library should play
38  * well with the C++ iostream classes.
39  * - The application should be able to intercept log records and re-direct them
40  * to their own logging framework.
41  *
42  * @par Example: Logging From Library
43  * Use the `GCP_LOG()` macro to log from a Google Cloud Platform C++ library:
44  *
45  * @code
46  * void LibraryCode(ComplexThing const& thing) {
47  * GCP_LOG(INFO) << "I am here";
48  * if (thing.is_bad()) {
49  * GCP_LOG(ERROR) << "Poor thing is bad: " << thing;
50  * }
51  * }
52  * @endcode
53  *
54  * @par Example: Enable Logs to `std::clog`
55  * To enable logs to `std::clog` the application can call:
56  *
57  * @code
58  * void AppCode() {
59  * google::cloud::LogSink::EnableStdClog();
60  * }
61  * @endcode
62  *
63  * Alternatively, the application can enable logging to `std::clog` without any
64  * code changes or recompiling by setting the "GOOGLE_CLOUD_CPP_ENABLE_CLOG"
65  * environment variable before the program starts. The existence of this
66  * variable is all that matters; the value is ignored.
67  *
68  * Note that while `std::clog` is buffered, the framework will flush any log
69  * message at severity `WARNING` or higher.
70  *
71  * @par Example: Capture Logs
72  * The application can implement simple backends by wrapping a functor:
73  *
74  * @code
75  * void AppCode() {
76  * auto id = google::cloud::LogSink::AttachFunctor(
77  * [](google::cloud::LogRecord record) {
78  * if (record.severity >= google::cloud::Severity::CRITICAL) {
79  * std::cerr << record << "\n";
80  * }
81  * });
82  * // Use "id" to remove the capture.
83  * }
84  * @endcode
85  */
86 
87 #include "google/cloud/version.h"
88 #include "absl/memory/memory.h"
89 #include <atomic>
90 #include <chrono>
91 #include <cstdlib>
92 #include <functional>
93 #include <iostream>
94 #include <map>
95 #include <memory>
96 #include <mutex>
97 #include <sstream>
98 #include <string>
99 #include <thread>
100 
101 namespace google {
102 namespace cloud {
104 /// Concatenate two pre-processor tokens.
105 #define GOOGLE_CLOUD_CPP_PP_CONCAT(a, b) a##b
106 
107 /**
108  * Create a unique, or most likely unique identifier.
109  *
110  * In GCP_LOG() we need an identifier for the logger, we can easily create a C++
111  * scope to make it work with any name, say "foo". However the user may have a
112  * variable called "foo" that they want to use in the scope (for example, to log
113  * the value of "foo". We try to make it unlikely that there will be collision
114  * by using an identifier that has a long prefix and depends on the line number.
115  */
116 #define GOOGLE_CLOUD_CPP_LOGGER_IDENTIFIER
117  GOOGLE_CLOUD_CPP_PP_CONCAT(google_cloud_cpp_log_, __LINE__)
118 
119 /**
120  * The main entry point for the Google Cloud Platform C++ Library loggers.
121  *
122  * Typically this used only in tests, applications should use GCP_LOG(). This
123  * macro introduces a new scope (via the for-loop) with a single new identifier:
124  * GOOGLE_CLOUD_CPP_LOG_RECORD_IDENTIFIER
125  * We use a for-loop (as opposed to an if-statement, or a do-while), because
126  * then we can say:
127  *
128  * @code
129  * GCP_LOG(WARNING) << a << b << c;
130  * @endcode
131  *
132  * and the variables are scoped correctly. The for-loop also affords us an
133  * opportunity to check that the log level is enabled before entering the body
134  * of the loop, and if disabled we can minimize the cost of the log. For
135  * example, disabled logs do not create an iostream at all.
136  *
137  * Finally, the type of the GOOGLE_CLOUD_CPP_LOG_RECORD_IDENTIFIER changes if
138  * the log level is disabled at compile-time. For compile-time disabled log
139  * levels the compiler should be able to determine that the loop will not
140  * execute at all, and completely eliminate the code (we verified this using
141  * godbolt.org with modern GCC and Clang versions).
142  *
143  * Note the use of fully-qualified class names, including the initial `::`, this
144  * is to prevent problems if anybody uses this macro in a context where `Logger`
145  * is defined by the enclosing namespaces.
146  */
147 #define GOOGLE_CLOUD_CPP_LOG_I(level, sink)
148  for (::google::cloud::Logger<::google::cloud::LogSink::CompileTimeEnabled(
149  ::google::cloud::Severity::level)>
151  ::google::cloud::Severity::level, __func__, __FILE__, __LINE__,
152  sink);
156 
157 // Note that we do not use `GOOGLE_CLOUD_CPP_PP_CONCAT` here: we actually want
158 // to concatenate `GCP_LS` with the literal `level`. On some platforms, the
159 // level names are used as macros (e.g., on macOS, `DEBUG` is often a macro with
160 // value 1 for debug builds). If we were to use `GOOGLE_CLOUD_CPP_PP_CONCAT` and
161 // `level` is a a macro, then we would get `GCP_LS_<macro_value>`, i.e.,
162 // `GCP_LS_1` (incorrect) instead of `GCP_LS_DEBUG` (correct).
163 /**
164  * Log a message with the Google Cloud Platform C++ Libraries logging framework.
165  */
166 #define GCP_LOG(level)
167  GOOGLE_CLOUD_CPP_LOG_I(GCP_LS_##level, ::google::cloud::LogSink::Instance())
168 
169 #ifndef GOOGLE_CLOUD_CPP_LOGGING_MIN_SEVERITY_ENABLED
170 #define GOOGLE_CLOUD_CPP_LOGGING_MIN_SEVERITY_ENABLED GCP_LS_DEBUG
171 #endif // GOOGLE_CLOUD_CPP_LOGGING_MIN_SEVERITY_ENABLED
172 
173 /**
174  * Define the severity levels for Google Cloud Platform C++ Libraries logging.
175  *
176  * These are modelled after the severity level in syslog(1) and many derived
177  * tools.
178  *
179  * We force the enum to be represented as an `int` because we will store the
180  * values in an `std::atomic<>` and the implementations usually optimize
181  * `std::atomic<int>` but not `std::atomic<Foo>`
182  */
183 enum class Severity : int {
184  /// Use this level for messages that indicate the code is entering and leaving
185  /// functions.
186  GCP_LS_TRACE, // NOLINT(readability-identifier-naming)
187  /// Use this level for debug messages that should not be present in
188  /// production.
189  GCP_LS_DEBUG,
190  /// Informational messages, such as normal progress.
191  GCP_LS_INFO, // NOLINT(readability-identifier-naming)
192  /// Informational messages, such as unusual, but expected conditions.
193  GCP_LS_NOTICE, // NOLINT(readability-identifier-naming)
194  /// An indication of problems, users may need to take action.
195  GCP_LS_WARNING, // NOLINT(readability-identifier-naming)
196  /// An error has been detected. Do not use for normal conditions, such as
197  /// remote servers disconnecting.
198  GCP_LS_ERROR, // NOLINT(readability-identifier-naming)
199  /// The system is in a critical state, such as running out of local resources.
200  GCP_LS_CRITICAL, // NOLINT(readability-identifier-naming)
201  /// The system is at risk of immediate failure.
202  GCP_LS_ALERT, // NOLINT(readability-identifier-naming)
203  /// The system is unusable. GCP_LOG(FATAL) will call std::abort().
204  GCP_LS_FATAL, // NOLINT(readability-identifier-naming)
205  /// The highest possible severity level.
206  GCP_LS_HIGHEST = GCP_LS_FATAL, // NOLINT(readability-identifier-naming)
207  /// The lowest possible severity level.
208  GCP_LS_LOWEST = GCP_LS_TRACE, // NOLINT(readability-identifier-naming)
209  /// The lowest level that is enabled at compile-time.
210  // NOLINTNEXTLINE(readability-identifier-naming)
212 };
213 
214 /// Streaming operator, writes a human readable representation.
215 std::ostream& operator<<(std::ostream& os, Severity x);
216 
217 /**
218  * Represents a single log message.
219  */
220 struct LogRecord {
222  std::string function;
223  std::string filename;
224  int lineno;
225  std::thread::id thread_id;
226  std::chrono::system_clock::time_point timestamp;
227  std::string message;
228 };
229 
230 /// Default formatting of a LogRecord.
231 std::ostream& operator<<(std::ostream& os, LogRecord const& rhs);
232 
233 /**
234  * The logging backend interface.
235  */
236 class LogBackend {
237  public:
238  virtual ~LogBackend() = default;
239 
240  virtual void Process(LogRecord const& log_record) = 0;
241  virtual void ProcessWithOwnership(LogRecord log_record) = 0;
242  virtual void Flush() {}
243 };
244 
245 /**
246  * A sink to receive log records.
247  */
248 class LogSink {
249  public:
251 
252  /// Return true if the severity is enabled at compile time.
253  static bool constexpr CompileTimeEnabled(Severity level) {
254  return level >= Severity::GCP_LS_LOWEST_ENABLED;
255  }
256 
257  /**
258  * Return the singleton instance for this application.
259  */
260  static LogSink& Instance();
261 
262  /**
263  * Return true if this object has no backends.
264  *
265  * We want to avoid synchronization overhead when checking if a log message is
266  * enabled. Most of the time, most messages will be disabled, so incurring the
267  * locking overhead on each message would be too expensive and would
268  * discourage developers from creating logs. Furthermore, missing a few
269  * messages while the change of state "propagates" to other threads does not
270  * affect the correctness of the program.
271  *
272  * Note that `memory_order_relaxed` does not provide a compiler barrier
273  * either, so in theory stores into the atomic could be reordered by the
274  * optimizer. We have no reason to worry about that because all the writes
275  * are done inside a critical section protected by a mutex. The compiler
276  * cannot (or should not) reorder operations around those.
277  */
278  bool empty() const { return empty_.load(std::memory_order_relaxed); }
279 
280  /**
281  * Return true if @p severity is enabled.
282  *
283  * We want to avoid synchronization overhead when checking if a log message is
284  * enabled. Most of the time, most messages will be disabled, so incurring the
285  * locking overhead on each message would be too expensive and would
286  * discourage developers from creating logs. Furthermore, missing a few
287  * messages while the change of state "propagates" to other threads does not
288  * affect the correctness of the program.
289  *
290  * Note that `memory_order_relaxed` does not provide a compiler barrier
291  * either, so in theory stores into the atomic could be reordered by the
292  * optimizer. We have no reason to worry about that because all the writes
293  * are done inside a critical section protected by a mutex. The compiler
294  * cannot (or should not) reorder operations around those.
295  */
296  bool is_enabled(Severity severity) const {
297  auto minimum = minimum_severity_.load(std::memory_order_relaxed);
298  return static_cast<int>(severity) >= minimum;
299  }
300 
302  minimum_severity_.store(static_cast<int>(minimum));
303  }
305  return static_cast<Severity>(minimum_severity_.load());
306  }
307 
308  // A `long` is perfectly fine here, it is guaranteed to be at least 32-bits
309  // wide, it is unlikely that an application would need more than 2 billion
310  // logging backends during its lifetime. The style guide recommends using
311  // `std::int32_t` for such a use-case, unfortunately I (coryan) picked `long`
312  // before we had tooling to enforce this style guide rule.
313  using BackendId = long; // NOLINT(google-runtime-int)
314 
315  BackendId AddBackend(std::shared_ptr<LogBackend> backend);
316  void RemoveBackend(BackendId id);
318  std::size_t BackendCount() const;
319 
320  void Log(LogRecord log_record);
321 
322  /// Flush all the current backends
323  void Flush();
324 
325  /**
326  * Enable `std::clog` on `LogSink::Instance()`.
327  *
328  * This is also enabled if the "GOOGLE_CLOUD_CPP_ENABLE_CLOG" environment
329  * variable is set.
330  */
331  static void EnableStdClog(
332  Severity min_severity = Severity::GCP_LS_LOWEST_ENABLED) {
333  Instance().EnableStdClogImpl(min_severity);
334  }
335 
336  /**
337  * Disable `std::clog` on `LogSink::Instance()`.
338  *
339  * Note that this will remove the default logging backend.
340  */
341  static void DisableStdClog() { Instance().DisableStdClogImpl(); }
342 
343  private:
344  void EnableStdClogImpl(Severity min_severity);
345  void DisableStdClogImpl();
346  void SetDefaultBackend(std::shared_ptr<LogBackend> backend);
347  BackendId AddBackendImpl(std::shared_ptr<LogBackend> backend);
348  void RemoveBackendImpl(BackendId id);
349 
350  std::map<BackendId, std::shared_ptr<LogBackend>> CopyBackends();
351 
352  std::atomic<bool> empty_;
353  std::atomic<int> minimum_severity_;
354  std::mutex mutable mu_;
355  BackendId next_id_ = 0;
356  BackendId default_backend_id_ = 0;
357  std::map<BackendId, std::shared_ptr<LogBackend>> backends_;
358 };
359 
360 /**
361  * Implements operator<< for all types, without any effect.
362  *
363  * It is desirable to disable at compile-time tracing, debugging, and other low
364  * severity messages. The Google Cloud Platform C++ Libraries logging adaptors
365  * return an object of this class when the particular log-line is disabled at
366  * compile-time.
367  */
368 struct NullStream {
369  /// Generic do-nothing streaming operator
370  template <typename T>
371  NullStream& operator<<(T) {
372  return *this;
373  }
374 };
375 
376 /**
377  * Define the class to capture a log message.
378  *
379  * @tparam CompileTimeEnabled this represents whether the severity has been
380  * disabled at compile-time. The class is specialized for `false` to minimize
381  * the run-time impact of (and, in practice, completely elide) disabled logs.
382  */
383 template <bool CompileTimeEnabled>
384 class Logger {
385  public:
386  Logger(Severity severity, char const* function, char const* filename,
387  int lineno, LogSink& sink)
388  : enabled_(!sink.empty() && sink.is_enabled(severity)),
389  severity_(severity),
390  function_(function),
391  filename_(filename),
392  lineno_(lineno) {}
393 
394  ~Logger() {
395  if (severity_ >= Severity::GCP_LS_FATAL) std::abort();
396  }
397 
398  bool enabled() const { return enabled_; }
399 
400  /// Send the log record captured by this object to @p sink.
401  void LogTo(LogSink& sink) {
402  if (!stream_ || !enabled_) {
403  return;
404  }
405  enabled_ = false;
406  LogRecord record;
407  record.severity = severity_;
408  record.function = function_;
409  record.filename = filename_;
410  record.lineno = lineno_;
411  record.thread_id = std::this_thread::get_id();
412  record.timestamp = std::chrono::system_clock::now();
413  record.message = stream_->str();
414  sink.Log(std::move(record));
415  }
416 
417  /// Return the iostream that captures the log message.
418  std::ostream& Stream() {
419  if (!stream_) stream_ = absl::make_unique<std::ostringstream>();
420  return *stream_;
421  }
422 
423  private:
424  bool enabled_;
425  Severity severity_;
426  char const* function_;
427  char const* filename_;
428  int lineno_;
429  std::unique_ptr<std::ostringstream> stream_;
430 };
431 
432 /**
433  * Define the logger for a disabled log level.
434  */
435 template <>
436 class Logger<false> {
437  public:
438  Logger(Severity severity, char const*, char const*, int, LogSink&)
439  : severity_(severity) {}
440 
441  ~Logger() {
442  if (severity_ >= Severity::GCP_LS_FATAL) std::abort();
443  }
444 
445  //@{
446  /**
447  * @name Provide trivial implementations that meet the generic `Logger<bool>`
448  * interface.
449  */
450  // NOLINTNEXTLINE(readability-convert-member-functions-to-static)
451  bool enabled() const { return false; }
452  void LogTo(LogSink&) {}
453  // NOLINTNEXTLINE(readability-convert-member-functions-to-static)
454  NullStream Stream() { return NullStream(); }
455  //@}
456 
457  private:
458  Severity severity_;
459 };
460 
461 namespace internal {
462 std::shared_ptr<LogBackend> DefaultLogBackend();
463 } // namespace internal
465 } // namespace cloud
466 } // namespace google
467 
468 #endif // GOOGLE_CLOUD_CPP_GOOGLE_CLOUD_LOG_H