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