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