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