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