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