OmniSciDB  16c4e035a1
 All Classes Namespaces Files Functions Variables Typedefs Enumerations Enumerator Friends Macros Groups Pages
logger Namespace Reference

Namespaces

 anonymous_namespace{Logger.cpp}
 

Classes

class  Duration
 
class  DurationTree
 
struct  GetDepth
 
class  JsonEncoder
 
struct  EraseDurationTrees
 Depth-first search and erase all DurationTrees. Not thread-safe. More...
 
class  LogOptions
 
struct  LogShutdown
 
class  Logger
 
class  DebugTimer
 
class  QidScopeGuard
 

Typedefs

using ChannelLogger = boost::log::sources::channel_logger_mt< Channel >
 
using SeverityLogger = boost::log::sources::severity_logger_mt< Severity >
 
using ClogSync = sinks::synchronous_sink< sinks::text_ostream_backend >
 
using FileSync = sinks::synchronous_sink< sinks::text_file_backend >
 
using Clock = std::chrono::steady_clock
 
using DurationTreeNode = boost::variant< Duration, DurationTree & >
 
using DurationTreeNodes = std::deque< DurationTreeNode >
 
using DurationTreeMap = std::unordered_map< ThreadId, std::unique_ptr< DurationTree >>
 
using Channels = std::set< Channel >
 
using FatalFunc = void(*)() noexcept
 
using QueryId = uint64_t
 
using ThreadId = uint64_t
 

Enumerations

enum  Channel { IR = 0, PTX, ASM, _NCHANNELS }
 
enum  Severity {
  DEBUG4 = 0, DEBUG3, DEBUG2, DEBUG1,
  INFO, WARNING, ERROR, FATAL,
  _NSEVERITIES
}
 

Functions

 BOOST_LOG_GLOBAL_LOGGER_CTOR_ARGS (gChannelLogger_IR, ChannelLogger,(keywords::channel=IR)) BOOST_LOG_GLOBAL_LOGGER_CTOR_ARGS(gChannelLogger_PTX
 
template<typename CONSOLE_SINK >
boost::shared_ptr< CONSOLE_SINK > make_sink (LogOptions const &log_opts)
 
void init (LogOptions const &log_opts)
 
void set_once_fatal_func (FatalFunc fatal_func)
 
void shutdown ()
 
std::istream & operator>> (std::istream &in, Channels &channels)
 
std::ostream & operator<< (std::ostream &out, Channels const &channels)
 
std::istream & operator>> (std::istream &in, Severity &sev)
 
std::ostream & operator<< (std::ostream &out, Severity const &sev)
 
QueryId query_id ()
 
QidScopeGuard set_thread_local_query_id (QueryId const query_id)
 
template<typename... Ts>
DurationnewDuration (Severity severity, Ts &&...args)
 
std::ostream & operator<< (std::ostream &os, Duration const &duration)
 
std::ostream & operator<< (std::ostream &os, DurationTree const &duration_tree)
 
boost::log::record_ostream & operator<< (boost::log::record_ostream &os, DurationTreeMap::const_reference kv_pair)
 
void logAndEraseDurationTree (std::string *json_str)
 
void debug_timer_new_thread (ThreadId parent_thread_id)
 
ThreadId thread_id ()
 
bool fast_logging_check (Channel)
 
bool fast_logging_check (Severity severity)
 
template<typename X , typename Y >
BOOST_NOINLINE std::string * check_failed (X const &x, Y const &y, char const *xstr, char const *ystr, char const *op_str)
 

Variables

std::once_flag g_fatal_func_flag
 
bool g_any_active_channels {false}
 
Severity g_min_active_severity {Severity::FATAL}
 
thread_local std::atomic< QueryIdg_query_id {0}
 
std::mutex g_duration_tree_map_mutex
 
DurationTreeMap g_duration_tree_map
 
std::atomic< ThreadIdg_next_thread_id {0}
 
thread_local ThreadId g_thread_id = g_next_thread_id++
 
constexpr std::array< char
const *, 3 > 
ChannelNames {"IR", "PTX", "ASM"}
 
constexpr std::array< char, 3 > ChannelSymbols {'R', 'P', 'A'}
 
constexpr std::array< char
const *, 8 > 
SeverityNames
 
constexpr std::array< char, 8 > SeveritySymbols {'4', '3', '2', '1', 'I', 'W', 'E', 'F'}
 

Typedef Documentation

Definition at line 52 of file Logger.cpp.

using logger::Channels = typedef std::set<Channel>

Definition at line 119 of file Logger.h.

using logger::Clock = typedef std::chrono::steady_clock

Definition at line 495 of file Logger.cpp.

using logger::ClogSync = typedef sinks::synchronous_sink<sinks::text_ostream_backend>

Definition at line 287 of file Logger.cpp.

using logger::DurationTreeMap = typedef std::unordered_map<ThreadId, std::unique_ptr<DurationTree>>

Definition at line 590 of file Logger.cpp.

using logger::DurationTreeNode = typedef boost::variant<Duration, DurationTree&>

Definition at line 533 of file Logger.cpp.

using logger::DurationTreeNodes = typedef std::deque<DurationTreeNode>

Definition at line 534 of file Logger.cpp.

using logger::FatalFunc = typedef void (*)() noexcept

Definition at line 164 of file Logger.h.

using logger::FileSync = typedef sinks::synchronous_sink<sinks::text_file_backend>

Definition at line 288 of file Logger.cpp.

using logger::QueryId = typedef uint64_t

Definition at line 324 of file Logger.h.

typedef boost::log::sources::severity_logger_mt< Severity > logger::SeverityLogger

Definition at line 57 of file Logger.cpp.

using logger::ThreadId = typedef uint64_t

Definition at line 351 of file Logger.h.

Enumeration Type Documentation

Enumerator
IR 
PTX 
ASM 
_NCHANNELS 

Definition at line 77 of file Logger.h.

Enumerator
DEBUG4 
DEBUG3 
DEBUG2 
DEBUG1 
INFO 
WARNING 
ERROR 
FATAL 
_NSEVERITIES 

Definition at line 89 of file Logger.h.

89  {
90  DEBUG4 = 0,
91  DEBUG3,
92  DEBUG2,
93  DEBUG1,
94  INFO,
95  WARNING,
96  ERROR,
97  FATAL,
98  _NSEVERITIES // number of severity levels
99 };

Function Documentation

logger::BOOST_LOG_GLOBAL_LOGGER_CTOR_ARGS ( gChannelLogger_IR  ,
ChannelLogger  ,
(keywords::channel=IR)   
)
template<typename X , typename Y >
BOOST_NOINLINE std::string* logger::check_failed ( X const x,
Y const y,
char const xstr,
char const ystr,
char const op_str 
)

Definition at line 227 of file Logger.h.

231  {
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 }
void logger::debug_timer_new_thread ( ThreadId  parent_thread_id)

Call this when a new thread is spawned that will have timers that need to be associated with timers on the parent thread.

Definition at line 791 of file Logger.cpp.

References CHECK, g_duration_tree_map, g_duration_tree_map_mutex, g_next_thread_id, and g_thread_id.

791  {
792  std::lock_guard<std::mutex> lock_guard(g_duration_tree_map_mutex);
793  auto parent_itr = g_duration_tree_map.find(parent_thread_id);
794  CHECK(parent_itr != g_duration_tree_map.end()) << parent_thread_id;
795  auto const current_depth = parent_itr->second->currentDepth();
796  auto& duration_tree_ptr = g_duration_tree_map[g_thread_id];
797  if (!duration_tree_ptr) {
798  duration_tree_ptr = std::make_unique<DurationTree>(g_thread_id, current_depth + 1);
799  parent_itr->second->pushDurationTree(*duration_tree_ptr);
800  } else if (parent_thread_id == g_thread_id) {
801  // DEBUG_TIMER_NEW_THREAD() was called but this is actually the same thread as the
802  // parent, so nothing will be done. TBB does this.
803  } else {
804  // This appears to be a recycled thread, so g_thread_id is updated manually.
805  // It is assumed the prior thread that was using this g_thread_id has completed,
806  // but we need to use a different value since the old value still exists as a
807  // key in g_duration_tree_map.
808  g_thread_id = g_next_thread_id++;
809  auto const insert = g_duration_tree_map.insert(
810  {g_thread_id, std::make_unique<DurationTree>(g_thread_id, current_depth + 1)});
811  CHECK(insert.second) << parent_thread_id << " -> " << g_thread_id;
812  parent_itr->second->pushDurationTree(*insert.first->second);
813  }
814 }
std::mutex g_duration_tree_map_mutex
Definition: Logger.cpp:592
std::atomic< ThreadId > g_next_thread_id
Definition: Logger.cpp:594
thread_local ThreadId g_thread_id
Definition: Logger.cpp:595
#define CHECK(condition)
Definition: Logger.h:211
DurationTreeMap g_duration_tree_map
Definition: Logger.cpp:593
bool logger::fast_logging_check ( Channel  )
inline

Definition at line 185 of file Logger.h.

References g_any_active_channels.

Referenced by anonymous_namespace{RelAlgOptimizer.cpp}::cleanup_dead_nodes(), fold_filters(), query_state::StdLog::log(), and query_state::StdLog::logCallStack().

185  {
186  extern bool g_any_active_channels;
187  return g_any_active_channels;
188 }
bool g_any_active_channels
Definition: Logger.cpp:302

+ Here is the caller graph for this function:

bool logger::fast_logging_check ( Severity  severity)
inline

Definition at line 190 of file Logger.h.

References g_min_active_severity.

190  {
192  return g_min_active_severity <= severity;
193 }
Severity g_min_active_severity
Definition: Logger.cpp:303
Severity
Definition: Logger.h:89
void logger::init ( LogOptions const log_opts)

Definition at line 305 of file Logger.cpp.

References _NSEVERITIES, logger::LogOptions::channels_, logger::LogOptions::full_log_dir(), g_any_active_channels, g_min_active_severity, i, INFO, nvtx_helpers::init(), LOG, logger::LogOptions::max_files_, logger::LogOptions::severity_, and logger::LogOptions::severity_clog_.

Referenced by UdfCompiler::compileFromCommandLine(), UdfCompiler::generateAST(), QueryRunner::QueryRunner::init(), CommandLineOptions::init_logging(), main(), ColumnarResults::mergeResults(), ResultSetManager::reduce(), Executor::reduceMultiDeviceResultSets(), FixedLengthEncoder< T, V >::updateStatsEncoded(), and NoneEncoder< T >::updateStatsEncoded().

305  {
306  boost::shared_ptr<boost::log::core> core = boost::log::core::get();
307  // boost::log::add_common_attributes(); // LineID TimeStamp ProcessID ThreadID
308  core->add_global_attribute("TimeStamp", attr::local_clock());
309  core->add_global_attribute("ProcessID", attr::current_process_id());
310  if (0 < log_opts.max_files_) {
311  boost::filesystem::path const full_log_dir = log_opts.full_log_dir();
312  bool const log_dir_was_created = boost::filesystem::create_directory(full_log_dir);
313  // Don't create separate log sinks for anything less than Severity::INFO.
314  Severity const min_sink_level = std::max(Severity::INFO, log_opts.severity_);
315  for (int i = min_sink_level; i < Severity::_NSEVERITIES; ++i) {
316  Severity const level = static_cast<Severity>(i);
317  core->add_sink(make_sink<FileSync>(log_opts, full_log_dir, level));
318  }
319  g_min_active_severity = std::min(g_min_active_severity, log_opts.severity_);
320  if (log_dir_was_created) {
321  LOG(INFO) << "Log directory(" << full_log_dir.native() << ") created.";
322  }
323  for (auto const channel : log_opts.channels_) {
324  core->add_sink(make_sink<FileSync>(log_opts, full_log_dir, channel));
325  }
326  g_any_active_channels = !log_opts.channels_.empty();
327  }
328  core->add_sink(make_sink<ClogSync>(log_opts));
329  g_min_active_severity = std::min(g_min_active_severity, log_opts.severity_clog_);
331 }
#define LOG(tag)
Definition: Logger.h:205
Severity g_min_active_severity
Definition: Logger.cpp:303
Severity
Definition: Logger.h:89
bool g_any_active_channels
Definition: Logger.cpp:302

+ Here is the call graph for this function:

+ Here is the caller graph for this function:

void logger::logAndEraseDurationTree ( std::string *  json_str)

Definition at line 743 of file Logger.cpp.

References CHECK, g_duration_tree_map, g_duration_tree_map_mutex, g_thread_id, and logger::JsonEncoder::str().

Referenced by logger::DebugTimer::stop(), and logger::DebugTimer::stopAndGetJson().

743  {
744  std::lock_guard<std::mutex> lock_guard(g_duration_tree_map_mutex);
745  DurationTreeMap::const_iterator const itr = g_duration_tree_map.find(g_thread_id);
746  CHECK(itr != g_duration_tree_map.cend());
747  auto const& root_duration = itr->second->rootDuration();
748  if (auto log = Logger(root_duration.severity_)) {
749  log.stream(root_duration.file_, root_duration.line_) << *itr;
750  }
751  if (json_str) {
752  JsonEncoder json_encoder;
753  *json_str = json_encoder.str(*itr);
754  }
755  EraseDurationTrees erase_duration_trees;
756  erase_duration_trees(itr);
757 }
std::mutex g_duration_tree_map_mutex
Definition: Logger.cpp:592
const std::string json_str(const rapidjson::Value &obj) noexcept
Definition: JsonAccessors.h:44
thread_local ThreadId g_thread_id
Definition: Logger.cpp:595
#define CHECK(condition)
Definition: Logger.h:211
DurationTreeMap g_duration_tree_map
Definition: Logger.cpp:593

+ Here is the call graph for this function:

+ Here is the caller graph for this function:

template<typename CONSOLE_SINK >
boost::shared_ptr<CONSOLE_SINK> logger::make_sink ( LogOptions const log_opts)

Definition at line 291 of file Logger.cpp.

References logger::LogOptions::severity_clog_.

291  {
292  auto sink = boost::make_shared<CONSOLE_SINK>();
293  boost::shared_ptr<std::ostream> clog(&std::clog, boost::null_deleter());
294  sink->locked_backend()->add_stream(clog);
295  sink->set_filter(log_opts.severity_clog_ <= severity);
296  set_formatter<Severity>(sink);
297  return sink;
298 }
template<typename... Ts>
Duration* logger::newDuration ( Severity  severity,
Ts &&...  args 
)

Definition at line 598 of file Logger.cpp.

References run_benchmark_import::args, g_duration_tree_map, g_duration_tree_map_mutex, g_enable_debug_timer, and g_thread_id.

598  {
599  if (g_enable_debug_timer) {
600  std::lock_guard<std::mutex> lock_guard(g_duration_tree_map_mutex);
601  auto& duration_tree_ptr = g_duration_tree_map[g_thread_id];
602  if (!duration_tree_ptr) {
603  duration_tree_ptr = std::make_unique<DurationTree>(g_thread_id, 0);
604  }
605  return duration_tree_ptr->newDuration(severity, std::forward<Ts>(args)...);
606  }
607  return nullptr; // Inactive - don't measure or report timing.
608 }
std::mutex g_duration_tree_map_mutex
Definition: Logger.cpp:592
bool g_enable_debug_timer
Definition: Logger.cpp:17
thread_local ThreadId g_thread_id
Definition: Logger.cpp:595
DurationTreeMap g_duration_tree_map
Definition: Logger.cpp:593
std::ostream& logger::operator<< ( std::ostream &  out,
Channels const channels 
)

Definition at line 383 of file Logger.cpp.

References ChannelNames, and i.

383  {
384  int i = 0;
385  for (auto const channel : channels) {
386  out << (i++ ? " " : "") << ChannelNames.at(channel);
387  }
388  return out;
389 }
constexpr std::array< char const *, 3 > ChannelNames
Definition: Logger.h:79
std::ostream& logger::operator<< ( std::ostream &  out,
Severity const sev 
)

Definition at line 406 of file Logger.cpp.

406  {
407  return out << SeverityNames.at(sev);
408 }
constexpr std::array< char const *, 8 > SeverityNames
Definition: Logger.h:101
std::ostream& logger::operator<< ( std::ostream &  os,
Duration const duration 
)

Definition at line 610 of file Logger.cpp.

References logger::Duration::depth_, logger::Duration::file_, nvtx_helpers::anonymous_namespace{nvtx_helpers.cpp}::filename(), logger::Duration::line_, logger::Duration::name_, logger::Duration::relative_start_time(), and logger::Duration::value().

610  {
611  return os << std::setw(2 * duration.depth_) << ' ' << duration.value() << "ms start("
612  << duration.relative_start_time() << "ms) " << duration.name_ << ' '
613  << filename(duration.file_) << ':' << duration.line_;
614 }

+ Here is the call graph for this function:

std::ostream& logger::operator<< ( std::ostream &  os,
DurationTree const duration_tree 
)

Definition at line 616 of file Logger.cpp.

References logger::DurationTree::depth_, logger::DurationTree::durations(), and logger::DurationTree::thread_id_.

616  {
617  os << std::setw(2 * duration_tree.depth_) << ' ' << "New thread("
618  << duration_tree.thread_id_ << ')';
619  for (auto const& duration_tree_node : duration_tree.durations()) {
620  os << '\n' << duration_tree_node;
621  }
622  return os << '\n'
623  << std::setw(2 * duration_tree.depth_) << ' ' << "End thread("
624  << duration_tree.thread_id_ << ')';
625 }

+ Here is the call graph for this function:

boost::log::record_ostream& logger::operator<< ( boost::log::record_ostream &  os,
DurationTreeMap::const_reference  kv_pair 
)

Definition at line 628 of file Logger.cpp.

629  {
630  auto itr = kv_pair.second->durations().cbegin();
631  auto const end = kv_pair.second->durations().cend();
632  auto const& root_duration = boost::get<Duration>(*itr);
633  os << "DEBUG_TIMER thread_id(" << kv_pair.first << ")\n"
634  << root_duration.value() << "ms total duration for " << root_duration.name_;
635  for (++itr; itr != end; ++itr) {
636  os << '\n' << *itr;
637  }
638  return os;
639 }
std::istream& logger::operator>> ( std::istream &  in,
Channels &  channels 
)

Definition at line 363 of file Logger.cpp.

References ChannelNames, parse_ast::line, and logger::anonymous_namespace{Logger.cpp}::unquote().

363  {
364  std::string line;
365  std::getline(in, line);
366  unquote(line);
367  std::regex const rex(R"(\w+)");
368  using TokenItr = std::regex_token_iterator<std::string::iterator>;
369  TokenItr const end;
370  for (TokenItr tok(line.begin(), line.end(), rex); tok != end; ++tok) {
371  auto itr = std::find(ChannelNames.cbegin(), ChannelNames.cend(), *tok);
372  if (itr == ChannelNames.cend()) {
373  in.setstate(std::ios_base::failbit);
374  break;
375  } else {
376  channels.emplace(static_cast<Channel>(itr - ChannelNames.cbegin()));
377  }
378  }
379  return in;
380 }
constexpr std::array< char const *, 3 > ChannelNames
Definition: Logger.h:79
tuple line
Definition: parse_ast.py:10
void unquote(std::string &str)
Definition: Logger.cpp:352

+ Here is the call graph for this function:

std::istream& logger::operator>> ( std::istream &  in,
Severity &  sev 
)

Definition at line 392 of file Logger.cpp.

References logger::anonymous_namespace{Logger.cpp}::unquote().

392  {
393  std::string token;
394  in >> token;
395  unquote(token);
396  auto itr = std::find(SeverityNames.cbegin(), SeverityNames.cend(), token);
397  if (itr == SeverityNames.cend()) {
398  in.setstate(std::ios_base::failbit);
399  } else {
400  sev = static_cast<Severity>(itr - SeverityNames.cbegin());
401  }
402  return in;
403 }
Severity
Definition: Logger.h:89
constexpr std::array< char const *, 8 > SeverityNames
Definition: Logger.h:101
void unquote(std::string &str)
Definition: Logger.cpp:352

+ Here is the call graph for this function:

QueryId logger::query_id ( )

Definition at line 469 of file Logger.cpp.

References g_query_id.

Referenced by DBHandler::broadcast_serialized_rows(), query_state::StdLog::log(), ResultSet::ResultSetComparator< BUFFER_ITERATOR_TYPE >::materializeApproxQuantileColumn(), ResultSet::ResultSetComparator< BUFFER_ITERATOR_TYPE >::materializeCountDistinctColumn(), ResultSet::parallelRowCount(), ResultSet::parallelTop(), and logger::Logger::stream().

469  {
470  return g_query_id.load();
471 }
thread_local std::atomic< QueryId > g_query_id
Definition: Logger.cpp:467

+ Here is the caller graph for this function:

void logger::set_once_fatal_func ( FatalFunc  fatal_func)

Definition at line 333 of file Logger.cpp.

Referenced by QueryRunner::QueryRunner::QueryRunner().

333  {
334  if (g_fatal_func.exchange(fatal_func)) {
335  throw std::runtime_error(
336  "logger::set_once_fatal_func() should not be called more than once.");
337  }
338 }

+ Here is the caller graph for this function:

QidScopeGuard logger::set_thread_local_query_id ( QueryId const  query_id)

Definition at line 483 of file Logger.cpp.

References g_query_id.

Referenced by ResultSet::ResultSetComparator< BUFFER_ITERATOR_TYPE >::materializeApproxQuantileColumn(), ResultSet::ResultSetComparator< BUFFER_ITERATOR_TYPE >::materializeCountDistinctColumn(), ResultSet::parallelRowCount(), ResultSet::parallelTop(), and query_state::QueryState::setThreadLocalQueryId().

483  {
484  QueryId expected = 0;
485  return g_query_id.compare_exchange_strong(expected, query_id) ? QidScopeGuard(query_id)
486  : QidScopeGuard(0);
487 }
uint64_t QueryId
Definition: Logger.h:324
thread_local std::atomic< QueryId > g_query_id
Definition: Logger.cpp:467
QueryId query_id()
Definition: Logger.cpp:469

+ Here is the caller graph for this function:

void logger::shutdown ( )

Definition at line 340 of file Logger.cpp.

References nvtx_helpers::shutdown().

Referenced by heartbeat(), EmbeddedDatabase::DBEngineImpl::reset(), TestProcessSignalHandler::shutdownSubsystemsAndExit(), startMapdServer(), and logger::LogShutdown::~LogShutdown().

340  {
341  static std::once_flag logger_flag;
342  std::call_once(logger_flag, []() {
343  boost::log::core::get()->remove_all_sinks();
345  });
346 }

+ Here is the call graph for this function:

+ Here is the caller graph for this function:

Variable Documentation

constexpr std::array<char const*, 3> logger::ChannelNames {"IR", "PTX", "ASM"}

Definition at line 79 of file Logger.h.

Referenced by operator<<(), and operator>>().

constexpr std::array<char, 3> logger::ChannelSymbols {'R', 'P', 'A'}

Definition at line 81 of file Logger.h.

bool logger::g_any_active_channels {false}

Definition at line 302 of file Logger.cpp.

Referenced by fast_logging_check(), and init().

std::mutex logger::g_duration_tree_map_mutex

Definition at line 592 of file Logger.cpp.

Referenced by debug_timer_new_thread(), logAndEraseDurationTree(), and newDuration().

std::once_flag logger::g_fatal_func_flag

Definition at line 285 of file Logger.cpp.

Referenced by logger::Logger::~Logger().

Severity logger::g_min_active_severity {Severity::FATAL}

Definition at line 303 of file Logger.cpp.

Referenced by fast_logging_check(), and init().

std::atomic<ThreadId> logger::g_next_thread_id {0}

Definition at line 594 of file Logger.cpp.

Referenced by debug_timer_new_thread().

thread_local std::atomic<QueryId> logger::g_query_id {0}
thread_local ThreadId logger::g_thread_id = g_next_thread_id++
constexpr std::array<char const*, 8> logger::SeverityNames
Initial value:
{"DEBUG4",
"DEBUG3",
"DEBUG2",
"DEBUG1",
"INFO",
"WARNING",
"ERROR",
"FATAL"}

Definition at line 101 of file Logger.h.

constexpr std::array<char, 8> logger::SeveritySymbols {'4', '3', '2', '1', 'I', 'W', 'E', 'F'}

Definition at line 110 of file Logger.h.