YugabyteDB (2.13.1.0-b60, 21121d69985fbf76aa6958d8f04a9bfa936293b5)

Coverage Report

Created: 2022-03-22 16:43

/Users/deen/code/yugabyte-db/src/yb/util/logging.h
Line
Count
Source (jump to first uncovered line)
1
// Licensed to the Apache Software Foundation (ASF) under one
2
// or more contributor license agreements.  See the NOTICE file
3
// distributed with this work for additional information
4
// regarding copyright ownership.  The ASF licenses this file
5
// to you under the Apache License, Version 2.0 (the
6
// "License"); you may not use this file except in compliance
7
// with the License.  You may obtain a copy of the License at
8
//
9
//   http://www.apache.org/licenses/LICENSE-2.0
10
//
11
// Unless required by applicable law or agreed to in writing,
12
// software distributed under the License is distributed on an
13
// "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
14
// KIND, either express or implied.  See the License for the
15
// specific language governing permissions and limitations
16
// under the License.
17
//
18
// Licensed under the Apache License, Version 2.0 (the "License");
19
// you may not use this file except in compliance with the License.
20
// You may obtain a copy of the License at
21
//
22
// http://www.apache.org/licenses/LICENSE-2.0
23
//
24
// Unless required by applicable law or agreed to in writing, software
25
// distributed under the License is distributed on an "AS IS" BASIS,
26
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
27
// See the License for the specific language governing permissions and
28
// limitations under the License.
29
//
30
// The following only applies to changes made to this file as part of YugaByte development.
31
//
32
// Portions Copyright (c) YugaByte, Inc.
33
//
34
// Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except
35
// in compliance with the License.  You may obtain a copy of the License at
36
//
37
// http://www.apache.org/licenses/LICENSE-2.0
38
//
39
// Unless required by applicable law or agreed to in writing, software distributed under the License
40
// is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express
41
// or implied.  See the License for the specific language governing permissions and limitations
42
// under the License.
43
44
#ifndef YB_UTIL_LOGGING_H
45
#define YB_UTIL_LOGGING_H
46
47
#include <mutex>
48
#include <string>
49
50
#include <boost/preprocessor/cat.hpp>
51
#include <boost/preprocessor/stringize.hpp>
52
#include <glog/logging.h>
53
54
#include "yb/gutil/atomicops.h"
55
#include "yb/gutil/dynamic_annotations.h"
56
#include "yb/gutil/walltime.h"
57
58
#include "yb/util/logging_callback.h"
59
#include "yb/util/monotime.h"
60
61
////////////////////////////////////////////////////////////////////////////////
62
// Throttled logging support
63
////////////////////////////////////////////////////////////////////////////////
64
65
// Logs a message throttled to appear at most once every 'n_secs' seconds to
66
// the given severity.
67
//
68
// The log message may include the special token 'THROTTLE_MSG' which expands
69
// to either an empty string or '[suppressed <n> similar messages]'.
70
//
71
// Example usage:
72
//   YB_LOG_EVERY_N_SECS(WARNING, 1) << "server is low on memory" << THROTTLE_MSG;
73
#define YB_LOG_EVERY_N_SECS(severity, n_secs) \
74
11.0M
  static yb::logging_internal::LogThrottler LOG_THROTTLER;  \
75
11.0M
  int num_suppressed = 0; \
76
11.0M
  if (
LOG_THROTTLER.ShouldLog(n_secs, &num_suppressed)10.4M
) \
77
11.0M
    
BOOST_PP_CAT(GOOGLE_LOG_, severity)(num_suppressed).stream()94.1k
78
79
#define YB_LOG_WITH_PREFIX_EVERY_N_SECS(severity, n_secs) \
80
363k
    YB_LOG_EVERY_N_SECS(severity, n_secs) << LogPrefix()
81
82
#define YB_LOG_WITH_PREFIX_UNLOCKED_EVERY_N_SECS(severity, n_secs) \
83
21.3k
    YB_LOG_EVERY_N_SECS(severity, n_secs) << LogPrefixUnlocked()
84
85
// Logs a messages with 2 different severities. By default used severity1, but if during
86
// duration there were more than count messages, then it will use severity2.
87
#define YB_LOG_HIGHER_SEVERITY_WHEN_TOO_MANY(severity1, severity2, duration, count) \
88
351k
  static yb::logging_internal::LogRateThrottler LOG_THROTTLER(duration, count);  \
89
351k
  google::LogMessage( \
90
351k
    __FILE__, __LINE__, \
91
351k
    
LOG_THROTTLER.TooMany()58.5k
? BOOST_PP_CAT(google::GLOG_, severity2) \
92
351k
                            : BOOST_PP_CAT(google::GLOG_, severity1)).stream()
93
94
namespace yb {
95
enum PRIVATE_ThrottleMsg {THROTTLE_MSG};
96
} // namespace yb
97
98
////////////////////////////////////////////////////////////////////////////////
99
// Versions of glog macros for "LOG_EVERY" and "LOG_FIRST" that annotate the
100
// benign races on their internal static variables.
101
////////////////////////////////////////////////////////////////////////////////
102
103
// The "base" macros.
104
#define YB_SOME_KIND_OF_LOG_EVERY_N(severity, n, what_to_do) \
105
14.4M
  static int LOG_OCCURRENCES = 0, LOG_OCCURRENCES_MOD_N = 0; \
106
14.4M
  ANNOTATE_BENIGN_RACE(&LOG_OCCURRENCES, "Logging every N is approximate"); \
107
14.4M
  ANNOTATE_BENIGN_RACE(&LOG_OCCURRENCES_MOD_N, "Logging every N is approximate"); \
108
14.4M
  ++LOG_OCCURRENCES; \
109
14.4M
  if (
++LOG_OCCURRENCES_MOD_N > n14.2M
) LOG_OCCURRENCES_MOD_N
-= n60.5k
; \
110
14.4M
  if (LOG_OCCURRENCES_MOD_N
== 114.2M
) \
111
14.4M
    google::LogMessage( \
112
68.0k
        __FILE__, __LINE__, google::GLOG_ ## severity, LOG_OCCURRENCES, \
113
68.0k
        &what_to_do).stream()
114
115
#define YB_SOME_KIND_OF_LOG_IF_EVERY_N(severity, condition, n, what_to_do) \
116
91.2M
  static int LOG_OCCURRENCES = 0, LOG_OCCURRENCES_MOD_N = 0; \
117
91.2M
  ANNOTATE_BENIGN_RACE(&LOG_OCCURRENCES, "Logging every N is approximate"); \
118
91.2M
  ANNOTATE_BENIGN_RACE(&LOG_OCCURRENCES_MOD_N, "Logging every N is approximate"); \
119
91.2M
  ++LOG_OCCURRENCES; \
120
91.2M
  if (condition && \
121
91.2M
      
((LOG_OCCURRENCES_MOD_N=(LOG_OCCURRENCES_MOD_N + 1) % n) == (1 % n))0
) \
122
91.2M
    google::LogMessage( \
123
0
        __FILE__, __LINE__, google::GLOG_ ## severity, LOG_OCCURRENCES, \
124
0
                 &what_to_do).stream()
125
126
#define YB_SOME_KIND_OF_PLOG_EVERY_N(severity, n, what_to_do) \
127
  static int LOG_OCCURRENCES = 0, LOG_OCCURRENCES_MOD_N = 0; \
128
  ANNOTATE_BENIGN_RACE(&LOG_OCCURRENCES, "Logging every N is approximate"); \
129
  ANNOTATE_BENIGN_RACE(&LOG_OCCURRENCES_MOD_N, "Logging every N is approximate"); \
130
  ++LOG_OCCURRENCES; \
131
  if (++LOG_OCCURRENCES_MOD_N > n) LOG_OCCURRENCES_MOD_N -= n; \
132
  if (LOG_OCCURRENCES_MOD_N == 1) \
133
    google::ErrnoLogMessage( \
134
        __FILE__, __LINE__, google::GLOG_ ## severity, LOG_OCCURRENCES, \
135
        &what_to_do).stream()
136
137
#define YB_SOME_KIND_OF_LOG_FIRST_N(severity, n, what_to_do) \
138
218k
  static uint64_t LOG_OCCURRENCES = 0; \
139
218k
  ANNOTATE_BENIGN_RACE(&LOG_OCCURRENCES, "Logging the first N is approximate"); \
140
218k
  if (LOG_OCCURRENCES
++ < (n)159k
) \
141
218k
    google::LogMessage( \
142
22.3k
      __FILE__, __LINE__, google::GLOG_ ## severity, static_cast<int>(LOG_OCCURRENCES), \
143
22.3k
      &what_to_do).stream()
144
145
// The direct user-facing macros.
146
#define YB_LOG_EVERY_N(severity, n) \
147
14.4M
  static_assert(google::GLOG_ ## severity < google::NUM_SEVERITIES, \
148
14.4M
                "Invalid requested log severity"); \
149
14.4M
  
YB_SOME_KIND_OF_LOG_EVERY_N14.2M
(severity, (n), google::LogMessage::SendToLog)
150
151
2.54M
#define YB_LOG_WITH_PREFIX_EVERY_N(severity, n) YB_LOG_EVERY_N(severity, n) << LogPrefix()
152
#define YB_LOG_WITH_PREFIX_UNLOCKED_EVERY_N(severity, n) \
153
    YB_LOG_EVERY_N(severity, n) << LogPrefixUnlocked()
154
155
#define YB_SYSLOG_EVERY_N(severity, n) \
156
  YB_SOME_KIND_OF_LOG_EVERY_N(severity, (n), google::LogMessage::SendToSyslogAndLog)
157
158
#define YB_PLOG_EVERY_N(severity, n) \
159
  YB_SOME_KIND_OF_PLOG_EVERY_N(severity, (n), google::LogMessage::SendToLog)
160
161
#define YB_LOG_FIRST_N(severity, n) \
162
159k
  YB_SOME_KIND_OF_LOG_FIRST_N(severity, (n), google::LogMessage::SendToLog)
163
164
#define YB_LOG_IF_EVERY_N(severity, condition, n) \
165
91.2M
  YB_SOME_KIND_OF_LOG_IF_EVERY_N(severity, (condition), (n), google::LogMessage::SendToLog)
166
167
// We also disable the un-annotated glog macros for anyone who includes this header.
168
#undef LOG_EVERY_N
169
#define LOG_EVERY_N(severity, n) \
170
  GOOGLE_GLOG_COMPILE_ASSERT(false, "LOG_EVERY_N is deprecated. Please use YB_LOG_EVERY_N.")
171
172
#undef SYSLOG_EVERY_N
173
#define SYSLOG_EVERY_N(severity, n) \
174
  GOOGLE_GLOG_COMPILE_ASSERT(false, "SYSLOG_EVERY_N is deprecated. Please use YB_SYSLOG_EVERY_N.")
175
176
#undef PLOG_EVERY_N
177
#define PLOG_EVERY_N(severity, n) \
178
  GOOGLE_GLOG_COMPILE_ASSERT(false, "PLOG_EVERY_N is deprecated. Please use YB_PLOG_EVERY_N.")
179
180
#undef LOG_FIRST_N
181
#define LOG_FIRST_N(severity, n) \
182
  GOOGLE_GLOG_COMPILE_ASSERT(false, "LOG_FIRST_N is deprecated. Please use YB_LOG_FIRST_N.")
183
184
#undef LOG_IF_EVERY_N
185
#define LOG_IF_EVERY_N(severity, condition, n) \
186
  GOOGLE_GLOG_COMPILE_ASSERT(false, "LOG_IF_EVERY_N is deprecated. Please use YB_LOG_IF_EVERY_N.")
187
188
namespace yb {
189
190
// glog doesn't allow multiple invocations of InitGoogleLogging. This method conditionally
191
// calls InitGoogleLogging only if it hasn't been called before.
192
//
193
// It also takes care of installing the google failure signal handler.
194
void InitGoogleLoggingSafe(const char* arg);
195
196
// Like InitGoogleLoggingSafe() but stripped down: no signal handlers are
197
// installed, regular logging is disabled, and log events of any severity
198
// will be written to stderr.
199
//
200
// These properties make it attractive for us in libraries.
201
void InitGoogleLoggingSafeBasic(const char* arg);
202
203
// Like InitGoogleLoggingSafeBasic() but nothing will be written to stderr.
204
void InitGoogleLoggingSafeBasicSuppressNonNativePostgresLogs(const char* arg);
205
206
// Check if Google Logging has been initialized. Can be used e.g. to determine whether to print
207
// something to stderr or log it. The implementation takes the logging mutex, so should not be used
208
// in hot codepaths.
209
bool IsLoggingInitialized();
210
211
// Demotes stderr logging to ERROR or higher and registers 'cb' as the
212
// recipient for all log events.
213
//
214
// Subsequent calls to RegisterLoggingCallback no-op (until the callback
215
// is unregistered with UnregisterLoggingCallback()).
216
void RegisterLoggingCallback(const LoggingCallback& cb);
217
218
// Unregisters a callback previously registered with
219
// RegisterLoggingCallback() and promotes stderr logging back to all
220
// severities.
221
//
222
// If no callback is registered, this is a no-op.
223
void UnregisterLoggingCallback();
224
225
// Returns the full pathname of the symlink to the most recent log
226
// file corresponding to this severity
227
void GetFullLogFilename(google::LogSeverity severity, std::string* filename);
228
229
// Shuts down the google logging library. Call before exit to ensure that log files are
230
// flushed.
231
void ShutdownLoggingSafe();
232
233
// Writes all command-line flags to the log at level INFO.
234
void LogCommandLineFlags();
235
236
// Internal function. Used by tooling for integrating with PostgreSQL C codebase.
237
void InitializeGoogleLogging(const char *arg);
238
239
namespace logging_internal {
240
241
// Internal implementation class used for throttling log messages.
242
class LogThrottler {
243
 public:
244
26.2k
  LogThrottler() : num_suppressed_(0), last_ts_(0) {
245
26.2k
    ANNOTATE_BENIGN_RACE(&last_ts_, "OK to be sloppy with log throttling");
246
26.2k
  }
247
248
10.4M
  bool ShouldLog(int n_secs, int* num_suppressed) {
249
10.4M
    MicrosecondsInt64 ts = GetMonoTimeMicros();
250
10.4M
    if (ts - last_ts_ < n_secs * 1e6) {
251
10.0M
      *num_suppressed = base::subtle::NoBarrier_AtomicIncrement(&num_suppressed_, 1);
252
10.0M
      return false;
253
10.0M
    }
254
399k
    last_ts_ = ts;
255
399k
    *num_suppressed = base::subtle::NoBarrier_AtomicExchange(&num_suppressed_, 0);
256
399k
    return true;
257
10.4M
  }
258
 private:
259
  Atomic32 num_suppressed_;
260
  uint64_t last_ts_;
261
};
262
263
// Utility class that is used by YB_LOG_HIGHER_SEVERITY_WHEN_TOO_MANY macros.
264
class LogRateThrottler {
265
 public:
266
  LogRateThrottler(const CoarseMonoClock::duration& duration, int count)
267
57
      : duration_(duration), queue_(count) {}
268
269
  bool TooMany();
270
 private:
271
  std::mutex mutex_;
272
  CoarseMonoClock::duration duration_;
273
  // Use manual queue implementation to avoid including too heavy boost/circular_buffer
274
  // to this very frequently used header.
275
  std::vector<CoarseMonoClock::time_point> queue_;
276
  size_t head_ = 0;
277
  size_t count_ = 0;
278
};
279
280
} // namespace logging_internal
281
282
std::ostream& operator<<(std::ostream &os, const PRIVATE_ThrottleMsg&);
283
284
// Convenience macros to prefix log messages with some prefix, these are the unlocked
285
// versions and should not obtain a lock (if one is required to obtain the prefix).
286
// There must be a LogPrefixUnlocked()/LogPrefixLocked() method available in the current
287
// scope in order to use these macros.
288
1.06M
#define LOG_WITH_PREFIX_UNLOCKED(severity) LOG(severity) << LogPrefixUnlocked()
289
346k
#define VLOG_WITH_PREFIX_UNLOCKED(verboselevel) LOG_IF(INFO, VLOG_IS_ON(verboselevel)) \
290
346k
  << LogPrefixUnlocked()
291
292
// Same as the above, but obtain the lock.
293
80.9M
#define LOG_WITH_PREFIX(severity) LOG(severity) << LogPrefix()
294
22.5k
#define LOG_WITH_FUNC(severity) LOG(severity) << __func__ << ": "
295
3.27k
#define LOG_WITH_PREFIX_AND_FUNC(severity) LOG_WITH_PREFIX(severity) << __func__ << ": "
296
297
13.8M
#define VLOG_WITH_PREFIX(verboselevel) VLOG(verboselevel) << LogPrefix()
298
18.4E
#define VLOG_WITH_FUNC(verboselevel) VLOG(verboselevel) << __func__ << ": "
299
18.4E
#define DVLOG_WITH_FUNC(verboselevel) DVLOG(verboselevel) << __func__ << ": "
300
106k
#define VLOG_WITH_PREFIX_AND_FUNC(verboselevel) VLOG_WITH_PREFIX(verboselevel) << __func__ << ": "
301
302
1.95M
#define DVLOG_WITH_PREFIX(verboselevel) DVLOG(verboselevel) << LogPrefix()
303
202k
#define LOG_IF_WITH_PREFIX(severity, condition) LOG_IF(severity, condition) << LogPrefix()
304
18.4E
#define VLOG_IF_WITH_PREFIX(verboselevel, condition) VLOG_IF(verboselevel, condition) << LogPrefix()
305
306
// DCHECK_ONLY_NOTNULL is like DCHECK_NOTNULL, but does not result in an unused expression in
307
// release mode, so it is suitable for being used as a stand-alone statement. In other words, use
308
// DCHECK_NOTNULL when you care about the result (e.g. when assigning it to a variable), and use
309
// DCHECK_ONLY_NOTNULL when you want to verify that an expression is not null in debug mode, but do
310
// nothing in release.
311
// E.g.
312
//   DCHECK_ONLY_NOTNULL(my_ptr)
313
//   SomeType* p = DCHECK_NOTNULL(SomeFunc());
314
315
#define CHECK_BETWEEN(val, lower_bound, upper_bound) \
316
  do { CHECK_GE(val, lower_bound); CHECK_LE(val, upper_bound); } while(false)
317
318
#ifndef NDEBUG
319
462M
#define DCHECK_ONLY_NOTNULL(expr) do { DCHECK_NOTNULL(expr); } while(false)
320
#define DCHECK_BETWEEN(val, lower_bound, upper_bound) CHECK_BETWEEN(val, lower_bound, upper_bound)
321
#else
322
#define DCHECK_ONLY_NOTNULL(expr) do {} while(false)
323
#define DCHECK_BETWEEN(val, lower_bound, upper_bound) \
324
  GLOG_MSVC_PUSH_DISABLE_WARNING(4127) \
325
  while (false) \
326
    GLOG_MSVC_POP_WARNING() CHECK_BETWEEN(val, lower_bound, upper_bound)
327
#endif
328
329
// Unlike plain LOG(FATAL), here the compiler always knows we're not returning.
330
#define FATAL_ERROR(msg) \
331
18.4E
  do { \
332
18.4E
    LOG(FATAL) << (msg); \
333
18.4E
    abort(); \
334
18.4E
  } while (
false0
)
335
336
void DisableCoreDumps();
337
338
// Get the path prefix for files that will contain details of a fatal crash (message and stack
339
// trace). This is based on the --fatal_details_path_prefix flag and the
340
// YB_FATAL_DETAILS_PATH_PREFIX environment variable. If neither of those are set, the result is
341
// based on the FATAL log path.
342
string GetFatalDetailsPathPrefix();
343
344
// Implements special handling for LOG(FATAL) and CHECK failures, such as disabling core dumps and
345
// printing the failure stack trace into a separate file.
346
class LogFatalHandlerSink : public google::LogSink {
347
 public:
348
  LogFatalHandlerSink();
349
  ~LogFatalHandlerSink();
350
  void send(google::LogSeverity severity, const char* /* full_filename */,
351
            const char* base_filename, int line, const struct tm* tm_time, const char* message,
352
            size_t message_len) override;
353
};
354
355
73.6M
#define EXPR_VALUE_FOR_LOG(expr) BOOST_PP_STRINGIZE(expr) << "=" << (yb::ToString(expr))
356
357
} // namespace yb
358
359
#endif // YB_UTIL_LOGGING_H