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
ForEachCategory(const Log::ChannelMap::value_type & entry,llvm::function_ref<void (llvm::StringRef,llvm::StringRef)> lambda)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
ListCategories(llvm::raw_ostream & stream,const ChannelMap::value_type & entry)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
GetFlags(llvm::raw_ostream & stream,const ChannelMap::value_type & entry,llvm::ArrayRef<const char * > categories)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
Enable(const std::shared_ptr<LogHandler> & handler_sp,uint32_t options,Log::MaskType flags)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
Disable(Log::MaskType flags)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
Dump(llvm::raw_ostream & output_stream)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
GetOptions() const127 const Flags Log::GetOptions() const {
128 return m_options.load(std::memory_order_relaxed);
129 }
130
GetMask() const131 Log::MaskType Log::GetMask() const {
132 return m_mask.load(std::memory_order_relaxed);
133 }
134
PutCString(const char * cstr)135 void Log::PutCString(const char *cstr) { PutString(cstr); }
136
PutString(llvm::StringRef str)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.
Printf(const char * format,...)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
VAPrintf(const char * format,va_list args)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
Formatf(llvm::StringRef file,llvm::StringRef function,const char * format,...)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
VAFormatf(llvm::StringRef file,llvm::StringRef function,const char * format,va_list args)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.
Error(const char * format,...)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
VAError(const char * format,va_list args)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.
Verbose(const char * format,...)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.
Warning(const char * format,...)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
Register(llvm::StringRef name,Channel & channel)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
Unregister(llvm::StringRef name)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
EnableLogChannel(const std::shared_ptr<LogHandler> & log_handler_sp,uint32_t log_options,llvm::StringRef channel,llvm::ArrayRef<const char * > categories,llvm::raw_ostream & error_stream)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
DisableLogChannel(llvm::StringRef channel,llvm::ArrayRef<const char * > categories,llvm::raw_ostream & error_stream)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
DumpLogChannel(llvm::StringRef channel,llvm::raw_ostream & output_stream,llvm::raw_ostream & error_stream)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
ListChannelCategories(llvm::StringRef channel,llvm::raw_ostream & stream)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
DisableAllLogChannels()282 void Log::DisableAllLogChannels() {
283 for (auto &entry : *g_channel_map)
284 entry.second.Disable(std::numeric_limits<MaskType>::max());
285 }
286
ForEachChannelCategory(llvm::StringRef channel,llvm::function_ref<void (llvm::StringRef,llvm::StringRef)> lambda)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
ListChannels()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
ListAllLogChannels(llvm::raw_ostream & stream)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
GetVerbose() const314 bool Log::GetVerbose() const {
315 return m_options.load(std::memory_order_relaxed) & LLDB_LOG_OPTION_VERBOSE;
316 }
317
WriteHeader(llvm::raw_ostream & OS,llvm::StringRef file,llvm::StringRef function)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.
WriteMessage(llvm::StringRef message)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
Format(llvm::StringRef file,llvm::StringRef function,const llvm::formatv_object_base & payload)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
StreamLogHandler(int fd,bool should_close,size_t buffer_size)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
~StreamLogHandler()387 StreamLogHandler::~StreamLogHandler() { Flush(); }
388
Flush()389 void StreamLogHandler::Flush() {
390 std::lock_guard<std::mutex> guard(m_mutex);
391 m_stream.flush();
392 }
393
Emit(llvm::StringRef message)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
CallbackLogHandler(lldb::LogOutputCallback callback,void * baton)403 CallbackLogHandler::CallbackLogHandler(lldb::LogOutputCallback callback,
404 void *baton)
405 : m_callback(callback), m_baton(baton) {}
406
Emit(llvm::StringRef message)407 void CallbackLogHandler::Emit(llvm::StringRef message) {
408 m_callback(message.data(), m_baton);
409 }
410
RotatingLogHandler(size_t size)411 RotatingLogHandler::RotatingLogHandler(size_t size)
412 : m_messages(std::make_unique<std::string[]>(size)), m_size(size) {}
413
Emit(llvm::StringRef message)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
NormalizeIndex(size_t i) const422 size_t RotatingLogHandler::NormalizeIndex(size_t i) const { return i % m_size; }
423
GetNumMessages() const424 size_t RotatingLogHandler::GetNumMessages() const {
425 return m_total_count < m_size ? m_total_count : m_size;
426 }
427
GetFirstMessageIndex() const428 size_t RotatingLogHandler::GetFirstMessageIndex() const {
429 return m_total_count < m_size ? 0 : m_next_index;
430 }
431
Dump(llvm::raw_ostream & stream) const432 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
TeeLogHandler(std::shared_ptr<LogHandler> first_log_handler,std::shared_ptr<LogHandler> second_log_handler)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
Emit(llvm::StringRef message)451 void TeeLogHandler::Emit(llvm::StringRef message) {
452 m_first_log_handler->Emit(message);
453 m_second_log_handler->Emit(message);
454 }
455