contrib/llvm/tools/lldb/source/Utility/Log.cpp

   1 //===-- Log.cpp -------------------------------------------------*- C++ -*-===//
   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/STLExtras.h"
  13 #include "llvm/ADT/SmallString.h"
  14 #include "llvm/ADT/Twine.h"
  15 #include "llvm/ADT/iterator.h"
  16
  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 <assert.h>
  30 #if defined(_WIN32)
  31 #include <process.h>
  32 #else
  33 #include <unistd.h>
  34 #include <pthread.h>
  35 #endif
  36
  37 using namespace lldb_private;
  38
  39 llvm::ManagedStatic<Log::ChannelMap> Log::g_channel_map;
  40
  41 void Log::ListCategories(llvm::raw_ostream &stream, const ChannelMap::value_type &entry) {
  42   stream << llvm::formatv("Logging categories for '{0}':\n", entry.first());
  43   stream << "  all - all available logging categories\n";
  44   stream << "  default - default set of logging categories\n";
  45   for (const auto &category : entry.second.m_channel.categories)
  46     stream << llvm::formatv("  {0} - {1}\n", category.name,
  47                             category.description);
  48 }
  49
  50 uint32_t Log::GetFlags(llvm::raw_ostream &stream, const ChannelMap::value_type &entry,
  51                          llvm::ArrayRef<const char *> categories) {
  52   bool list_categories = false;
  53   uint32_t flags = 0;
  54   for (const char *category : categories) {
  55     if (llvm::StringRef("all").equals_lower(category)) {
  56       flags |= UINT32_MAX;
  57       continue;
  58     }
  59     if (llvm::StringRef("default").equals_lower(category)) {
  60       flags |= entry.second.m_channel.default_flags;
  61       continue;
  62     }
  63     auto cat = llvm::find_if(
  64         entry.second.m_channel.categories,
  65         [&](const Log::Category &c) { return c.name.equals_lower(category); });
  66     if (cat != entry.second.m_channel.categories.end()) {
  67       flags |= cat->flag;
  68       continue;
  69     }
  70     stream << llvm::formatv("error: unrecognized log category '{0}'\n",
  71                             category);
  72     list_categories = true;
  73   }
  74   if (list_categories)
  75     ListCategories(stream, entry);
  76   return flags;
  77 }
  78
  79 void Log::Enable(const std::shared_ptr<llvm::raw_ostream> &stream_sp,
  80                  uint32_t options, uint32_t flags) {
  81   llvm::sys::ScopedWriter lock(m_mutex);
  82
  83   uint32_t mask = m_mask.fetch_or(flags, std::memory_order_relaxed);
  84   if (mask | flags) {
  85     m_options.store(options, std::memory_order_relaxed);
  86     m_stream_sp = stream_sp;
  87     m_channel.log_ptr.store(this, std::memory_order_relaxed);
  88   }
  89 }
  90
  91 void Log::Disable(uint32_t flags) {
  92   llvm::sys::ScopedWriter lock(m_mutex);
  93
  94   uint32_t mask = m_mask.fetch_and(~flags, std::memory_order_relaxed);
  95   if (!(mask & ~flags)) {
  96     m_stream_sp.reset();
  97     m_channel.log_ptr.store(nullptr, std::memory_order_relaxed);
  98   }
  99 }
 100
 101 const Flags Log::GetOptions() const {
 102   return m_options.load(std::memory_order_relaxed);
 103 }
 104
 105 const Flags Log::GetMask() const {
 106   return m_mask.load(std::memory_order_relaxed);
 107 }
 108
 109 void Log::PutCString(const char *cstr) { Printf("%s", cstr); }
 110 void Log::PutString(llvm::StringRef str) { PutCString(str.str().c_str()); }
 111
 112 // Simple variable argument logging with flags.
 113 void Log::Printf(const char *format, ...) {
 114   va_list args;
 115   va_start(args, format);
 116   VAPrintf(format, args);
 117   va_end(args);
 118 }
 119
 120 // All logging eventually boils down to this function call. If we have a
 121 // callback registered, then we call the logging callback. If we have a valid
 122 // file handle, we also log to the file.
 123 void Log::VAPrintf(const char *format, va_list args) {
 124   llvm::SmallString<64> FinalMessage;
 125   llvm::raw_svector_ostream Stream(FinalMessage);
 126   WriteHeader(Stream, "", "");
 127
 128   llvm::SmallString<64> Content;
 129   lldb_private::VASprintf(Content, format, args);
 130
 131   Stream << Content << "\n";
 132
 133   WriteMessage(FinalMessage.str());
 134 }
 135
 136 // Printing of errors that are not fatal.
 137 void Log::Error(const char *format, ...) {
 138   va_list args;
 139   va_start(args, format);
 140   VAError(format, args);
 141   va_end(args);
 142 }
 143
 144 void Log::VAError(const char *format, va_list args) {
 145   llvm::SmallString<64> Content;
 146   VASprintf(Content, format, args);
 147
 148   Printf("error: %s", Content.c_str());
 149 }
 150
 151 // Printing of warnings that are not fatal only if verbose mode is enabled.
 152 void Log::Verbose(const char *format, ...) {
 153   if (!GetVerbose())
 154     return;
 155
 156   va_list args;
 157   va_start(args, format);
 158   VAPrintf(format, args);
 159   va_end(args);
 160 }
 161
 162 // Printing of warnings that are not fatal.
 163 void Log::Warning(const char *format, ...) {
 164   llvm::SmallString<64> Content;
 165   va_list args;
 166   va_start(args, format);
 167   VASprintf(Content, format, args);
 168   va_end(args);
 169
 170   Printf("warning: %s", Content.c_str());
 171 }
 172
 173 void Log::Initialize() {
 174 #ifdef LLVM_ON_UNIX
 175   pthread_atfork(nullptr, nullptr, &Log::DisableLoggingChild);
 176 #endif
 177   InitializeLldbChannel();
 178 }
 179
 180 void Log::Register(llvm::StringRef name, Channel &channel) {
 181   auto iter = g_channel_map->try_emplace(name, channel);
 182   assert(iter.second == true);
 183   (void)iter;
 184 }
 185
 186 void Log::Unregister(llvm::StringRef name) {
 187   auto iter = g_channel_map->find(name);
 188   assert(iter != g_channel_map->end());
 189   iter->second.Disable(UINT32_MAX);
 190   g_channel_map->erase(iter);
 191 }
 192
 193 bool Log::EnableLogChannel(
 194     const std::shared_ptr<llvm::raw_ostream> &log_stream_sp,
 195     uint32_t log_options, llvm::StringRef channel,
 196     llvm::ArrayRef<const char *> categories, llvm::raw_ostream &error_stream) {
 197   auto iter = g_channel_map->find(channel);
 198   if (iter == g_channel_map->end()) {
 199     error_stream << llvm::formatv("Invalid log channel '{0}'.\n", channel);
 200     return false;
 201   }
 202   uint32_t flags = categories.empty()
 203                        ? iter->second.m_channel.default_flags
 204                        : GetFlags(error_stream, *iter, categories);
 205   iter->second.Enable(log_stream_sp, log_options, flags);
 206   return true;
 207 }
 208
 209 bool Log::DisableLogChannel(llvm::StringRef channel,
 210                             llvm::ArrayRef<const char *> categories,
 211                             llvm::raw_ostream &error_stream) {
 212   auto iter = g_channel_map->find(channel);
 213   if (iter == g_channel_map->end()) {
 214     error_stream << llvm::formatv("Invalid log channel '{0}'.\n", channel);
 215     return false;
 216   }
 217   uint32_t flags = categories.empty()
 218                        ? UINT32_MAX
 219                        : GetFlags(error_stream, *iter, categories);
 220   iter->second.Disable(flags);
 221   return true;
 222 }
 223
 224 bool Log::ListChannelCategories(llvm::StringRef channel,
 225                                 llvm::raw_ostream &stream) {
 226   auto ch = g_channel_map->find(channel);
 227   if (ch == g_channel_map->end()) {
 228     stream << llvm::formatv("Invalid log channel '{0}'.\n", channel);
 229     return false;
 230   }
 231   ListCategories(stream, *ch);
 232   return true;
 233 }
 234
 235 void Log::DisableAllLogChannels() {
 236   for (auto &entry : *g_channel_map)
 237     entry.second.Disable(UINT32_MAX);
 238 }
 239
 240 void Log::ListAllLogChannels(llvm::raw_ostream &stream) {
 241   if (g_channel_map->empty()) {
 242     stream << "No logging channels are currently registered.\n";
 243     return;
 244   }
 245
 246   for (const auto &channel : *g_channel_map)
 247     ListCategories(stream, channel);
 248 }
 249
 250 bool Log::GetVerbose() const {
 251   return m_options.load(std::memory_order_relaxed) & LLDB_LOG_OPTION_VERBOSE;
 252 }
 253
 254 void Log::WriteHeader(llvm::raw_ostream &OS, llvm::StringRef file,
 255                       llvm::StringRef function) {
 256   Flags options = GetOptions();
 257   static uint32_t g_sequence_id = 0;
 258   // Add a sequence ID if requested
 259   if (options.Test(LLDB_LOG_OPTION_PREPEND_SEQUENCE))
 260     OS << ++g_sequence_id << " ";
 261
 262   // Timestamp if requested
 263   if (options.Test(LLDB_LOG_OPTION_PREPEND_TIMESTAMP)) {
 264     auto now = std::chrono::duration<double>(
 265         std::chrono::system_clock::now().time_since_epoch());
 266     OS << llvm::formatv("{0:f9} ", now.count());
 267   }
 268
 269   // Add the process and thread if requested
 270   if (options.Test(LLDB_LOG_OPTION_PREPEND_PROC_AND_THREAD))
 271     OS << llvm::formatv("[{0,0+4}/{1,0+4}] ", getpid(),
 272                         llvm::get_threadid());
 273
 274   // Add the thread name if requested
 275   if (options.Test(LLDB_LOG_OPTION_PREPEND_THREAD_NAME)) {
 276     llvm::SmallString<32> thread_name;
 277     llvm::get_thread_name(thread_name);
 278
 279     llvm::SmallString<12> format_str;
 280     llvm::raw_svector_ostream format_os(format_str);
 281     format_os << "{0,-" << llvm::alignTo<16>(thread_name.size()) << "} ";
 282     OS << llvm::formatv(format_str.c_str(), thread_name);
 283   }
 284
 285   if (options.Test(LLDB_LOG_OPTION_BACKTRACE))
 286     llvm::sys::PrintStackTrace(OS);
 287
 288   if (options.Test(LLDB_LOG_OPTION_PREPEND_FILE_FUNCTION) &&
 289       (!file.empty() || !function.empty())) {
 290     file = llvm::sys::path::filename(file).take_front(40);
 291     function = function.take_front(40);
 292     OS << llvm::formatv("{0,-60:60} ", (file + ":" + function).str());
 293   }
 294 }
 295
 296 void Log::WriteMessage(const std::string &message) {
 297   // Make a copy of our stream shared pointer in case someone disables our log
 298   // while we are logging and releases the stream
 299   auto stream_sp = GetStream();
 300   if (!stream_sp)
 301     return;
 302
 303   Flags options = GetOptions();
 304   if (options.Test(LLDB_LOG_OPTION_THREADSAFE)) {
 305     static std::recursive_mutex g_LogThreadedMutex;
 306     std::lock_guard<std::recursive_mutex> guard(g_LogThreadedMutex);
 307     *stream_sp << message;
 308     stream_sp->flush();
 309   } else {
 310     *stream_sp << message;
 311     stream_sp->flush();
 312   }
 313 }
 314
 315 void Log::Format(llvm::StringRef file, llvm::StringRef function,
 316                  const llvm::formatv_object_base &payload) {
 317   std::string message_string;
 318   llvm::raw_string_ostream message(message_string);
 319   WriteHeader(message, file, function);
 320   message << payload << "\n";
 321   WriteMessage(message.str());
 322 }
 323
 324 void Log::DisableLoggingChild() {
 325   // Disable logging by clearing out the atomic variable after forking -- if we
 326   // forked while another thread held the channel mutex, we would deadlock when
 327   // trying to write to the log.
 328   for (auto &c: *g_channel_map)
 329     c.second.m_channel.log_ptr.store(nullptr, std::memory_order_relaxed);
 330 }