lldb/source/Utility/Log.cpp

   1 //===-- Log.cpp -----------------------------------------------------------===//
   2 //
   3 // Part of the LLVM Project, under the Apache License v2.0 with LLVM Exceptions.
   4 // See https://llvm.org/LICENSE.txt for license information.
   5 // SPDX-License-Identifier: Apache-2.0 WITH LLVM-exception
   6 //
   7 //===----------------------------------------------------------------------===//
   8
   9 #include "lldb/Utility/Log.h"
  10 #include "lldb/Utility/VASPrintf.h"
  11
  12 #include "llvm/ADT/SmallString.h"
  13 #include "llvm/ADT/Twine.h"
  14 #include "llvm/ADT/iterator.h"
  15
  16 #include "llvm/Support/Casting.h"
  17 #include "llvm/Support/Chrono.h"
  18 #include "llvm/Support/ManagedStatic.h"
  19 #include "llvm/Support/Path.h"
  20 #include "llvm/Support/Signals.h"
  21 #include "llvm/Support/Threading.h"
  22 #include "llvm/Support/raw_ostream.h"
  23
  24 #include <chrono>
  25 #include <cstdarg>
  26 #include <mutex>
  27 #include <utility>
  28
  29 #include <cassert>
  30 #if defined(_WIN32)
  31 #include <process.h>
  32 #else
  33 #include <unistd.h>
  34 #endif
  35
  36 using namespace lldb_private;
  37
  38 char LogHandler::ID;
  39 char StreamLogHandler::ID;
  40 char CallbackLogHandler::ID;
  41 char RotatingLogHandler::ID;
  42
  43 llvm::ManagedStatic<Log::ChannelMap> Log::g_channel_map;
  44
  45 void Log::ForEachCategory(
  46     const Log::ChannelMap::value_type &entry,
  47     llvm::function_ref<void(llvm::StringRef, llvm::StringRef)> lambda) {
  48   lambda("all", "all available logging categories");
  49   lambda("default", "default set of logging categories");
  50   for (const auto &category : entry.second.m_channel.categories)
  51     lambda(category.name, category.description);
  52 }
  53
  54 void Log::ListCategories(llvm::raw_ostream &stream,
  55                          const ChannelMap::value_type &entry) {
  56   stream << llvm::formatv("Logging categories for '{0}':\n", entry.first());
  57   ForEachCategory(entry,
  58                   [&stream](llvm::StringRef name, llvm::StringRef description) {
  59                     stream << llvm::formatv("  {0} - {1}\n", name, description);
  60                   });
  61 }
  62
  63 Log::MaskType Log::GetFlags(llvm::raw_ostream &stream,
  64                             const ChannelMap::value_type &entry,
  65                             llvm::ArrayRef<const char *> categories) {
  66   bool list_categories = false;
  67   Log::MaskType flags = 0;
  68   for (const char *category : categories) {
  69     if (llvm::StringRef("all").equals_insensitive(category)) {
  70       flags |= std::numeric_limits<Log::MaskType>::max();
  71       continue;
  72     }
  73     if (llvm::StringRef("default").equals_insensitive(category)) {
  74       flags |= entry.second.m_channel.default_flags;
  75       continue;
  76     }
  77     auto cat = llvm::find_if(entry.second.m_channel.categories,
  78                              [&](const Log::Category &c) {
  79                                return c.name.equals_insensitive(category);
  80                              });
  81     if (cat != entry.second.m_channel.categories.end()) {
  82       flags |= cat->flag;
  83       continue;
  84     }
  85     stream << llvm::formatv("error: unrecognized log category '{0}'\n",
  86                             category);
  87     list_categories = true;
  88   }
  89   if (list_categories)
  90     ListCategories(stream, entry);
  91   return flags;
  92 }
  93
  94 void Log::Enable(const std::shared_ptr<LogHandler> &handler_sp,
  95                  uint32_t options, Log::MaskType flags) {
  96   llvm::sys::ScopedWriter lock(m_mutex);
  97
  98   MaskType mask = m_mask.fetch_or(flags, std::memory_order_relaxed);
  99   if (mask | flags) {
 100     m_options.store(options, std::memory_order_relaxed);
 101     m_handler = handler_sp;
 102     m_channel.log_ptr.store(this, std::memory_order_relaxed);
 103   }
 104 }
 105
 106 void Log::Disable(Log::MaskType flags) {
 107   llvm::sys::ScopedWriter lock(m_mutex);
 108
 109   MaskType mask = m_mask.fetch_and(~flags, std::memory_order_relaxed);
 110   if (!(mask & ~flags)) {
 111     m_handler.reset();
 112     m_channel.log_ptr.store(nullptr, std::memory_order_relaxed);
 113   }
 114 }
 115
 116 bool Log::Dump(llvm::raw_ostream &output_stream) {
 117   llvm::sys::ScopedReader lock(m_mutex);
 118   if (RotatingLogHandler *handler =
 119           llvm::dyn_cast_or_null<RotatingLogHandler>(m_handler.get())) {
 120     handler->Dump(output_stream);
 121     return true;
 122   }
 123   return false;
 124 }
 125
 126 const Flags Log::GetOptions() const {
 127   return m_options.load(std::memory_order_relaxed);
 128 }
 129
 130 Log::MaskType Log::GetMask() const {
 131   return m_mask.load(std::memory_order_relaxed);
 132 }
 133
 134 void Log::PutCString(const char *cstr) { PutString(cstr); }
 135
 136 void Log::PutString(llvm::StringRef str) {
 137   std::string FinalMessage;
 138   llvm::raw_string_ostream Stream(FinalMessage);
 139   WriteHeader(Stream, "", "");
 140   Stream << str << "\n";
 141   WriteMessage(FinalMessage);
 142 }
 143
 144 // Simple variable argument logging with flags.
 145 void Log::Printf(const char *format, ...) {
 146   va_list args;
 147   va_start(args, format);
 148   VAPrintf(format, args);
 149   va_end(args);
 150 }
 151
 152 void Log::VAPrintf(const char *format, va_list args) {
 153   llvm::SmallString<64> Content;
 154   lldb_private::VASprintf(Content, format, args);
 155   PutString(Content);
 156 }
 157
 158 void Log::Formatf(llvm::StringRef file, llvm::StringRef function,
 159                   const char *format, ...) {
 160   va_list args;
 161   va_start(args, format);
 162   VAFormatf(file, function, format, args);
 163   va_end(args);
 164 }
 165
 166 void Log::VAFormatf(llvm::StringRef file, llvm::StringRef function,
 167                     const char *format, va_list args) {
 168   llvm::SmallString<64> Content;
 169   lldb_private::VASprintf(Content, format, args);
 170   Format(file, function, llvm::formatv("{0}", Content));
 171 }
 172
 173 // Printing of errors that are not fatal.
 174 void Log::Error(const char *format, ...) {
 175   va_list args;
 176   va_start(args, format);
 177   VAError(format, args);
 178   va_end(args);
 179 }
 180
 181 void Log::VAError(const char *format, va_list args) {
 182   llvm::SmallString<64> Content;
 183   VASprintf(Content, format, args);
 184
 185   Printf("error: %s", Content.c_str());
 186 }
 187
 188 // Printing of warnings that are not fatal only if verbose mode is enabled.
 189 void Log::Verbose(const char *format, ...) {
 190   if (!GetVerbose())
 191     return;
 192
 193   va_list args;
 194   va_start(args, format);
 195   VAPrintf(format, args);
 196   va_end(args);
 197 }
 198
 199 // Printing of warnings that are not fatal.
 200 void Log::Warning(const char *format, ...) {
 201   llvm::SmallString<64> Content;
 202   va_list args;
 203   va_start(args, format);
 204   VASprintf(Content, format, args);
 205   va_end(args);
 206
 207   Printf("warning: %s", Content.c_str());
 208 }
 209
 210 void Log::Register(llvm::StringRef name, Channel &channel) {
 211   auto iter = g_channel_map->try_emplace(name, channel);
 212   assert(iter.second == true);
 213   (void)iter;
 214 }
 215
 216 void Log::Unregister(llvm::StringRef name) {
 217   auto iter = g_channel_map->find(name);
 218   assert(iter != g_channel_map->end());
 219   iter->second.Disable(std::numeric_limits<MaskType>::max());
 220   g_channel_map->erase(iter);
 221 }
 222
 223 bool Log::EnableLogChannel(const std::shared_ptr<LogHandler> &log_handler_sp,
 224                            uint32_t log_options, llvm::StringRef channel,
 225                            llvm::ArrayRef<const char *> categories,
 226                            llvm::raw_ostream &error_stream) {
 227   auto iter = g_channel_map->find(channel);
 228   if (iter == g_channel_map->end()) {
 229     error_stream << llvm::formatv("Invalid log channel '{0}'.\n", channel);
 230     return false;
 231   }
 232   MaskType flags = categories.empty()
 233                        ? iter->second.m_channel.default_flags
 234                        : GetFlags(error_stream, *iter, categories);
 235   iter->second.Enable(log_handler_sp, log_options, flags);
 236   return true;
 237 }
 238
 239 bool Log::DisableLogChannel(llvm::StringRef channel,
 240                             llvm::ArrayRef<const char *> categories,
 241                             llvm::raw_ostream &error_stream) {
 242   auto iter = g_channel_map->find(channel);
 243   if (iter == g_channel_map->end()) {
 244     error_stream << llvm::formatv("Invalid log channel '{0}'.\n", channel);
 245     return false;
 246   }
 247   MaskType flags = categories.empty()
 248                        ? std::numeric_limits<MaskType>::max()
 249                        : GetFlags(error_stream, *iter, categories);
 250   iter->second.Disable(flags);
 251   return true;
 252 }
 253
 254 bool Log::DumpLogChannel(llvm::StringRef channel,
 255                          llvm::raw_ostream &output_stream,
 256                          llvm::raw_ostream &error_stream) {
 257   auto iter = g_channel_map->find(channel);
 258   if (iter == g_channel_map->end()) {
 259     error_stream << llvm::formatv("Invalid log channel '{0}'.\n", channel);
 260     return false;
 261   }
 262   if (!iter->second.Dump(output_stream)) {
 263     error_stream << llvm::formatv(
 264         "log channel '{0}' does not support dumping.\n", channel);
 265     return false;
 266   }
 267   return true;
 268 }
 269
 270 bool Log::ListChannelCategories(llvm::StringRef channel,
 271                                 llvm::raw_ostream &stream) {
 272   auto ch = g_channel_map->find(channel);
 273   if (ch == g_channel_map->end()) {
 274     stream << llvm::formatv("Invalid log channel '{0}'.\n", channel);
 275     return false;
 276   }
 277   ListCategories(stream, *ch);
 278   return true;
 279 }
 280
 281 void Log::DisableAllLogChannels() {
 282   for (auto &entry : *g_channel_map)
 283     entry.second.Disable(std::numeric_limits<MaskType>::max());
 284 }
 285
 286 void Log::ForEachChannelCategory(
 287     llvm::StringRef channel,
 288     llvm::function_ref<void(llvm::StringRef, llvm::StringRef)> lambda) {
 289   auto ch = g_channel_map->find(channel);
 290   if (ch == g_channel_map->end())
 291     return;
 292
 293   ForEachCategory(*ch, lambda);
 294 }
 295
 296 std::vector<llvm::StringRef> Log::ListChannels() {
 297   std::vector<llvm::StringRef> result;
 298   for (const auto &channel : *g_channel_map)
 299     result.push_back(channel.first());
 300   return result;
 301 }
 302
 303 void Log::ListAllLogChannels(llvm::raw_ostream &stream) {
 304   if (g_channel_map->empty()) {
 305     stream << "No logging channels are currently registered.\n";
 306     return;
 307   }
 308
 309   for (const auto &channel : *g_channel_map)
 310     ListCategories(stream, channel);
 311 }
 312
 313 bool Log::GetVerbose() const {
 314   return m_options.load(std::memory_order_relaxed) & LLDB_LOG_OPTION_VERBOSE;
 315 }
 316
 317 void Log::WriteHeader(llvm::raw_ostream &OS, llvm::StringRef file,
 318                       llvm::StringRef function) {
 319   Flags options = GetOptions();
 320   static uint32_t g_sequence_id = 0;
 321   // Add a sequence ID if requested
 322   if (options.Test(LLDB_LOG_OPTION_PREPEND_SEQUENCE))
 323     OS << ++g_sequence_id << " ";
 324
 325   // Timestamp if requested
 326   if (options.Test(LLDB_LOG_OPTION_PREPEND_TIMESTAMP)) {
 327     auto now = std::chrono::duration<double>(
 328         std::chrono::system_clock::now().time_since_epoch());
 329     OS << llvm::formatv("{0:f9} ", now.count());
 330   }
 331
 332   // Add the process and thread if requested
 333   if (options.Test(LLDB_LOG_OPTION_PREPEND_PROC_AND_THREAD))
 334     OS << llvm::formatv("[{0,0+4}/{1,0+4}] ", getpid(),
 335                         llvm::get_threadid());
 336
 337   // Add the thread name if requested
 338   if (options.Test(LLDB_LOG_OPTION_PREPEND_THREAD_NAME)) {
 339     llvm::SmallString<32> thread_name;
 340     llvm::get_thread_name(thread_name);
 341
 342     llvm::SmallString<12> format_str;
 343     llvm::raw_svector_ostream format_os(format_str);
 344     format_os << "{0,-" << llvm::alignTo<16>(thread_name.size()) << "} ";
 345     OS << llvm::formatv(format_str.c_str(), thread_name);
 346   }
 347
 348   if (options.Test(LLDB_LOG_OPTION_BACKTRACE))
 349     llvm::sys::PrintStackTrace(OS);
 350
 351   if (options.Test(LLDB_LOG_OPTION_PREPEND_FILE_FUNCTION) &&
 352       (!file.empty() || !function.empty())) {
 353     file = llvm::sys::path::filename(file).take_front(40);
 354     function = function.take_front(40);
 355     OS << llvm::formatv("{0,-60:60} ", (file + ":" + function).str());
 356   }
 357 }
 358
 359 // If we have a callback registered, then we call the logging callback. If we
 360 // have a valid file handle, we also log to the file.
 361 void Log::WriteMessage(llvm::StringRef message) {
 362   // Make a copy of our stream shared pointer in case someone disables our log
 363   // while we are logging and releases the stream
 364   auto handler_sp = GetHandler();
 365   if (!handler_sp)
 366     return;
 367   handler_sp->Emit(message);
 368 }
 369
 370 void Log::Format(llvm::StringRef file, llvm::StringRef function,
 371                  const llvm::formatv_object_base &payload) {
 372   std::string message_string;
 373   llvm::raw_string_ostream message(message_string);
 374   WriteHeader(message, file, function);
 375   message << payload << "\n";
 376   WriteMessage(message.str());
 377 }
 378
 379 StreamLogHandler::StreamLogHandler(int fd, bool should_close,
 380                                    size_t buffer_size)
 381     : m_stream(fd, should_close, buffer_size == 0) {
 382   if (buffer_size > 0)
 383     m_stream.SetBufferSize(buffer_size);
 384 }
 385
 386 StreamLogHandler::~StreamLogHandler() { Flush(); }
 387
 388 void StreamLogHandler::Flush() {
 389   std::lock_guard<std::mutex> guard(m_mutex);
 390   m_stream.flush();
 391 }
 392
 393 void StreamLogHandler::Emit(llvm::StringRef message) {
 394   if (m_stream.GetBufferSize() > 0) {
 395     std::lock_guard<std::mutex> guard(m_mutex);
 396     m_stream << message;
 397   } else {
 398     m_stream << message;
 399   }
 400 }
 401
 402 CallbackLogHandler::CallbackLogHandler(lldb::LogOutputCallback callback,
 403                                        void *baton)
 404     : m_callback(callback), m_baton(baton) {}
 405
 406 void CallbackLogHandler::Emit(llvm::StringRef message) {
 407   m_callback(message.data(), m_baton);
 408 }
 409
 410 RotatingLogHandler::RotatingLogHandler(size_t size)
 411     : m_messages(std::make_unique<std::string[]>(size)), m_size(size) {}
 412
 413 void RotatingLogHandler::Emit(llvm::StringRef message) {
 414   std::lock_guard<std::mutex> guard(m_mutex);
 415   ++m_total_count;
 416   const size_t index = m_next_index;
 417   m_next_index = NormalizeIndex(index + 1);
 418   m_messages[index] = message.str();
 419 }
 420
 421 size_t RotatingLogHandler::NormalizeIndex(size_t i) const { return i % m_size; }
 422
 423 size_t RotatingLogHandler::GetNumMessages() const {
 424   return m_total_count < m_size ? m_total_count : m_size;
 425 }
 426
 427 size_t RotatingLogHandler::GetFirstMessageIndex() const {
 428   return m_total_count < m_size ? 0 : m_next_index;
 429 }
 430
 431 void RotatingLogHandler::Dump(llvm::raw_ostream &stream) const {
 432   std::lock_guard<std::mutex> guard(m_mutex);
 433   const size_t start_idx = GetFirstMessageIndex();
 434   const size_t stop_idx = start_idx + GetNumMessages();
 435   for (size_t i = start_idx; i < stop_idx; ++i) {
 436     const size_t idx = NormalizeIndex(i);
 437     stream << m_messages[idx];
 438   }
 439   stream.flush();
 440 }