OmniSciDB  16c4e035a1
 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/log/sources/record_ostream.hpp>
44 
45 #include <memory>
46 #include <set>
47 
48 #endif
49 
50 #include <array>
51 #include <sstream>
52 #include <string>
53 #include <thread>
54 
55 #ifdef _WIN32
56 #if defined(ERROR) || defined(INFO) || defined(WARNING) || defined(FATAL)
58 #endif
59 #endif
60 
61 namespace boost {
62 // Forward declare boost types to avoid including expensive headers.
63 namespace program_options {
64 class options_description;
65 }
66 namespace filesystem {
67 class path;
68 }
69 } // namespace boost
70 
71 extern bool g_enable_debug_timer;
72 
73 namespace logger {
74 
75 // Channel, ChannelNames, and ChannelSymbols must be updated together.
76 // Each Channel has its own ChannelLogger declared below and defined in Logger.cpp.
77 enum Channel { IR = 0, PTX, ASM, _NCHANNELS };
78 
79 constexpr std::array<char const*, 3> ChannelNames{"IR", "PTX", "ASM"};
80 
81 constexpr std::array<char, 3> ChannelSymbols{'R', 'P', 'A'};
82 
83 static_assert(Channel::_NCHANNELS == ChannelNames.size(),
84  "Size of ChannelNames must equal number of Channels.");
85 static_assert(Channel::_NCHANNELS == ChannelSymbols.size(),
86  "Size of ChannelSymbols must equal number of Channels.");
87 
88 // Severity, SeverityNames, and SeveritySymbols must be updated together.
89 enum Severity {
90  DEBUG4 = 0,
98  _NSEVERITIES // number of severity levels
99 };
100 
101 constexpr std::array<char const*, 8> SeverityNames{"DEBUG4",
102  "DEBUG3",
103  "DEBUG2",
104  "DEBUG1",
105  "INFO",
106  "WARNING",
107  "ERROR",
108  "FATAL"};
109 
110 constexpr std::array<char, 8> SeveritySymbols{'4', '3', '2', '1', 'I', 'W', 'E', 'F'};
111 
112 static_assert(Severity::_NSEVERITIES == SeverityNames.size(),
113  "Size of SeverityNames must equal number of Severity levels.");
114 static_assert(Severity::_NSEVERITIES == SeveritySymbols.size(),
115  "Size of SeveritySymbols must equal number of Severity levels.");
116 
117 #if !(defined(__CUDACC__) || defined(NO_BOOST))
118 
119 using Channels = std::set<Channel>;
120 
121 // Filled by boost::program_options
122 class LogOptions {
123  std::string base_path_{"."}; // ignored if log_dir_ is absolute.
124  // boost::program_options::options_description is not copyable so unique_ptr
125  // allows for modification after initialization (e.g. changing default values.)
126  std::unique_ptr<boost::program_options::options_description> options_;
127 
128  public:
129  // Initialize to default values
130  std::unique_ptr<boost::filesystem::path> log_dir_;
131  // file_name_pattern and symlink are prepended with base_name.
132  std::string file_name_pattern_{".{SEVERITY}.%Y%m%d-%H%M%S.log"};
133  std::string symlink_{".{SEVERITY}"};
137  bool auto_flush_{true};
138  size_t max_files_{100};
139  size_t min_free_space_{20 << 20};
140  bool rotate_daily_{true};
141  size_t rotation_size_{10 << 20};
142 
143  LogOptions(char const* argv0);
144  ~LogOptions(); // Needed to allow forward declarations within std::unique_ptr.
145  boost::filesystem::path full_log_dir() const;
146  boost::program_options::options_description const& get_options() const;
147  void parse_command_line(int, char const* const*);
148  void set_base_path(std::string const& base_path);
149  void set_options();
150 };
151 
152 // Execute once in main() to initialize boost loggers.
153 void init(LogOptions const&);
154 
155 // Flush all sinks.
156 // https://www.boost.org/libs/log/doc/html/log/rationale/why_crash_on_term.html
157 void shutdown();
158 
159 struct LogShutdown {
160  inline ~LogShutdown() { shutdown(); }
161 };
162 
163 // Optional pointer to function to call on LOG(FATAL).
164 using FatalFunc = void (*)() noexcept;
166 
167 // Lifetime of Logger is each call to LOG().
168 class Logger {
169  bool const is_channel_;
170  int const enum_value_;
171  // Pointers are used to minimize size of inline objects.
172  std::unique_ptr<boost::log::record> record_;
173  std::unique_ptr<boost::log::record_ostream> stream_;
174 
175  public:
176  explicit Logger(Channel);
177  explicit Logger(Severity);
178  Logger(Logger&&) = default;
179  ~Logger();
180  operator bool() const;
181  // Must check operator bool() first before calling stream().
182  boost::log::record_ostream& stream(char const* file, int line);
183 };
184 
186  extern bool g_any_active_channels;
187  return g_any_active_channels;
188 }
189 
190 inline bool fast_logging_check(Severity severity) {
192  return g_min_active_severity <= severity;
193 }
194 
195 // These macros risk inadvertent else-matching to the if statements,
196 // which are fortunately prevented by our clang-tidy requirements.
197 // These can be changed to for/while loops with slight performance degradation.
198 
199 #define SLOG(severity_or_channel) \
200  if (auto _omnisci_logger_severity_or_channel_ = severity_or_channel; \
201  logger::fast_logging_check(_omnisci_logger_severity_or_channel_)) \
202  if (auto _omnisci_logger_ = logger::Logger(_omnisci_logger_severity_or_channel_)) \
203  _omnisci_logger_.stream(__FILE__, __LINE__)
204 
205 #define LOG(tag) SLOG(logger::tag)
206 
207 #define LOGGING(tag) logger::fast_logging_check(logger::tag)
208 
209 #define VLOGGING(n) logger::fast_logging_check(logger::DEBUG##n)
210 
211 #define CHECK(condition) \
212  if (BOOST_UNLIKELY(!(condition))) \
213  LOG(FATAL) << "Check failed: " #condition " "
214 
215 #define CHECK_OP(OP, x, y) \
216  if (std::string* fatal_msg = logger::Check##OP(x, y, #x, #y)) \
217  LOG(FATAL) << *std::unique_ptr<std::string>(fatal_msg)
218 
219 #define CHECK_EQ(x, y) CHECK_OP(EQ, x, y)
220 #define CHECK_NE(x, y) CHECK_OP(NE, x, y)
221 #define CHECK_LT(x, y) CHECK_OP(LT, x, y)
222 #define CHECK_LE(x, y) CHECK_OP(LE, x, y)
223 #define CHECK_GT(x, y) CHECK_OP(GT, x, y)
224 #define CHECK_GE(x, y) CHECK_OP(GE, x, y)
225 
226 template <typename X, typename Y>
227 BOOST_NOINLINE std::string* check_failed(X const& x,
228  Y const& y,
229  char const* xstr,
230  char const* ystr,
231  char const* op_str) {
232  std::stringstream ss;
233  ss << "Check failed: " << xstr << op_str << ystr << " (" << x << op_str << y << ") ";
234  return new std::string(ss.str()); // Deleted by CHECK_OP macro.
235 }
236 
237 // Complexity comes from requirement that x and y be evaluated only once.
238 #define OMINSCI_CHECKOP_FUNCTION(name, op) \
239  template <typename X, typename Y> \
240  inline std::string* Check##name( \
241  X const& x, Y const& y, char const* xstr, char const* ystr) { \
242  if (BOOST_LIKELY(x op y)) \
243  return nullptr; \
244  else \
245  return logger::check_failed(x, y, xstr, ystr, " " #op " "); \
246  }
253 #undef OMINSCI_CHECKOP_FUNCTION
254 
255 #define UNREACHABLE() LOG(FATAL) << "UNREACHABLE "
256 
257 #else // __CUDACC__
258 
259 // Provided for backward compatibility to allow code to compile.
260 // No logging is actually done, since cuda code should not log.
261 template <Severity severity>
262 class NullLogger {
263  public:
264  NullLogger() {
265  if /*constexpr*/ (severity == Severity::FATAL) {
266  abort();
267  }
268  }
269  template <typename T>
270 #ifndef SUPPRESS_NULL_LOGGER_DEPRECATION_WARNINGS
271  [[deprecated]]
272 #endif
273  // If you are here because of a deprecation warning, that is because the code
274  // is attempting to log something in cuda (e.g. CHECK macros). It should
275  // probably be fixed there.
276  NullLogger&
277  operator<<(const T&) {
278  return *this;
279  }
280 };
281 
282 #define LOG(severity) logger::NullLogger<logger::Severity::severity>()
283 
284 #define LOGGING(tag) false
285 
286 #define VLOGGING(n) false
287 
288 #define CHECK(condition) LOG_IF(FATAL, !(condition))
289 
290 #define CHECK_EQ(x, y) CHECK((x) == (y))
291 #define CHECK_NE(x, y) CHECK((x) != (y))
292 #define CHECK_LT(x, y) CHECK((x) < (y))
293 #define CHECK_LE(x, y) CHECK((x) <= (y))
294 #define CHECK_GT(x, y) CHECK((x) > (y))
295 #define CHECK_GE(x, y) CHECK((x) >= (y))
296 
297 #define UNREACHABLE() LOG(FATAL)
298 
299 #endif // __CUDACC__
300 
301 #define LOG_IF(severity, condition) \
302  if (condition) \
303  LOG(severity)
304 
305 #define VLOG(n) LOG(DEBUG##n)
306 
307 class Duration;
308 
309 class DebugTimer {
311  DebugTimer(DebugTimer const&) = delete;
312  DebugTimer(DebugTimer&&) = delete;
313  DebugTimer& operator=(DebugTimer const&) = delete;
314  DebugTimer& operator=(DebugTimer&&) = delete;
315 
316  public:
317  DebugTimer(Severity, char const* file, int line, char const* name);
318  ~DebugTimer();
319  void stop();
320  // json is returned only when called on the root DurationTree.
321  std::string stopAndGetJson();
322 };
323 
324 using QueryId = uint64_t;
325 QueryId query_id();
326 
327 // ~QidScopeGuard resets the thread_local g_query_id to 0 if the current value = id_.
328 // In other words, only the QidScopeGuard instance which resulted from changing
329 // g_query_id from zero to non-zero is responsible for resetting it back to zero when it
330 // goes out of scope. All other instances have no effect.
333 
334  public:
335  QidScopeGuard(QueryId const id) : id_{id} {}
336  QidScopeGuard(QidScopeGuard const&) = delete;
337  QidScopeGuard& operator=(QidScopeGuard const&) = delete;
338  QidScopeGuard(QidScopeGuard&& that) : id_(that.id_) { that.id_ = 0; }
340  id_ = that.id_;
341  that.id_ = 0;
342  return *this;
343  }
344  ~QidScopeGuard();
345  QueryId id() const { return id_; }
346 };
347 
348 // Set logger::g_query_id based on given parameter.
349 QidScopeGuard set_thread_local_query_id(QueryId const);
350 
351 using ThreadId = uint64_t;
352 
353 void debug_timer_new_thread(ThreadId parent_thread_id);
354 
356 
357 // Typical usage: auto timer = DEBUG_TIMER(__func__);
358 #define DEBUG_TIMER(name) logger::DebugTimer(logger::INFO, __FILE__, __LINE__, name)
359 
360 // This MUST NOT be called more than once per thread, otherwise a failed CHECK() occurs.
361 // Best practice is to call it from the point where the new thread is spawned.
362 // Beware of threads that are re-used.
363 #define DEBUG_TIMER_NEW_THREAD(parent_thread_id) \
364  do { \
365  if (g_enable_debug_timer) \
366  logger::debug_timer_new_thread(parent_thread_id); \
367  } while (false)
368 
369 } // namespace logger
370 
371 #endif // SHARED_LOGGER_H
QidScopeGuard set_thread_local_query_id(QueryId const query_id)
Definition: Logger.cpp:483
void debug_timer_new_thread(ThreadId parent_thread_id)
Definition: Logger.cpp:791
std::unique_ptr< boost::program_options::options_description > options_
Definition: Logger.h:126
int const enum_value_
Definition: Logger.h:170
constexpr std::array< char const *, 3 > ChannelNames
Definition: Logger.h:79
size_t min_free_space_
Definition: Logger.h:139
std::set< Channel > Channels
Definition: Logger.h:119
std::string stopAndGetJson()
Definition: Logger.cpp:778
QidScopeGuard(QueryId const id)
Definition: Logger.h:335
std::unique_ptr< boost::log::record > record_
Definition: Logger.h:172
LogOptions(char const *argv0)
std::string base_path_
Definition: Logger.h:123
QidScopeGuard(QidScopeGuard &&that)
Definition: Logger.h:338
bool g_enable_debug_timer
Definition: Logger.cpp:17
Channel
Definition: Logger.h:77
string name
Definition: setup.in.py:72
Duration * duration_
Definition: Logger.h:310
QueryId id() const
Definition: Logger.h:345
void set_once_fatal_func(FatalFunc fatal_func)
Definition: Logger.cpp:333
constexpr std::array< char, 3 > ChannelSymbols
Definition: Logger.h:81
QidScopeGuard & operator=(QidScopeGuard const &)=delete
void(*)() noexcept FatalFunc
Definition: Logger.h:164
constexpr std::array< char, 8 > SeveritySymbols
Definition: Logger.h:110
Channels channels_
Definition: Logger.h:136
bool const is_channel_
Definition: Logger.h:169
uint64_t QueryId
Definition: Logger.h:324
bool fast_logging_check(Channel)
Definition: Logger.h:185
void init(LogOptions const &log_opts)
Definition: Logger.cpp:305
Severity g_min_active_severity
Definition: Logger.cpp:303
#define OMINSCI_CHECKOP_FUNCTION(name, op)
Definition: Logger.h:238
bool rotate_daily_
Definition: Logger.h:140
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:227
std::string symlink_
Definition: Logger.h:133
DebugTimer & operator=(DebugTimer const &)=delete
DebugTimer(DebugTimer const &)=delete
std::unique_ptr< boost::log::record_ostream > stream_
Definition: Logger.h:173
tuple line
Definition: parse_ast.py:10
Severity
Definition: Logger.h:89
void shutdown()
Definition: Logger.cpp:340
constexpr std::array< char const *, 8 > SeverityNames
Definition: Logger.h:101
uint64_t ThreadId
Definition: Logger.h:351
std::unique_ptr< boost::filesystem::path > log_dir_
Definition: Logger.h:130
Severity severity_
Definition: Logger.h:134
bool g_any_active_channels
Definition: Logger.cpp:302
ThreadId thread_id()
Definition: Logger.cpp:816
boost::program_options::options_description const & get_options() const
std::string file_name_pattern_
Definition: Logger.h:132
QueryId query_id()
Definition: Logger.cpp:469
size_t rotation_size_
Definition: Logger.h:141
void set_base_path(std::string const &base_path)
boost::filesystem::path full_log_dir() const
size_t max_files_
Definition: Logger.h:138
Logger(Channel)
Definition: Logger.cpp:424
std::ostream & operator<<(std::ostream &out, Channels const &channels)
Definition: Logger.cpp:383
QidScopeGuard & operator=(QidScopeGuard &&that)
Definition: Logger.h:339
Severity severity_clog_
Definition: Logger.h:135
boost::log::record_ostream & stream(char const *file, int line)
Definition: Logger.cpp:489
void parse_command_line(int, char const *const *)