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/Chrono.h"
17 #include "llvm/Support/ManagedStatic.h"
18 #include "llvm/Support/Path.h"
19 #include "llvm/Support/Signals.h"
20 #include "llvm/Support/Threading.h"
21 #include "llvm/Support/raw_ostream.h"
22
23 #include <chrono>
24 #include <cstdarg>
25 #include <mutex>
26 #include <utility>
27
28 #include <assert.h>
29 #if defined(_WIN32)
30 #include <process.h>
31 #else
32 #include <unistd.h>
33 #include <pthread.h>
34 #endif
35
36 using namespace lldb_private;
37
38 llvm::ManagedStatic<Log::ChannelMap> Log::g_channel_map;
39
ForEachCategory(const Log::ChannelMap::value_type & entry,llvm::function_ref<void (llvm::StringRef,llvm::StringRef)> lambda)40 void 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
ListCategories(llvm::raw_ostream & stream,const ChannelMap::value_type & entry)49 void 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
GetFlags(llvm::raw_ostream & stream,const ChannelMap::value_type & entry,llvm::ArrayRef<const char * > categories)58 uint32_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
Enable(const std::shared_ptr<llvm::raw_ostream> & stream_sp,uint32_t options,uint32_t flags)87 void 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
Disable(uint32_t flags)99 void 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
GetOptions() const109 const Flags Log::GetOptions() const {
110 return m_options.load(std::memory_order_relaxed);
111 }
112
GetMask() const113 const Flags Log::GetMask() const {
114 return m_mask.load(std::memory_order_relaxed);
115 }
116
PutCString(const char * cstr)117 void Log::PutCString(const char *cstr) { Printf("%s", cstr); }
PutString(llvm::StringRef str)118 void Log::PutString(llvm::StringRef str) { PutCString(str.str().c_str()); }
119
120 // Simple variable argument logging with flags.
Printf(const char * format,...)121 void 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.
VAPrintf(const char * format,va_list args)131 void 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(std::string(FinalMessage.str()));
142 }
143
144 // Printing of errors that are not fatal.
Error(const char * format,...)145 void Log::Error(const char *format, ...) {
146 va_list args;
147 va_start(args, format);
148 VAError(format, args);
149 va_end(args);
150 }
151
VAError(const char * format,va_list args)152 void 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.
Verbose(const char * format,...)160 void 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.
Warning(const char * format,...)171 void 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
Initialize()181 void Log::Initialize() {
182 #ifdef LLVM_ON_UNIX
183 pthread_atfork(nullptr, nullptr, &Log::DisableLoggingChild);
184 #endif
185 InitializeLldbChannel();
186 }
187
Register(llvm::StringRef name,Channel & channel)188 void 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
Unregister(llvm::StringRef name)194 void 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
EnableLogChannel(const std::shared_ptr<llvm::raw_ostream> & log_stream_sp,uint32_t log_options,llvm::StringRef channel,llvm::ArrayRef<const char * > categories,llvm::raw_ostream & error_stream)201 bool 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
DisableLogChannel(llvm::StringRef channel,llvm::ArrayRef<const char * > categories,llvm::raw_ostream & error_stream)217 bool 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
ListChannelCategories(llvm::StringRef channel,llvm::raw_ostream & stream)232 bool 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
DisableAllLogChannels()243 void Log::DisableAllLogChannels() {
244 for (auto &entry : *g_channel_map)
245 entry.second.Disable(UINT32_MAX);
246 }
247
ForEachChannelCategory(llvm::StringRef channel,llvm::function_ref<void (llvm::StringRef,llvm::StringRef)> lambda)248 void 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
ListChannels()258 std::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
ListAllLogChannels(llvm::raw_ostream & stream)265 void 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
GetVerbose() const275 bool Log::GetVerbose() const {
276 return m_options.load(std::memory_order_relaxed) & LLDB_LOG_OPTION_VERBOSE;
277 }
278
WriteHeader(llvm::raw_ostream & OS,llvm::StringRef file,llvm::StringRef function)279 void 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
WriteMessage(const std::string & message)321 void 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
Format(llvm::StringRef file,llvm::StringRef function,const llvm::formatv_object_base & payload)340 void 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
DisableLoggingChild()349 void 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