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