OmniSciDB  6686921089
 All Classes Namespaces Files Functions Variables Typedefs Enumerations Enumerator Friends Macros Groups Pages
Logger.h
Go to the documentation of this file.
1 /*
2  * Copyright (c) 2019 OmniSci, Inc.
3  *
4  * Licensed under the Apache License, Version 2.0 (the "License");
5  * you may not use this file except in compliance with the License.
6  * You may obtain a copy of the License at
7  *
8  * http://www.apache.org/licenses/LICENSE-2.0
9  *
10  * Unless required by applicable law or agreed to in writing, software
11  * distributed under the License is distributed on an "AS IS" BASIS,
12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13  * See the License for the specific language governing permissions and
14  * limitations under the License.
15  */
16 
17 /*
18  * @file Logger.h
19  * @author Matt Pulver <matt.pulver@omnisci.com>
20  * @description Use Boost.Log for logging data compatible with previous API.
21  *
22  * Usage:
23  * - Initialize a LogOptions object. E.g.
24  * logger::LogOptions log_options(argv[0]);
25  * - LogOptions can optionally be added to boost::program_options:
26  * help_desc.add(log_options.get_options());
27  * - Initialize global logger once per application:
28  * logger::init(log_options);
29  * - From anywhere in the program:
30  * - LOG(INFO) << "Nice query!";
31  * - LOG(DEBUG4) << "x = " << x;
32  * - CHECK(condition);
33  * - CHECK_LE(x, xmax);
34  * Newlines are automatically appended to log messages.
35  */
36 
37 #ifndef SHARED_LOGGER_H
38 #define SHARED_LOGGER_H
39 
40 #if !(defined(__CUDACC__) || defined(NO_BOOST))
41 
42 #include <boost/config.hpp>
43 #include <boost/filesystem.hpp>
44 #include <boost/log/common.hpp>
45 #include <boost/program_options.hpp>
46 
47 #include <memory>
48 #include <set>
49 
50 #endif
51 
52 #include <array>
53 #include <sstream>
54 #include <thread>
55 
56 #ifdef _WIN32
57 #if defined(ERROR) || defined(INFO) || defined(WARNING) || defined(FATAL)
59 #endif
60 #endif
61 
62 extern bool g_enable_debug_timer;
63 
64 namespace logger {
65 
66 // Channel, ChannelNames, and ChannelSymbols must be updated together.
67 // Each Channel has its own ChannelLogger declared below and defined in Logger.cpp.
68 enum Channel { IR = 0, PTX, ASM, _NCHANNELS };
69 
70 constexpr std::array<char const*, 3> ChannelNames{"IR", "PTX", "ASM"};
71 
72 constexpr std::array<char, 3> ChannelSymbols{'R', 'P', 'A'};
73 
74 static_assert(Channel::_NCHANNELS == ChannelNames.size(),
75  "Size of ChannelNames must equal number of Channels.");
76 static_assert(Channel::_NCHANNELS == ChannelSymbols.size(),
77  "Size of ChannelSymbols must equal number of Channels.");
78 
79 // Severity, SeverityNames, and SeveritySymbols must be updated together.
80 enum Severity {
81  DEBUG4 = 0,
89  _NSEVERITIES // number of severity levels
90 };
91 
92 constexpr std::array<char const*, 8> SeverityNames{"DEBUG4",
93  "DEBUG3",
94  "DEBUG2",
95  "DEBUG1",
96  "INFO",
97  "WARNING",
98  "ERROR",
99  "FATAL"};
100 
101 constexpr std::array<char, 8> SeveritySymbols{'4', '3', '2', '1', 'I', 'W', 'E', 'F'};
102 
103 static_assert(Severity::_NSEVERITIES == SeverityNames.size(),
104  "Size of SeverityNames must equal number of Severity levels.");
105 static_assert(Severity::_NSEVERITIES == SeveritySymbols.size(),
106  "Size of SeveritySymbols must equal number of Severity levels.");
107 
108 #if !(defined(__CUDACC__) || defined(NO_BOOST))
109 
110 using Channels = std::set<Channel>;
111 
112 // Filled by boost::program_options
113 class LogOptions {
114  std::string base_path_{"."}; // ignored if log_dir_ is absolute.
115  // boost::program_options::options_description is not copyable so unique_ptr
116  // allows for modification after initialization (e.g. changing default values.)
117  std::unique_ptr<boost::program_options::options_description> options_;
118 
119  public:
120  // Initialize to default values
121  boost::filesystem::path log_dir_{"mapd_log"};
122  // file_name_pattern and symlink are prepended with base_name.
123  std::string file_name_pattern_{".{SEVERITY}.%Y%m%d-%H%M%S.log"};
124  std::string symlink_{".{SEVERITY}"};
128  bool auto_flush_{true};
129  size_t max_files_{100};
130  size_t min_free_space_{20 << 20};
131  bool rotate_daily_{true};
132  size_t rotation_size_{10 << 20};
133 
134  LogOptions(char const* argv0);
135  boost::filesystem::path full_log_dir() const;
136  boost::program_options::options_description const& get_options() const;
137  void parse_command_line(int, char const* const*);
138  void set_base_path(std::string const& base_path);
139  void set_options();
140 };
141 
142 // Execute once in main() to initialize boost loggers.
143 void init(LogOptions const&);
144 
145 // Flush all sinks.
146 // https://www.boost.org/libs/log/doc/html/log/rationale/why_crash_on_term.html
147 void shutdown();
148 
149 struct LogShutdown {
150  inline ~LogShutdown() { shutdown(); }
151 };
152 
153 // Optional pointer to function to call on LOG(FATAL).
154 using FatalFunc = void (*)() noexcept;
156 
157 using ChannelLogger = boost::log::sources::channel_logger_mt<Channel>;
158 BOOST_LOG_GLOBAL_LOGGER(gChannelLogger_IR, ChannelLogger)
159 BOOST_LOG_GLOBAL_LOGGER(gChannelLogger_PTX, ChannelLogger)
160 BOOST_LOG_GLOBAL_LOGGER(gChannelLogger_ASM, ChannelLogger)
161 
162 using SeverityLogger = boost::log::sources::severity_logger_mt<Severity>;
163 BOOST_LOG_GLOBAL_LOGGER(gSeverityLogger, SeverityLogger)
164 
165 // Lifetime of Logger is each call to LOG().
166 class Logger {
167  bool const is_channel_;
168  int const enum_value_;
169  // Pointers are used to minimize size of inline objects.
170  std::unique_ptr<boost::log::record> record_;
171  std::unique_ptr<boost::log::record_ostream> stream_;
172 
173  public:
174  explicit Logger(Channel);
175  explicit Logger(Severity);
176  Logger(Logger&&) = default;
177  ~Logger();
178  operator bool() const;
179  // Must check operator bool() first before calling stream().
180  boost::log::record_ostream& stream(char const* file, int line);
181 };
182 
184  extern bool g_any_active_channels;
185  return g_any_active_channels;
186 }
187 
188 inline bool fast_logging_check(Severity severity) {
190  return g_min_active_severity <= severity;
191 }
192 
193 // These macros risk inadvertent else-matching to the if statements,
194 // which are fortunately prevented by our clang-tidy requirements.
195 // These can be changed to for/while loops with slight performance degradation.
196 
197 #define SLOG(severity_or_channel) \
198  if (auto _omnisci_logger_severity_or_channel_ = severity_or_channel; \
199  logger::fast_logging_check(_omnisci_logger_severity_or_channel_)) \
200  if (auto _omnisci_logger_ = logger::Logger(_omnisci_logger_severity_or_channel_)) \
201  _omnisci_logger_.stream(__FILE__, __LINE__)
202 
203 #define LOG(tag) SLOG(logger::tag)
204 
205 #define LOGGING(tag) logger::fast_logging_check(logger::tag)
206 
207 #define VLOGGING(n) logger::fast_logging_check(logger::DEBUG##n)
208 
209 #define CHECK(condition) \
210  if (BOOST_UNLIKELY(!(condition))) \
211  LOG(FATAL) << "Check failed: " #condition " "
212 
213 #define CHECK_OP(OP, x, y) \
214  if (std::string* fatal_msg = logger::Check##OP(x, y, #x, #y)) \
215  LOG(FATAL) << *std::unique_ptr<std::string>(fatal_msg)
216 
217 #define CHECK_EQ(x, y) CHECK_OP(EQ, x, y)
218 #define CHECK_NE(x, y) CHECK_OP(NE, x, y)
219 #define CHECK_LT(x, y) CHECK_OP(LT, x, y)
220 #define CHECK_LE(x, y) CHECK_OP(LE, x, y)
221 #define CHECK_GT(x, y) CHECK_OP(GT, x, y)
222 #define CHECK_GE(x, y) CHECK_OP(GE, x, y)
223 
224 template <typename X, typename Y>
225 BOOST_NOINLINE std::string* check_failed(X const& x,
226  Y const& y,
227  char const* xstr,
228  char const* ystr,
229  char const* op_str) {
230  std::stringstream ss;
231  ss << "Check failed: " << xstr << op_str << ystr << " (" << x << op_str << y << ") ";
232  return new std::string(ss.str()); // Deleted by CHECK_OP macro.
233 }
234 
235 // Complexity comes from requirement that x and y be evaluated only once.
236 #define OMINSCI_CHECKOP_FUNCTION(name, op) \
237  template <typename X, typename Y> \
238  inline std::string* Check##name( \
239  X const& x, Y const& y, char const* xstr, char const* ystr) { \
240  if (BOOST_LIKELY(x op y)) \
241  return nullptr; \
242  else \
243  return logger::check_failed(x, y, xstr, ystr, " " #op " "); \
244  }
251 #undef OMINSCI_CHECKOP_FUNCTION
252 
253 #define UNREACHABLE() LOG(FATAL) << "UNREACHABLE "
254 
255 #else // __CUDACC__
256 
257 // Provided for backward compatibility to allow code to compile.
258 // No logging is actually done, since cuda code should not log.
259 template <Severity severity>
260 class NullLogger {
261  public:
262  NullLogger() {
263  if /*constexpr*/ (severity == Severity::FATAL) {
264  abort();
265  }
266  }
267  template <typename T>
268 #ifndef SUPPRESS_NULL_LOGGER_DEPRECATION_WARNINGS
269  [[deprecated]]
270 #endif
271  // If you are here because of a deprecation warning, that is because the code
272  // is attempting to log something in cuda (e.g. CHECK macros). It should
273  // probably be fixed there.
274  NullLogger&
275  operator<<(const T&) {
276  return *this;
277  }
278 };
279 
280 #define LOG(severity) logger::NullLogger<logger::Severity::severity>()
281 
282 #define LOGGING(tag) false
283 
284 #define VLOGGING(n) false
285 
286 #define CHECK(condition) LOG_IF(FATAL, !(condition))
287 
288 #define CHECK_EQ(x, y) CHECK((x) == (y))
289 #define CHECK_NE(x, y) CHECK((x) != (y))
290 #define CHECK_LT(x, y) CHECK((x) < (y))
291 #define CHECK_LE(x, y) CHECK((x) <= (y))
292 #define CHECK_GT(x, y) CHECK((x) > (y))
293 #define CHECK_GE(x, y) CHECK((x) >= (y))
294 
295 #define UNREACHABLE() LOG(FATAL)
296 
297 #endif // __CUDACC__
298 
299 #define LOG_IF(severity, condition) \
300  if (condition) \
301  LOG(severity)
302 
303 #define VLOG(n) LOG(DEBUG##n)
304 
305 class Duration;
306 
307 class DebugTimer {
309 
310  public:
311  DebugTimer(Severity, char const* file, int line, char const* name);
312  ~DebugTimer();
313  void stop();
314  // json is returned only when called on the root DurationTree.
315  std::string stopAndGetJson();
316 };
317 
318 using QueryId = uint64_t;
319 QueryId query_id();
320 
321 // ~QidScopeGuard resets the thread_local g_query_id to 0 if the current value = id_.
322 // In other words, only the QidScopeGuard instance which resulted from changing
323 // g_query_id from zero to non-zero is responsible for resetting it back to zero when it
324 // goes out of scope. All other instances have no effect.
327 
328  public:
329  QidScopeGuard(QueryId const id) : id_{id} {}
330  QidScopeGuard(QidScopeGuard const&) = delete;
331  QidScopeGuard& operator=(QidScopeGuard const&) = delete;
332  QidScopeGuard(QidScopeGuard&& that) : id_(that.id_) { that.id_ = 0; }
334  id_ = that.id_;
335  that.id_ = 0;
336  return *this;
337  }
338  ~QidScopeGuard();
339  QueryId id() const { return id_; }
340 };
341 
342 // Set logger::g_query_id based on given parameter.
343 QidScopeGuard set_thread_local_query_id(QueryId const);
344 
345 using ThreadId = uint64_t;
346 
347 void debug_timer_new_thread(ThreadId parent_thread_id);
348 
350 
351 // Typical usage: auto timer = DEBUG_TIMER(__func__);
352 #define DEBUG_TIMER(name) logger::DebugTimer(logger::INFO, __FILE__, __LINE__, name)
353 
354 // This MUST NOT be called more than once per thread, otherwise a failed CHECK() occurs.
355 // Best practice is to call it from the point where the new thread is spawned.
356 // Beware of threads that are re-used.
357 #define DEBUG_TIMER_NEW_THREAD(parent_thread_id) \
358  do { \
359  if (g_enable_debug_timer) \
360  logger::debug_timer_new_thread(parent_thread_id); \
361  } while (false)
362 
363 } // namespace logger
364 
365 #endif // SHARED_LOGGER_H
QidScopeGuard set_thread_local_query_id(QueryId const query_id)
Definition: Logger.cpp:468
void debug_timer_new_thread(ThreadId parent_thread_id)
Definition: Logger.cpp:776
std::unique_ptr< boost::program_options::options_description > options_
Definition: Logger.h:117
int const enum_value_
Definition: Logger.h:168
constexpr std::array< char const *, 3 > ChannelNames
Definition: Logger.h:70
size_t min_free_space_
Definition: Logger.h:130
std::set< Channel > Channels
Definition: Logger.h:110
std::string stopAndGetJson()
Definition: Logger.cpp:763
QidScopeGuard(QueryId const id)
Definition: Logger.h:329
std::unique_ptr< boost::log::record > record_
Definition: Logger.h:170
LogOptions(char const *argv0)
std::string base_path_
Definition: Logger.h:114
QidScopeGuard(QidScopeGuard &&that)
Definition: Logger.h:332
bool g_enable_debug_timer
Definition: Logger.cpp:17
Channel
Definition: Logger.h:68
string name
Definition: setup.in.py:72
Duration * duration_
Definition: Logger.h:308
QueryId id() const
Definition: Logger.h:339
void set_once_fatal_func(FatalFunc fatal_func)
Definition: Logger.cpp:318
constexpr std::array< char, 3 > ChannelSymbols
Definition: Logger.h:72
QidScopeGuard & operator=(QidScopeGuard const &)=delete
boost::log::sources::channel_logger_mt< Channel > ChannelLogger
Definition: Logger.h:157
void(*)() noexcept FatalFunc
Definition: Logger.h:154
constexpr std::array< char, 8 > SeveritySymbols
Definition: Logger.h:101
Channels channels_
Definition: Logger.h:127
bool const is_channel_
Definition: Logger.h:167
uint64_t QueryId
Definition: Logger.h:318
bool fast_logging_check(Channel)
Definition: Logger.h:183
void init(LogOptions const &log_opts)
Definition: Logger.cpp:290
Severity g_min_active_severity
Definition: Logger.cpp:288
DebugTimer(Severity, char const *file, int line, char const *name)
Definition: Logger.cpp:744
#define OMINSCI_CHECKOP_FUNCTION(name, op)
Definition: Logger.h:236
bool rotate_daily_
Definition: Logger.h:131
BOOST_NOINLINE std::string * check_failed(X const &x, Y const &y, char const *xstr, char const *ystr, char const *op_str)
Definition: Logger.h:225
std::string symlink_
Definition: Logger.h:124
std::unique_ptr< boost::log::record_ostream > stream_
Definition: Logger.h:171
tuple line
Definition: parse_ast.py:10
Severity
Definition: Logger.h:80
void shutdown()
Definition: Logger.cpp:325
constexpr std::array< char const *, 8 > SeverityNames
Definition: Logger.h:92
uint64_t ThreadId
Definition: Logger.h:345
Severity severity_
Definition: Logger.h:125
bool g_any_active_channels
Definition: Logger.cpp:287
ThreadId thread_id()
Definition: Logger.cpp:791
boost::program_options::options_description const & get_options() const
boost::log::sources::severity_logger_mt< Severity > SeverityLogger
Definition: Logger.h:162
std::string file_name_pattern_
Definition: Logger.h:123
QueryId query_id()
Definition: Logger.cpp:454
size_t rotation_size_
Definition: Logger.h:132
void set_base_path(std::string const &base_path)
boost::filesystem::path full_log_dir() const
size_t max_files_
Definition: Logger.h:129
std::ostream & operator<<(std::ostream &out, Channels const &channels)
Definition: Logger.cpp:368
QidScopeGuard & operator=(QidScopeGuard &&that)
Definition: Logger.h:333
Severity severity_clog_
Definition: Logger.h:126
boost::filesystem::path log_dir_
Definition: Logger.h:121
void parse_command_line(int, char const *const *)