1239281Sgonzo//===-- Log.cpp -------------------------------------------------*- C++ -*-===// 2239281Sgonzo// 3239281Sgonzo// Part of the LLVM Project, under the Apache License v2.0 with LLVM Exceptions. 4239281Sgonzo// See https://llvm.org/LICENSE.txt for license information. 5239281Sgonzo// SPDX-License-Identifier: Apache-2.0 WITH LLVM-exception 6239281Sgonzo// 7239281Sgonzo//===----------------------------------------------------------------------===// 8239281Sgonzo 9239281Sgonzo#include "lldb/Utility/Log.h" 10239281Sgonzo#include "lldb/Utility/VASPrintf.h" 11239281Sgonzo 12239281Sgonzo#include "llvm/ADT/SmallString.h" 13239281Sgonzo#include "llvm/ADT/Twine.h" 14239281Sgonzo#include "llvm/ADT/iterator.h" 15239281Sgonzo 16239281Sgonzo#include "llvm/Support/Chrono.h" 17239281Sgonzo#include "llvm/Support/ManagedStatic.h" 18239281Sgonzo#include "llvm/Support/Path.h" 19239281Sgonzo#include "llvm/Support/Signals.h" 20239281Sgonzo#include "llvm/Support/Threading.h" 21239281Sgonzo#include "llvm/Support/raw_ostream.h" 22239281Sgonzo 23239281Sgonzo#include <chrono> 24239281Sgonzo#include <cstdarg> 25239281Sgonzo#include <mutex> 26239281Sgonzo#include <utility> 27239281Sgonzo 28239281Sgonzo#include <assert.h> 29239281Sgonzo#if defined(_WIN32) 30239281Sgonzo#include <process.h> 31239281Sgonzo#else 32239281Sgonzo#include <unistd.h> 33239281Sgonzo#include <pthread.h> 34#endif 35 36using namespace lldb_private; 37 38llvm::ManagedStatic<Log::ChannelMap> Log::g_channel_map; 39 40void Log::ForEachCategory( 41 const Log::ChannelMap::value_type &entry, 42 llvm::function_ref<void(llvm::StringRef, llvm::StringRef)> lambda) { 43 lambda("all", "all available logging categories"); 44 lambda("default", "default set of logging categories"); 45 for (const auto &category : entry.second.m_channel.categories) 46 lambda(category.name, category.description); 47} 48 49void Log::ListCategories(llvm::raw_ostream &stream, 50 const ChannelMap::value_type &entry) { 51 stream << llvm::formatv("Logging categories for '{0}':\n", entry.first()); 52 ForEachCategory(entry, 53 [&stream](llvm::StringRef name, llvm::StringRef description) { 54 stream << llvm::formatv(" {0} - {1}\n", name, description); 55 }); 56} 57 58uint32_t Log::GetFlags(llvm::raw_ostream &stream, const ChannelMap::value_type &entry, 59 llvm::ArrayRef<const char *> categories) { 60 bool list_categories = false; 61 uint32_t flags = 0; 62 for (const char *category : categories) { 63 if (llvm::StringRef("all").equals_lower(category)) { 64 flags |= UINT32_MAX; 65 continue; 66 } 67 if (llvm::StringRef("default").equals_lower(category)) { 68 flags |= entry.second.m_channel.default_flags; 69 continue; 70 } 71 auto cat = llvm::find_if( 72 entry.second.m_channel.categories, 73 [&](const Log::Category &c) { return c.name.equals_lower(category); }); 74 if (cat != entry.second.m_channel.categories.end()) { 75 flags |= cat->flag; 76 continue; 77 } 78 stream << llvm::formatv("error: unrecognized log category '{0}'\n", 79 category); 80 list_categories = true; 81 } 82 if (list_categories) 83 ListCategories(stream, entry); 84 return flags; 85} 86 87void Log::Enable(const std::shared_ptr<llvm::raw_ostream> &stream_sp, 88 uint32_t options, uint32_t flags) { 89 llvm::sys::ScopedWriter lock(m_mutex); 90 91 uint32_t mask = m_mask.fetch_or(flags, std::memory_order_relaxed); 92 if (mask | flags) { 93 m_options.store(options, std::memory_order_relaxed); 94 m_stream_sp = stream_sp; 95 m_channel.log_ptr.store(this, std::memory_order_relaxed); 96 } 97} 98 99void Log::Disable(uint32_t flags) { 100 llvm::sys::ScopedWriter lock(m_mutex); 101 102 uint32_t mask = m_mask.fetch_and(~flags, std::memory_order_relaxed); 103 if (!(mask & ~flags)) { 104 m_stream_sp.reset(); 105 m_channel.log_ptr.store(nullptr, std::memory_order_relaxed); 106 } 107} 108 109const Flags Log::GetOptions() const { 110 return m_options.load(std::memory_order_relaxed); 111} 112 113const Flags Log::GetMask() const { 114 return m_mask.load(std::memory_order_relaxed); 115} 116 117void Log::PutCString(const char *cstr) { Printf("%s", cstr); } 118void Log::PutString(llvm::StringRef str) { PutCString(str.str().c_str()); } 119 120// Simple variable argument logging with flags. 121void Log::Printf(const char *format, ...) { 122 va_list args; 123 va_start(args, format); 124 VAPrintf(format, args); 125 va_end(args); 126} 127 128// All logging eventually boils down to this function call. If we have a 129// callback registered, then we call the logging callback. If we have a valid 130// file handle, we also log to the file. 131void Log::VAPrintf(const char *format, va_list args) { 132 llvm::SmallString<64> FinalMessage; 133 llvm::raw_svector_ostream Stream(FinalMessage); 134 WriteHeader(Stream, "", ""); 135 136 llvm::SmallString<64> Content; 137 lldb_private::VASprintf(Content, format, args); 138 139 Stream << Content << "\n"; 140 141 WriteMessage(FinalMessage.str()); 142} 143 144// Printing of errors that are not fatal. 145void Log::Error(const char *format, ...) { 146 va_list args; 147 va_start(args, format); 148 VAError(format, args); 149 va_end(args); 150} 151 152void Log::VAError(const char *format, va_list args) { 153 llvm::SmallString<64> Content; 154 VASprintf(Content, format, args); 155 156 Printf("error: %s", Content.c_str()); 157} 158 159// Printing of warnings that are not fatal only if verbose mode is enabled. 160void Log::Verbose(const char *format, ...) { 161 if (!GetVerbose()) 162 return; 163 164 va_list args; 165 va_start(args, format); 166 VAPrintf(format, args); 167 va_end(args); 168} 169 170// Printing of warnings that are not fatal. 171void Log::Warning(const char *format, ...) { 172 llvm::SmallString<64> Content; 173 va_list args; 174 va_start(args, format); 175 VASprintf(Content, format, args); 176 va_end(args); 177 178 Printf("warning: %s", Content.c_str()); 179} 180 181void Log::Initialize() { 182#ifdef LLVM_ON_UNIX 183 pthread_atfork(nullptr, nullptr, &Log::DisableLoggingChild); 184#endif 185 InitializeLldbChannel(); 186} 187 188void Log::Register(llvm::StringRef name, Channel &channel) { 189 auto iter = g_channel_map->try_emplace(name, channel); 190 assert(iter.second == true); 191 (void)iter; 192} 193 194void Log::Unregister(llvm::StringRef name) { 195 auto iter = g_channel_map->find(name); 196 assert(iter != g_channel_map->end()); 197 iter->second.Disable(UINT32_MAX); 198 g_channel_map->erase(iter); 199} 200 201bool Log::EnableLogChannel( 202 const std::shared_ptr<llvm::raw_ostream> &log_stream_sp, 203 uint32_t log_options, llvm::StringRef channel, 204 llvm::ArrayRef<const char *> categories, llvm::raw_ostream &error_stream) { 205 auto iter = g_channel_map->find(channel); 206 if (iter == g_channel_map->end()) { 207 error_stream << llvm::formatv("Invalid log channel '{0}'.\n", channel); 208 return false; 209 } 210 uint32_t flags = categories.empty() 211 ? iter->second.m_channel.default_flags 212 : GetFlags(error_stream, *iter, categories); 213 iter->second.Enable(log_stream_sp, log_options, flags); 214 return true; 215} 216 217bool Log::DisableLogChannel(llvm::StringRef channel, 218 llvm::ArrayRef<const char *> categories, 219 llvm::raw_ostream &error_stream) { 220 auto iter = g_channel_map->find(channel); 221 if (iter == g_channel_map->end()) { 222 error_stream << llvm::formatv("Invalid log channel '{0}'.\n", channel); 223 return false; 224 } 225 uint32_t flags = categories.empty() 226 ? UINT32_MAX 227 : GetFlags(error_stream, *iter, categories); 228 iter->second.Disable(flags); 229 return true; 230} 231 232bool Log::ListChannelCategories(llvm::StringRef channel, 233 llvm::raw_ostream &stream) { 234 auto ch = g_channel_map->find(channel); 235 if (ch == g_channel_map->end()) { 236 stream << llvm::formatv("Invalid log channel '{0}'.\n", channel); 237 return false; 238 } 239 ListCategories(stream, *ch); 240 return true; 241} 242 243void Log::DisableAllLogChannels() { 244 for (auto &entry : *g_channel_map) 245 entry.second.Disable(UINT32_MAX); 246} 247 248void Log::ForEachChannelCategory( 249 llvm::StringRef channel, 250 llvm::function_ref<void(llvm::StringRef, llvm::StringRef)> lambda) { 251 auto ch = g_channel_map->find(channel); 252 if (ch == g_channel_map->end()) 253 return; 254 255 ForEachCategory(*ch, lambda); 256} 257 258std::vector<llvm::StringRef> Log::ListChannels() { 259 std::vector<llvm::StringRef> result; 260 for (const auto &channel : *g_channel_map) 261 result.push_back(channel.first()); 262 return result; 263} 264 265void Log::ListAllLogChannels(llvm::raw_ostream &stream) { 266 if (g_channel_map->empty()) { 267 stream << "No logging channels are currently registered.\n"; 268 return; 269 } 270 271 for (const auto &channel : *g_channel_map) 272 ListCategories(stream, channel); 273} 274 275bool Log::GetVerbose() const { 276 return m_options.load(std::memory_order_relaxed) & LLDB_LOG_OPTION_VERBOSE; 277} 278 279void Log::WriteHeader(llvm::raw_ostream &OS, llvm::StringRef file, 280 llvm::StringRef function) { 281 Flags options = GetOptions(); 282 static uint32_t g_sequence_id = 0; 283 // Add a sequence ID if requested 284 if (options.Test(LLDB_LOG_OPTION_PREPEND_SEQUENCE)) 285 OS << ++g_sequence_id << " "; 286 287 // Timestamp if requested 288 if (options.Test(LLDB_LOG_OPTION_PREPEND_TIMESTAMP)) { 289 auto now = std::chrono::duration<double>( 290 std::chrono::system_clock::now().time_since_epoch()); 291 OS << llvm::formatv("{0:f9} ", now.count()); 292 } 293 294 // Add the process and thread if requested 295 if (options.Test(LLDB_LOG_OPTION_PREPEND_PROC_AND_THREAD)) 296 OS << llvm::formatv("[{0,0+4}/{1,0+4}] ", getpid(), 297 llvm::get_threadid()); 298 299 // Add the thread name if requested 300 if (options.Test(LLDB_LOG_OPTION_PREPEND_THREAD_NAME)) { 301 llvm::SmallString<32> thread_name; 302 llvm::get_thread_name(thread_name); 303 304 llvm::SmallString<12> format_str; 305 llvm::raw_svector_ostream format_os(format_str); 306 format_os << "{0,-" << llvm::alignTo<16>(thread_name.size()) << "} "; 307 OS << llvm::formatv(format_str.c_str(), thread_name); 308 } 309 310 if (options.Test(LLDB_LOG_OPTION_BACKTRACE)) 311 llvm::sys::PrintStackTrace(OS); 312 313 if (options.Test(LLDB_LOG_OPTION_PREPEND_FILE_FUNCTION) && 314 (!file.empty() || !function.empty())) { 315 file = llvm::sys::path::filename(file).take_front(40); 316 function = function.take_front(40); 317 OS << llvm::formatv("{0,-60:60} ", (file + ":" + function).str()); 318 } 319} 320 321void Log::WriteMessage(const std::string &message) { 322 // Make a copy of our stream shared pointer in case someone disables our log 323 // while we are logging and releases the stream 324 auto stream_sp = GetStream(); 325 if (!stream_sp) 326 return; 327 328 Flags options = GetOptions(); 329 if (options.Test(LLDB_LOG_OPTION_THREADSAFE)) { 330 static std::recursive_mutex g_LogThreadedMutex; 331 std::lock_guard<std::recursive_mutex> guard(g_LogThreadedMutex); 332 *stream_sp << message; 333 stream_sp->flush(); 334 } else { 335 *stream_sp << message; 336 stream_sp->flush(); 337 } 338} 339 340void Log::Format(llvm::StringRef file, llvm::StringRef function, 341 const llvm::formatv_object_base &payload) { 342 std::string message_string; 343 llvm::raw_string_ostream message(message_string); 344 WriteHeader(message, file, function); 345 message << payload << "\n"; 346 WriteMessage(message.str()); 347} 348 349void Log::DisableLoggingChild() { 350 // Disable logging by clearing out the atomic variable after forking -- if we 351 // forked while another thread held the channel mutex, we would deadlock when 352 // trying to write to the log. 353 for (auto &c: *g_channel_map) 354 c.second.m_channel.log_ptr.store(nullptr, std::memory_order_relaxed); 355} 356