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