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 36using namespace lldb_private; 37 38char LogHandler::ID; 39char StreamLogHandler::ID; 40char CallbackLogHandler::ID; 41char RotatingLogHandler::ID; 42 43llvm::ManagedStatic<Log::ChannelMap> Log::g_channel_map; 44 45void 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 54void 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 63Log::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 94void 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 106void 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 116bool 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 126const Flags Log::GetOptions() const { 127 return m_options.load(std::memory_order_relaxed); 128} 129 130Log::MaskType Log::GetMask() const { 131 return m_mask.load(std::memory_order_relaxed); 132} 133 134void Log::PutCString(const char *cstr) { PutString(cstr); } 135 136void 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. 145void Log::Printf(const char *format, ...) { 146 va_list args; 147 va_start(args, format); 148 VAPrintf(format, args); 149 va_end(args); 150} 151 152void 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 158void 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 166void 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. 174void Log::Error(const char *format, ...) { 175 va_list args; 176 va_start(args, format); 177 VAError(format, args); 178 va_end(args); 179} 180 181void 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. 189void 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. 200void 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 210void Log::Register(llvm::StringRef name, Channel &channel) { 211 auto iter = g_channel_map->try_emplace(name, channel); 212 assert(iter.second == true); 213 UNUSED_IF_ASSERT_DISABLED(iter); 214} 215 216void 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 223bool 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 239bool 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 254bool 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 270bool 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 281void Log::DisableAllLogChannels() { 282 for (auto &entry : *g_channel_map) 283 entry.second.Disable(std::numeric_limits<MaskType>::max()); 284} 285 286void 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 296std::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 303void 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 313bool Log::GetVerbose() const { 314 return m_options.load(std::memory_order_relaxed) & LLDB_LOG_OPTION_VERBOSE; 315} 316 317void 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. 361void 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 370void 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 379StreamLogHandler::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 386StreamLogHandler::~StreamLogHandler() { Flush(); } 387 388void StreamLogHandler::Flush() { 389 std::lock_guard<std::mutex> guard(m_mutex); 390 m_stream.flush(); 391} 392 393void 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 402CallbackLogHandler::CallbackLogHandler(lldb::LogOutputCallback callback, 403 void *baton) 404 : m_callback(callback), m_baton(baton) {} 405 406void CallbackLogHandler::Emit(llvm::StringRef message) { 407 m_callback(message.data(), m_baton); 408} 409 410RotatingLogHandler::RotatingLogHandler(size_t size) 411 : m_messages(std::make_unique<std::string[]>(size)), m_size(size) {} 412 413void 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 421size_t RotatingLogHandler::NormalizeIndex(size_t i) const { return i % m_size; } 422 423size_t RotatingLogHandler::GetNumMessages() const { 424 return m_total_count < m_size ? m_total_count : m_size; 425} 426 427size_t RotatingLogHandler::GetFirstMessageIndex() const { 428 return m_total_count < m_size ? 0 : m_next_index; 429} 430 431void 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} 441