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(Fmt: "Logging categories for '{0}':\n" , Vals: entry.first()); |
57 | ForEachCategory(entry, |
58 | lambda: [&stream](llvm::StringRef name, llvm::StringRef description) { |
59 | stream << llvm::formatv(Fmt: " {0} - {1}\n" , Vals&: name, Vals&: description); |
60 | }); |
61 | } |
62 | |
63 | Log::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(RHS: category)) { |
70 | flags |= std::numeric_limits<Log::MaskType>::max(); |
71 | continue; |
72 | } |
73 | if (llvm::StringRef("default" ).equals_insensitive(RHS: category)) { |
74 | flags |= entry.second.m_channel.default_flags; |
75 | continue; |
76 | } |
77 | auto cat = llvm::find_if(Range: entry.second.m_channel.categories, |
78 | P: [&](const Log::Category &c) { |
79 | return c.name.equals_insensitive(RHS: category); |
80 | }); |
81 | if (cat != entry.second.m_channel.categories.end()) { |
82 | flags |= cat->flag; |
83 | continue; |
84 | } |
85 | stream << llvm::formatv(Fmt: "error: unrecognized log category '{0}'\n" , |
86 | Vals&: category); |
87 | list_categories = true; |
88 | } |
89 | if (list_categories) |
90 | ListCategories(stream, entry); |
91 | return flags; |
92 | } |
93 | |
94 | void 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(i: flags, m: std::memory_order_relaxed); |
99 | if (mask | flags) { |
100 | m_options.store(i: options, m: std::memory_order_relaxed); |
101 | m_handler = handler_sp; |
102 | m_channel.log_ptr.store(p: this, m: std::memory_order_relaxed); |
103 | } |
104 | } |
105 | |
106 | void Log::Disable(Log::MaskType flags) { |
107 | llvm::sys::ScopedWriter lock(m_mutex); |
108 | |
109 | MaskType mask = m_mask.fetch_and(i: ~flags, m: std::memory_order_relaxed); |
110 | if (!(mask & ~flags)) { |
111 | m_handler.reset(); |
112 | m_channel.log_ptr.store(p: nullptr, m: std::memory_order_relaxed); |
113 | } |
114 | } |
115 | |
116 | bool 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>(Val: m_handler.get())) { |
120 | handler->Dump(stream&: output_stream); |
121 | return true; |
122 | } |
123 | return false; |
124 | } |
125 | |
126 | const Flags Log::GetOptions() const { |
127 | return m_options.load(m: std::memory_order_relaxed); |
128 | } |
129 | |
130 | Log::MaskType Log::GetMask() const { |
131 | return m_mask.load(m: std::memory_order_relaxed); |
132 | } |
133 | |
134 | void Log::PutCString(const char *cstr) { PutString(str: cstr); } |
135 | |
136 | void Log::PutString(llvm::StringRef str) { |
137 | std::string FinalMessage; |
138 | llvm::raw_string_ostream Stream(FinalMessage); |
139 | WriteHeader(OS&: Stream, file: "" , function: "" ); |
140 | Stream << str << "\n" ; |
141 | WriteMessage(message: FinalMessage); |
142 | } |
143 | |
144 | // Simple variable argument logging with flags. |
145 | void Log::Printf(const char *format, ...) { |
146 | va_list args; |
147 | va_start(args, format); |
148 | VAPrintf(format, args); |
149 | va_end(args); |
150 | } |
151 | |
152 | void Log::VAPrintf(const char *format, va_list args) { |
153 | llvm::SmallString<64> Content; |
154 | lldb_private::VASprintf(buf&: Content, fmt: format, args); |
155 | PutString(str: Content); |
156 | } |
157 | |
158 | void 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 | |
166 | void Log::VAFormatf(llvm::StringRef file, llvm::StringRef function, |
167 | const char *format, va_list args) { |
168 | llvm::SmallString<64> Content; |
169 | lldb_private::VASprintf(buf&: Content, fmt: format, args); |
170 | Format(file, function, payload: llvm::formatv(Fmt: "{0}" , Vals&: Content)); |
171 | } |
172 | |
173 | // Printing of errors that are not fatal. |
174 | void Log::Error(const char *format, ...) { |
175 | va_list args; |
176 | va_start(args, format); |
177 | VAError(format, args); |
178 | va_end(args); |
179 | } |
180 | |
181 | void Log::VAError(const char *format, va_list args) { |
182 | llvm::SmallString<64> Content; |
183 | VASprintf(buf&: Content, fmt: format, args); |
184 | |
185 | Printf(format: "error: %s" , Content.c_str()); |
186 | } |
187 | |
188 | // Printing of warnings that are not fatal only if verbose mode is enabled. |
189 | void 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. |
200 | void Log::Warning(const char *format, ...) { |
201 | llvm::SmallString<64> Content; |
202 | va_list args; |
203 | va_start(args, format); |
204 | VASprintf(buf&: Content, fmt: format, args); |
205 | va_end(args); |
206 | |
207 | Printf(format: "warning: %s" , Content.c_str()); |
208 | } |
209 | |
210 | void Log::Register(llvm::StringRef name, Channel &channel) { |
211 | auto iter = g_channel_map->try_emplace(Key: name, Args&: channel); |
212 | assert(iter.second == true); |
213 | UNUSED_IF_ASSERT_DISABLED(iter); |
214 | } |
215 | |
216 | void Log::Unregister(llvm::StringRef name) { |
217 | auto iter = g_channel_map->find(Key: name); |
218 | assert(iter != g_channel_map->end()); |
219 | iter->second.Disable(flags: std::numeric_limits<MaskType>::max()); |
220 | g_channel_map->erase(I: iter); |
221 | } |
222 | |
223 | bool 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(Key: channel); |
228 | if (iter == g_channel_map->end()) { |
229 | error_stream << llvm::formatv(Fmt: "Invalid log channel '{0}'.\n" , Vals&: channel); |
230 | return false; |
231 | } |
232 | MaskType flags = categories.empty() |
233 | ? iter->second.m_channel.default_flags |
234 | : GetFlags(stream&: error_stream, entry: *iter, categories); |
235 | iter->second.Enable(handler_sp: log_handler_sp, options: log_options, flags); |
236 | return true; |
237 | } |
238 | |
239 | bool Log::DisableLogChannel(llvm::StringRef channel, |
240 | llvm::ArrayRef<const char *> categories, |
241 | llvm::raw_ostream &error_stream) { |
242 | auto iter = g_channel_map->find(Key: channel); |
243 | if (iter == g_channel_map->end()) { |
244 | error_stream << llvm::formatv(Fmt: "Invalid log channel '{0}'.\n" , Vals&: channel); |
245 | return false; |
246 | } |
247 | MaskType flags = categories.empty() |
248 | ? std::numeric_limits<MaskType>::max() |
249 | : GetFlags(stream&: error_stream, entry: *iter, categories); |
250 | iter->second.Disable(flags); |
251 | return true; |
252 | } |
253 | |
254 | bool Log::DumpLogChannel(llvm::StringRef channel, |
255 | llvm::raw_ostream &output_stream, |
256 | llvm::raw_ostream &error_stream) { |
257 | auto iter = g_channel_map->find(Key: channel); |
258 | if (iter == g_channel_map->end()) { |
259 | error_stream << llvm::formatv(Fmt: "Invalid log channel '{0}'.\n" , Vals&: channel); |
260 | return false; |
261 | } |
262 | if (!iter->second.Dump(output_stream)) { |
263 | error_stream << llvm::formatv( |
264 | Fmt: "log channel '{0}' does not support dumping.\n" , Vals&: channel); |
265 | return false; |
266 | } |
267 | return true; |
268 | } |
269 | |
270 | bool Log::ListChannelCategories(llvm::StringRef channel, |
271 | llvm::raw_ostream &stream) { |
272 | auto ch = g_channel_map->find(Key: channel); |
273 | if (ch == g_channel_map->end()) { |
274 | stream << llvm::formatv(Fmt: "Invalid log channel '{0}'.\n" , Vals&: channel); |
275 | return false; |
276 | } |
277 | ListCategories(stream, entry: *ch); |
278 | return true; |
279 | } |
280 | |
281 | void Log::DisableAllLogChannels() { |
282 | for (auto &entry : *g_channel_map) |
283 | entry.second.Disable(flags: std::numeric_limits<MaskType>::max()); |
284 | } |
285 | |
286 | void Log::ForEachChannelCategory( |
287 | llvm::StringRef channel, |
288 | llvm::function_ref<void(llvm::StringRef, llvm::StringRef)> lambda) { |
289 | auto ch = g_channel_map->find(Key: channel); |
290 | if (ch == g_channel_map->end()) |
291 | return; |
292 | |
293 | ForEachCategory(entry: *ch, lambda); |
294 | } |
295 | |
296 | std::vector<llvm::StringRef> Log::ListChannels() { |
297 | std::vector<llvm::StringRef> result; |
298 | for (const auto &channel : *g_channel_map) |
299 | result.push_back(x: channel.first()); |
300 | return result; |
301 | } |
302 | |
303 | void 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, entry: channel); |
311 | } |
312 | |
313 | bool Log::GetVerbose() const { |
314 | return m_options.load(m: std::memory_order_relaxed) & LLDB_LOG_OPTION_VERBOSE; |
315 | } |
316 | |
317 | void Log::(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(Fmt: "{0:f9} " , Vals: 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(Fmt: "[{0,0+4}/{1,0+4}] " , Vals: getpid(), |
335 | Vals: 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(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>(Value: thread_name.size()) << "} " ; |
345 | OS << llvm::formatv(Fmt: format_str.c_str(), Vals&: 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(path: file).take_front(N: 40); |
354 | function = function.take_front(N: 40); |
355 | OS << llvm::formatv(Fmt: "{0,-60:60} " , Vals: (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. |
361 | void 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 | |
370 | void 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(OS&: message, file, function); |
375 | message << payload << "\n" ; |
376 | WriteMessage(message: message.str()); |
377 | } |
378 | |
379 | StreamLogHandler::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 | |
386 | StreamLogHandler::~StreamLogHandler() { Flush(); } |
387 | |
388 | void StreamLogHandler::Flush() { |
389 | std::lock_guard<std::mutex> guard(m_mutex); |
390 | m_stream.flush(); |
391 | } |
392 | |
393 | void 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 | |
402 | CallbackLogHandler::CallbackLogHandler(lldb::LogOutputCallback callback, |
403 | void *baton) |
404 | : m_callback(callback), m_baton(baton) {} |
405 | |
406 | void CallbackLogHandler::Emit(llvm::StringRef message) { |
407 | m_callback(message.data(), m_baton); |
408 | } |
409 | |
410 | RotatingLogHandler::RotatingLogHandler(size_t size) |
411 | : m_messages(std::make_unique<std::string[]>(num: size)), m_size(size) {} |
412 | |
413 | void 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(i: index + 1); |
418 | m_messages[index] = message.str(); |
419 | } |
420 | |
421 | size_t RotatingLogHandler::NormalizeIndex(size_t i) const { return i % m_size; } |
422 | |
423 | size_t RotatingLogHandler::GetNumMessages() const { |
424 | return m_total_count < m_size ? m_total_count : m_size; |
425 | } |
426 | |
427 | size_t RotatingLogHandler::GetFirstMessageIndex() const { |
428 | return m_total_count < m_size ? 0 : m_next_index; |
429 | } |
430 | |
431 | void 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 | |