Bitcoin ABC  0.26.3
P2P Digital Currency
logging.cpp
Go to the documentation of this file.
1 // Copyright (c) 2009-2010 Satoshi Nakamoto
2 // Copyright (c) 2009-2016 The Bitcoin Core developers
3 // Copyright (c) 2017-2019 The Bitcoin developers
4 // Distributed under the MIT software license, see the accompanying
5 // file COPYING or http://www.opensource.org/licenses/mit-license.php.
6 
7 #include <fs.h>
8 #include <logging.h>
9 
10 #include <util/string.h>
11 #include <util/threadnames.h>
12 #include <util/time.h>
13 
14 #include <algorithm>
15 #include <array>
16 
18 const char *const DEFAULT_DEBUGLOGFILE = "debug.log";
19 
36  static BCLog::Logger *g_logger{new BCLog::Logger()};
37  return *g_logger;
38 }
39 
40 static int FileWriteStr(const std::string &str, FILE *fp) {
41  return fwrite(str.data(), 1, str.size(), fp);
42 }
43 
45  StdLockGuard scoped_lock(m_cs);
46 
47  assert(m_buffering);
48  assert(m_fileout == nullptr);
49 
50  if (m_print_to_file) {
51  assert(!m_file_path.empty());
52  m_fileout = fsbridge::fopen(m_file_path, "a");
53  if (!m_fileout) {
54  return false;
55  }
56 
57  // Unbuffered.
58  setbuf(m_fileout, nullptr);
59 
60  // Add newlines to the logfile to distinguish this execution from the
61  // last one.
62  FileWriteStr("\n\n\n\n\n", m_fileout);
63  }
64 
65  // Dump buffered messages from before we opened the log.
66  m_buffering = false;
67  while (!m_msgs_before_open.empty()) {
68  const std::string &s = m_msgs_before_open.front();
69 
70  if (m_print_to_file) {
71  FileWriteStr(s, m_fileout);
72  }
73  if (m_print_to_console) {
74  fwrite(s.data(), 1, s.size(), stdout);
75  }
76  for (const auto &cb : m_print_callbacks) {
77  cb(s);
78  }
79 
80  m_msgs_before_open.pop_front();
81  }
82  if (m_print_to_console) {
83  fflush(stdout);
84  }
85 
86  return true;
87 }
88 
90  StdLockGuard scoped_lock(m_cs);
91  m_buffering = true;
92  if (m_fileout != nullptr) {
93  fclose(m_fileout);
94  }
95  m_fileout = nullptr;
96  m_print_callbacks.clear();
97 }
98 
101  std::string category;
102 };
103 
105  {BCLog::NONE, "0"},
106  {BCLog::NONE, "none"},
107  {BCLog::NET, "net"},
108  {BCLog::TOR, "tor"},
109  {BCLog::MEMPOOL, "mempool"},
110  {BCLog::HTTP, "http"},
111  {BCLog::BENCH, "bench"},
112  {BCLog::ZMQ, "zmq"},
113  {BCLog::WALLETDB, "walletdb"},
114  {BCLog::RPC, "rpc"},
115  {BCLog::ESTIMATEFEE, "estimatefee"},
116  {BCLog::ADDRMAN, "addrman"},
117  {BCLog::SELECTCOINS, "selectcoins"},
118  {BCLog::REINDEX, "reindex"},
119  {BCLog::CMPCTBLOCK, "cmpctblock"},
120  {BCLog::RAND, "rand"},
121  {BCLog::PRUNE, "prune"},
122  {BCLog::PROXY, "proxy"},
123  {BCLog::MEMPOOLREJ, "mempoolrej"},
124  {BCLog::LIBEVENT, "libevent"},
125  {BCLog::COINDB, "coindb"},
126  {BCLog::QT, "qt"},
127  {BCLog::LEVELDB, "leveldb"},
128  {BCLog::VALIDATION, "validation"},
129  {BCLog::AVALANCHE, "avalanche"},
130  {BCLog::I2P, "i2p"},
131  {BCLog::CHRONIK, "chronik"},
132 #ifdef DEBUG_LOCKCONTENTION
133  {BCLog::LOCK, "lock"},
134 #endif
135  {BCLog::BLOCKSTORE, "blockstorage"},
136  {BCLog::ALL, "1"},
137  {BCLog::ALL, "all"},
138 };
139 
140 bool GetLogCategory(BCLog::LogFlags &flag, const std::string &str) {
141  if (str == "") {
142  flag = BCLog::ALL;
143  return true;
144  }
145  for (const CLogCategoryDesc &category_desc : LogCategories) {
146  if (category_desc.category == str) {
147  flag = category_desc.flag;
148  return true;
149  }
150  }
151  return false;
152 }
153 
154 std::vector<LogCategory> BCLog::Logger::LogCategoriesList() const {
155  // Sort log categories by alphabetical order.
156  std::array<CLogCategoryDesc, std::size(LogCategories)> categories;
157  std::copy(std::begin(LogCategories), std::end(LogCategories),
158  categories.begin());
159  std::sort(categories.begin(), categories.end(),
160  [](auto a, auto b) { return a.category < b.category; });
161 
162  std::vector<LogCategory> ret;
163  for (const CLogCategoryDesc &category_desc : categories) {
164  if (category_desc.flag == BCLog::NONE ||
165  category_desc.flag == BCLog::ALL) {
166  continue;
167  }
168  LogCategory catActive;
169  catActive.category = category_desc.category;
170  catActive.active = WillLogCategory(category_desc.flag);
171  ret.push_back(catActive);
172  }
173  return ret;
174 }
175 
177  if (m_fileout) {
178  fclose(m_fileout);
179  }
180 }
181 
182 std::string BCLog::Logger::LogTimestampStr(const std::string &str) {
183  std::string strStamped;
184 
185  if (!m_log_timestamps) {
186  return str;
187  }
188 
189  if (m_started_new_line) {
190  int64_t nTimeMicros = GetTimeMicros();
191  strStamped = FormatISO8601DateTime(nTimeMicros / 1000000);
192  if (m_log_time_micros) {
193  strStamped.pop_back();
194  strStamped += strprintf(".%06dZ", nTimeMicros % 1000000);
195  }
196  std::chrono::seconds mocktime = GetMockTime();
197  if (mocktime > 0s) {
198  strStamped += " (mocktime: " +
199  FormatISO8601DateTime(count_seconds(mocktime)) + ")";
200  }
201  strStamped += ' ' + str;
202  } else {
203  strStamped = str;
204  }
205 
206  return strStamped;
207 }
208 
209 namespace BCLog {
217 std::string LogEscapeMessage(const std::string &str) {
218  std::string ret;
219  for (char ch_in : str) {
220  uint8_t ch = (uint8_t)ch_in;
221  if ((ch >= 32 || ch == '\n') && ch != '\x7f') {
222  ret += ch_in;
223  } else {
224  ret += strprintf("\\x%02x", ch);
225  }
226  }
227  return ret;
228 }
229 } // namespace BCLog
230 
231 void BCLog::Logger::LogPrintStr(const std::string &str,
232  const std::string &logging_function,
233  const std::string &source_file,
234  const int source_line) {
235  StdLockGuard scoped_lock(m_cs);
236  std::string str_prefixed = LogEscapeMessage(str);
237 
238  if (m_log_sourcelocations && m_started_new_line) {
239  str_prefixed.insert(0, "[" + RemovePrefix(source_file, "./") + ":" +
240  ToString(source_line) + "] [" +
241  logging_function + "] ");
242  }
243 
244  if (m_log_threadnames && m_started_new_line) {
245  str_prefixed.insert(0, "[" + util::ThreadGetInternalName() + "] ");
246  }
247 
248  str_prefixed = LogTimestampStr(str_prefixed);
249 
250  m_started_new_line = !str.empty() && str[str.size() - 1] == '\n';
251 
252  if (m_buffering) {
253  // buffer if we haven't started logging yet
254  m_msgs_before_open.push_back(str_prefixed);
255  return;
256  }
257 
258  if (m_print_to_console) {
259  // Print to console.
260  fwrite(str_prefixed.data(), 1, str_prefixed.size(), stdout);
261  fflush(stdout);
262  }
263  for (const auto &cb : m_print_callbacks) {
264  cb(str_prefixed);
265  }
266  if (m_print_to_file) {
267  assert(m_fileout != nullptr);
268 
269  // Reopen the log file, if requested.
270  if (m_reopen_file) {
271  m_reopen_file = false;
272  FILE *new_fileout = fsbridge::fopen(m_file_path, "a");
273  if (new_fileout) {
274  // unbuffered.
275  setbuf(m_fileout, nullptr);
276  fclose(m_fileout);
277  m_fileout = new_fileout;
278  }
279  }
280  FileWriteStr(str_prefixed, m_fileout);
281  }
282 }
283 
285  // Amount of debug.log to save at end when shrinking (must fit in memory)
286  constexpr size_t RECENT_DEBUG_HISTORY_SIZE = 10 * 1000000;
287 
288  assert(!m_file_path.empty());
289 
290  // Scroll debug.log if it's getting too big.
291  FILE *file = fsbridge::fopen(m_file_path, "r");
292 
293  // Special files (e.g. device nodes) may not have a size.
294  size_t log_size = 0;
295  try {
296  log_size = fs::file_size(m_file_path);
297  } catch (const fs::filesystem_error &) {
298  }
299 
300  // If debug.log file is more than 10% bigger the RECENT_DEBUG_HISTORY_SIZE
301  // trim it down by saving only the last RECENT_DEBUG_HISTORY_SIZE bytes.
302  if (file && log_size > 11 * (RECENT_DEBUG_HISTORY_SIZE / 10)) {
303  // Restart the file with some of the end.
304  std::vector<char> vch(RECENT_DEBUG_HISTORY_SIZE, 0);
305  if (fseek(file, -((long)vch.size()), SEEK_END)) {
306  LogPrintf("Failed to shrink debug log file: fseek(...) failed\n");
307  fclose(file);
308  return;
309  }
310  int nBytes = fread(vch.data(), 1, vch.size(), file);
311  fclose(file);
312 
313  file = fsbridge::fopen(m_file_path, "w");
314  if (file) {
315  fwrite(vch.data(), 1, nBytes, file);
316  fclose(file);
317  }
318  } else if (file != nullptr) {
319  fclose(file);
320  }
321 }
322 
324  m_categories |= category;
325 }
326 
327 bool BCLog::Logger::EnableCategory(const std::string &str) {
328  BCLog::LogFlags flag;
329  if (!GetLogCategory(flag, str)) {
330  return false;
331  }
332  EnableCategory(flag);
333  return true;
334 }
335 
337  m_categories &= ~category;
338 }
339 
340 bool BCLog::Logger::DisableCategory(const std::string &str) {
341  BCLog::LogFlags flag;
342  if (!GetLogCategory(flag, str)) {
343  return false;
344  }
345  DisableCategory(flag);
346  return true;
347 }
348 
350  // ALL is not meant to be used as a logging category, but only as a mask
351  // representing all categories.
352  if (category == BCLog::NONE || category == BCLog::ALL) {
353  LogPrintf("Error trying to log using a category mask instead of an "
354  "explicit category.\n");
355  return true;
356  }
357 
358  return (m_categories.load(std::memory_order_relaxed) & category) != 0;
359 }
360 
362  return m_categories != BCLog::NONE;
363 }
bool WillLogCategory(LogFlags category) const
Return true if log accepts specified category.
Definition: logging.cpp:349
std::string LogTimestampStr(const std::string &str)
Definition: logging.cpp:182
void DisconnectTestLogger()
Only for testing.
Definition: logging.cpp:89
bool DefaultShrinkDebugFile() const
Default for whether ShrinkDebugFile should be run.
Definition: logging.cpp:361
fs::path m_file_path
Definition: logging.h:109
std::vector< LogCategory > LogCategoriesList() const
Returns a vector of the log categories in alphabetical order.
Definition: logging.cpp:154
void DisableCategory(LogFlags category)
Definition: logging.cpp:336
void EnableCategory(LogFlags category)
Definition: logging.cpp:323
bool StartLogging()
Start logging (and flush all buffered messages)
Definition: logging.cpp:44
void ShrinkDebugFile()
Definition: logging.cpp:284
bool m_print_to_file
Definition: logging.h:102
bool m_print_to_console
Definition: logging.h:101
StdMutex m_cs
Definition: logging.h:76
void LogPrintStr(const std::string &str, const std::string &logging_function, const std::string &source_file, const int source_line)
Send a string to the log output.
Definition: logging.cpp:231
const CLogCategoryDesc LogCategories[]
Definition: logging.cpp:104
static int FileWriteStr(const std::string &str, FILE *fp)
Definition: logging.cpp:40
bool GetLogCategory(BCLog::LogFlags &flag, const std::string &str)
Return true if str parses as a log category and set the flag.
Definition: logging.cpp:140
bool fLogIPs
Definition: logging.cpp:17
const char *const DEFAULT_DEBUGLOGFILE
Definition: logging.cpp:18
BCLog::Logger & LogInstance()
Definition: logging.cpp:20
static const bool DEFAULT_LOGIPS
Definition: logging.h:23
#define LogPrintf(...)
Definition: logging.h:205
Definition: timer.h:17
std::string LogEscapeMessage(const std::string &str)
Belts and suspenders: make sure outgoing log messages don't contain potentially suspicious characters...
Definition: logging.cpp:217
LogFlags
Definition: logging.h:38
@ ESTIMATEFEE
Definition: logging.h:48
@ AVALANCHE
Definition: logging.h:62
@ RAND
Definition: logging.h:53
@ COINDB
Definition: logging.h:58
@ REINDEX
Definition: logging.h:51
@ WALLETDB
Definition: logging.h:46
@ ADDRMAN
Definition: logging.h:49
@ ALL
Definition: logging.h:69
@ RPC
Definition: logging.h:47
@ HTTP
Definition: logging.h:43
@ LEVELDB
Definition: logging.h:60
@ NONE
Definition: logging.h:39
@ VALIDATION
Definition: logging.h:61
@ MEMPOOLREJ
Definition: logging.h:56
@ PRUNE
Definition: logging.h:54
@ TOR
Definition: logging.h:41
@ LIBEVENT
Definition: logging.h:57
@ CMPCTBLOCK
Definition: logging.h:52
@ PROXY
Definition: logging.h:55
@ CHRONIK
Definition: logging.h:64
@ ZMQ
Definition: logging.h:45
@ MEMPOOL
Definition: logging.h:42
@ SELECTCOINS
Definition: logging.h:50
@ I2P
Definition: logging.h:63
@ BENCH
Definition: logging.h:44
@ NET
Definition: logging.h:40
@ QT
Definition: logging.h:59
@ BLOCKSTORE
Definition: logging.h:68
FILE * fopen(const fs::path &p, const char *mode)
Definition: fs.cpp:28
const std::string & ThreadGetInternalName()
Get the thread's internal (in-memory) name; used e.g.
Definition: threadnames.cpp:39
std::string RemovePrefix(const std::string &str, const std::string &prefix)
Definition: string.h:30
std::string ToString(const T &t)
Locale-independent version of std::to_string.
Definition: string.h:79
BCLog::LogFlags flag
Definition: logging.cpp:100
std::string category
Definition: logging.cpp:101
bool active
Definition: logging.h:33
std::string category
Definition: logging.h:32
#define LOCK(cs)
Definition: sync.h:243
int64_t GetTimeMicros()
Returns the system time (not mockable)
Definition: time.cpp:110
std::chrono::seconds GetMockTime()
For testing.
Definition: time.cpp:102
std::string FormatISO8601DateTime(int64_t nTime)
ISO 8601 formatting is preferred.
Definition: time.cpp:122
constexpr int64_t count_seconds(std::chrono::seconds t)
Helper to count the seconds of a duration.
Definition: time.h:29
#define strprintf
Format arguments and return the string or write to given std::ostream (see tinyformat::format doc for...
Definition: tinyformat.h:1202
assert(!tx.IsCoinBase())