Log.cpp revision 355940
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 37using namespace lldb_private; 38 39llvm::ManagedStatic<Log::ChannelMap> Log::g_channel_map; 40 41void 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 50uint32_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 79void 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 91void 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 101const Flags Log::GetOptions() const { 102 return m_options.load(std::memory_order_relaxed); 103} 104 105const Flags Log::GetMask() const { 106 return m_mask.load(std::memory_order_relaxed); 107} 108 109void Log::PutCString(const char *cstr) { Printf("%s", cstr); } 110void Log::PutString(llvm::StringRef str) { PutCString(str.str().c_str()); } 111 112// Simple variable argument logging with flags. 113void 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. 123void 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. 137void Log::Error(const char *format, ...) { 138 va_list args; 139 va_start(args, format); 140 VAError(format, args); 141 va_end(args); 142} 143 144void 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. 152void 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. 163void 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 173void Log::Initialize() { 174#ifdef LLVM_ON_UNIX 175 pthread_atfork(nullptr, nullptr, &Log::DisableLoggingChild); 176#endif 177 InitializeLldbChannel(); 178} 179 180void 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 186void 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 193bool 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 209bool 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 224bool 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 235void Log::DisableAllLogChannels() { 236 for (auto &entry : *g_channel_map) 237 entry.second.Disable(UINT32_MAX); 238} 239 240void 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 250bool Log::GetVerbose() const { 251 return m_options.load(std::memory_order_relaxed) & LLDB_LOG_OPTION_VERBOSE; 252} 253 254void 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 296void 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 315void 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 324void 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} 331