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) { Printf("%s", cstr); } 135 void Log::PutString(llvm::StringRef str) { PutCString(str.str().c_str()); } 136 137 // Simple variable argument logging with flags. 138 void Log::Printf(const char *format, ...) { 139 va_list args; 140 va_start(args, format); 141 VAPrintf(format, args); 142 va_end(args); 143 } 144 145 // All logging eventually boils down to this function call. If we have a 146 // callback registered, then we call the logging callback. If we have a valid 147 // file handle, we also log to the file. 148 void Log::VAPrintf(const char *format, va_list args) { 149 llvm::SmallString<64> FinalMessage; 150 llvm::raw_svector_ostream Stream(FinalMessage); 151 WriteHeader(Stream, "", ""); 152 153 llvm::SmallString<64> Content; 154 lldb_private::VASprintf(Content, format, args); 155 156 Stream << Content << "\n"; 157 158 WriteMessage(std::string(FinalMessage.str())); 159 } 160 161 // Printing of errors that are not fatal. 162 void Log::Error(const char *format, ...) { 163 va_list args; 164 va_start(args, format); 165 VAError(format, args); 166 va_end(args); 167 } 168 169 void Log::VAError(const char *format, va_list args) { 170 llvm::SmallString<64> Content; 171 VASprintf(Content, format, args); 172 173 Printf("error: %s", Content.c_str()); 174 } 175 176 // Printing of warnings that are not fatal only if verbose mode is enabled. 177 void Log::Verbose(const char *format, ...) { 178 if (!GetVerbose()) 179 return; 180 181 va_list args; 182 va_start(args, format); 183 VAPrintf(format, args); 184 va_end(args); 185 } 186 187 // Printing of warnings that are not fatal. 188 void Log::Warning(const char *format, ...) { 189 llvm::SmallString<64> Content; 190 va_list args; 191 va_start(args, format); 192 VASprintf(Content, format, args); 193 va_end(args); 194 195 Printf("warning: %s", Content.c_str()); 196 } 197 198 void Log::Register(llvm::StringRef name, Channel &channel) { 199 auto iter = g_channel_map->try_emplace(name, channel); 200 assert(iter.second == true); 201 (void)iter; 202 } 203 204 void Log::Unregister(llvm::StringRef name) { 205 auto iter = g_channel_map->find(name); 206 assert(iter != g_channel_map->end()); 207 iter->second.Disable(std::numeric_limits<MaskType>::max()); 208 g_channel_map->erase(iter); 209 } 210 211 bool Log::EnableLogChannel(const std::shared_ptr<LogHandler> &log_handler_sp, 212 uint32_t log_options, llvm::StringRef channel, 213 llvm::ArrayRef<const char *> categories, 214 llvm::raw_ostream &error_stream) { 215 auto iter = g_channel_map->find(channel); 216 if (iter == g_channel_map->end()) { 217 error_stream << llvm::formatv("Invalid log channel '{0}'.\n", channel); 218 return false; 219 } 220 MaskType flags = categories.empty() 221 ? iter->second.m_channel.default_flags 222 : GetFlags(error_stream, *iter, categories); 223 iter->second.Enable(log_handler_sp, log_options, flags); 224 return true; 225 } 226 227 bool Log::DisableLogChannel(llvm::StringRef channel, 228 llvm::ArrayRef<const char *> categories, 229 llvm::raw_ostream &error_stream) { 230 auto iter = g_channel_map->find(channel); 231 if (iter == g_channel_map->end()) { 232 error_stream << llvm::formatv("Invalid log channel '{0}'.\n", channel); 233 return false; 234 } 235 MaskType flags = categories.empty() 236 ? std::numeric_limits<MaskType>::max() 237 : GetFlags(error_stream, *iter, categories); 238 iter->second.Disable(flags); 239 return true; 240 } 241 242 bool Log::DumpLogChannel(llvm::StringRef channel, 243 llvm::raw_ostream &output_stream, 244 llvm::raw_ostream &error_stream) { 245 auto iter = g_channel_map->find(channel); 246 if (iter == g_channel_map->end()) { 247 error_stream << llvm::formatv("Invalid log channel '{0}'.\n", channel); 248 return false; 249 } 250 if (!iter->second.Dump(output_stream)) { 251 error_stream << llvm::formatv( 252 "log channel '{0}' does not support dumping.\n", channel); 253 return false; 254 } 255 return true; 256 } 257 258 bool Log::ListChannelCategories(llvm::StringRef channel, 259 llvm::raw_ostream &stream) { 260 auto ch = g_channel_map->find(channel); 261 if (ch == g_channel_map->end()) { 262 stream << llvm::formatv("Invalid log channel '{0}'.\n", channel); 263 return false; 264 } 265 ListCategories(stream, *ch); 266 return true; 267 } 268 269 void Log::DisableAllLogChannels() { 270 for (auto &entry : *g_channel_map) 271 entry.second.Disable(std::numeric_limits<MaskType>::max()); 272 } 273 274 void Log::ForEachChannelCategory( 275 llvm::StringRef channel, 276 llvm::function_ref<void(llvm::StringRef, llvm::StringRef)> lambda) { 277 auto ch = g_channel_map->find(channel); 278 if (ch == g_channel_map->end()) 279 return; 280 281 ForEachCategory(*ch, lambda); 282 } 283 284 std::vector<llvm::StringRef> Log::ListChannels() { 285 std::vector<llvm::StringRef> result; 286 for (const auto &channel : *g_channel_map) 287 result.push_back(channel.first()); 288 return result; 289 } 290 291 void Log::ListAllLogChannels(llvm::raw_ostream &stream) { 292 if (g_channel_map->empty()) { 293 stream << "No logging channels are currently registered.\n"; 294 return; 295 } 296 297 for (const auto &channel : *g_channel_map) 298 ListCategories(stream, channel); 299 } 300 301 bool Log::GetVerbose() const { 302 return m_options.load(std::memory_order_relaxed) & LLDB_LOG_OPTION_VERBOSE; 303 } 304 305 void Log::WriteHeader(llvm::raw_ostream &OS, llvm::StringRef file, 306 llvm::StringRef function) { 307 Flags options = GetOptions(); 308 static uint32_t g_sequence_id = 0; 309 // Add a sequence ID if requested 310 if (options.Test(LLDB_LOG_OPTION_PREPEND_SEQUENCE)) 311 OS << ++g_sequence_id << " "; 312 313 // Timestamp if requested 314 if (options.Test(LLDB_LOG_OPTION_PREPEND_TIMESTAMP)) { 315 auto now = std::chrono::duration<double>( 316 std::chrono::system_clock::now().time_since_epoch()); 317 OS << llvm::formatv("{0:f9} ", now.count()); 318 } 319 320 // Add the process and thread if requested 321 if (options.Test(LLDB_LOG_OPTION_PREPEND_PROC_AND_THREAD)) 322 OS << llvm::formatv("[{0,0+4}/{1,0+4}] ", getpid(), 323 llvm::get_threadid()); 324 325 // Add the thread name if requested 326 if (options.Test(LLDB_LOG_OPTION_PREPEND_THREAD_NAME)) { 327 llvm::SmallString<32> thread_name; 328 llvm::get_thread_name(thread_name); 329 330 llvm::SmallString<12> format_str; 331 llvm::raw_svector_ostream format_os(format_str); 332 format_os << "{0,-" << llvm::alignTo<16>(thread_name.size()) << "} "; 333 OS << llvm::formatv(format_str.c_str(), thread_name); 334 } 335 336 if (options.Test(LLDB_LOG_OPTION_BACKTRACE)) 337 llvm::sys::PrintStackTrace(OS); 338 339 if (options.Test(LLDB_LOG_OPTION_PREPEND_FILE_FUNCTION) && 340 (!file.empty() || !function.empty())) { 341 file = llvm::sys::path::filename(file).take_front(40); 342 function = function.take_front(40); 343 OS << llvm::formatv("{0,-60:60} ", (file + ":" + function).str()); 344 } 345 } 346 347 void Log::WriteMessage(const std::string &message) { 348 // Make a copy of our stream shared pointer in case someone disables our log 349 // while we are logging and releases the stream 350 auto handler_sp = GetHandler(); 351 if (!handler_sp) 352 return; 353 handler_sp->Emit(message); 354 } 355 356 void Log::Format(llvm::StringRef file, llvm::StringRef function, 357 const llvm::formatv_object_base &payload) { 358 std::string message_string; 359 llvm::raw_string_ostream message(message_string); 360 WriteHeader(message, file, function); 361 message << payload << "\n"; 362 WriteMessage(message.str()); 363 } 364 365 StreamLogHandler::StreamLogHandler(int fd, bool should_close, 366 size_t buffer_size) 367 : m_stream(fd, should_close, buffer_size == 0) { 368 if (buffer_size > 0) 369 m_stream.SetBufferSize(buffer_size); 370 } 371 372 StreamLogHandler::~StreamLogHandler() { Flush(); } 373 374 void StreamLogHandler::Flush() { 375 std::lock_guard<std::mutex> guard(m_mutex); 376 m_stream.flush(); 377 } 378 379 void StreamLogHandler::Emit(llvm::StringRef message) { 380 if (m_stream.GetBufferSize() > 0) { 381 std::lock_guard<std::mutex> guard(m_mutex); 382 m_stream << message; 383 } else { 384 m_stream << message; 385 } 386 } 387 388 CallbackLogHandler::CallbackLogHandler(lldb::LogOutputCallback callback, 389 void *baton) 390 : m_callback(callback), m_baton(baton) {} 391 392 void CallbackLogHandler::Emit(llvm::StringRef message) { 393 m_callback(message.data(), m_baton); 394 } 395 396 RotatingLogHandler::RotatingLogHandler(size_t size) 397 : m_messages(std::make_unique<std::string[]>(size)), m_size(size) {} 398 399 void RotatingLogHandler::Emit(llvm::StringRef message) { 400 std::lock_guard<std::mutex> guard(m_mutex); 401 ++m_total_count; 402 const size_t index = m_next_index; 403 m_next_index = NormalizeIndex(index + 1); 404 m_messages[index] = message.str(); 405 } 406 407 size_t RotatingLogHandler::NormalizeIndex(size_t i) const { return i % m_size; } 408 409 size_t RotatingLogHandler::GetNumMessages() const { 410 return m_total_count < m_size ? m_total_count : m_size; 411 } 412 413 size_t RotatingLogHandler::GetFirstMessageIndex() const { 414 return m_total_count < m_size ? 0 : m_next_index; 415 } 416 417 void RotatingLogHandler::Dump(llvm::raw_ostream &stream) const { 418 std::lock_guard<std::mutex> guard(m_mutex); 419 const size_t start_idx = GetFirstMessageIndex(); 420 const size_t stop_idx = start_idx + GetNumMessages(); 421 for (size_t i = start_idx; i < stop_idx; ++i) { 422 const size_t idx = NormalizeIndex(i); 423 stream << m_messages[idx]; 424 } 425 stream.flush(); 426 } 427