Bitcoin Core  0.20.99
P2P Digital Currency
logging.cpp
Go to the documentation of this file.
1 // Copyright (c) 2009-2010 Satoshi Nakamoto
2 // Copyright (c) 2009-2020 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 <logging.h>
7 #include <util/threadnames.h>
8 #include <util/time.h>
9 
10 #include <mutex>
11 
12 const char * const DEFAULT_DEBUGLOGFILE = "debug.log";
13 
15 {
31  static BCLog::Logger* g_logger{new BCLog::Logger()};
32  return *g_logger;
33 }
34 
36 
37 static int FileWriteStr(const std::string &str, FILE *fp)
38 {
39  return fwrite(str.data(), 1, str.size(), fp);
40 }
41 
43 {
44  StdLockGuard scoped_lock(m_cs);
45 
46  assert(m_buffering);
47  assert(m_fileout == nullptr);
48 
49  if (m_print_to_file) {
50  assert(!m_file_path.empty());
51  m_fileout = fsbridge::fopen(m_file_path, "a");
52  if (!m_fileout) {
53  return false;
54  }
55 
56  setbuf(m_fileout, nullptr); // unbuffered
57 
58  // Add newlines to the logfile to distinguish this execution from the
59  // last one.
60  FileWriteStr("\n\n\n\n\n", m_fileout);
61  }
62 
63  // dump buffered messages from before we opened the log
64  m_buffering = false;
65  while (!m_msgs_before_open.empty()) {
66  const std::string& s = m_msgs_before_open.front();
67 
68  if (m_print_to_file) FileWriteStr(s, m_fileout);
69  if (m_print_to_console) fwrite(s.data(), 1, s.size(), stdout);
70  for (const auto& cb : m_print_callbacks) {
71  cb(s);
72  }
73 
74  m_msgs_before_open.pop_front();
75  }
76  if (m_print_to_console) fflush(stdout);
77 
78  return true;
79 }
80 
82 {
83  StdLockGuard scoped_lock(m_cs);
84  m_buffering = true;
85  if (m_fileout != nullptr) fclose(m_fileout);
86  m_fileout = nullptr;
87  m_print_callbacks.clear();
88 }
89 
91 {
92  m_categories |= flag;
93 }
94 
95 bool BCLog::Logger::EnableCategory(const std::string& str)
96 {
97  BCLog::LogFlags flag;
98  if (!GetLogCategory(flag, str)) return false;
99  EnableCategory(flag);
100  return true;
101 }
102 
104 {
105  m_categories &= ~flag;
106 }
107 
108 bool BCLog::Logger::DisableCategory(const std::string& str)
109 {
110  BCLog::LogFlags flag;
111  if (!GetLogCategory(flag, str)) return false;
112  DisableCategory(flag);
113  return true;
114 }
115 
117 {
118  return (m_categories.load(std::memory_order_relaxed) & category) != 0;
119 }
120 
122 {
123  return m_categories == BCLog::NONE;
124 }
125 
127 {
129  std::string category;
130 };
131 
133 {
134  {BCLog::NONE, "0"},
135  {BCLog::NONE, "none"},
136  {BCLog::NET, "net"},
137  {BCLog::TOR, "tor"},
138  {BCLog::MEMPOOL, "mempool"},
139  {BCLog::HTTP, "http"},
140  {BCLog::BENCH, "bench"},
141  {BCLog::ZMQ, "zmq"},
142  {BCLog::WALLETDB, "walletdb"},
143  {BCLog::RPC, "rpc"},
144  {BCLog::ESTIMATEFEE, "estimatefee"},
145  {BCLog::ADDRMAN, "addrman"},
146  {BCLog::SELECTCOINS, "selectcoins"},
147  {BCLog::REINDEX, "reindex"},
148  {BCLog::CMPCTBLOCK, "cmpctblock"},
149  {BCLog::RAND, "rand"},
150  {BCLog::PRUNE, "prune"},
151  {BCLog::PROXY, "proxy"},
152  {BCLog::MEMPOOLREJ, "mempoolrej"},
153  {BCLog::LIBEVENT, "libevent"},
154  {BCLog::COINDB, "coindb"},
155  {BCLog::QT, "qt"},
156  {BCLog::LEVELDB, "leveldb"},
157  {BCLog::VALIDATION, "validation"},
158  {BCLog::ALL, "1"},
159  {BCLog::ALL, "all"},
160 };
161 
162 bool GetLogCategory(BCLog::LogFlags& flag, const std::string& str)
163 {
164  if (str == "") {
165  flag = BCLog::ALL;
166  return true;
167  }
168  for (const CLogCategoryDesc& category_desc : LogCategories) {
169  if (category_desc.category == str) {
170  flag = category_desc.flag;
171  return true;
172  }
173  }
174  return false;
175 }
176 
177 std::vector<LogCategory> BCLog::Logger::LogCategoriesList()
178 {
179  std::vector<LogCategory> ret;
180  for (const CLogCategoryDesc& category_desc : LogCategories) {
181  // Omit the special cases.
182  if (category_desc.flag != BCLog::NONE && category_desc.flag != BCLog::ALL) {
183  LogCategory catActive;
184  catActive.category = category_desc.category;
185  catActive.active = WillLogCategory(category_desc.flag);
186  ret.push_back(catActive);
187  }
188  }
189  return ret;
190 }
191 
192 std::string BCLog::Logger::LogTimestampStr(const std::string& str)
193 {
194  std::string strStamped;
195 
196  if (!m_log_timestamps)
197  return str;
198 
199  if (m_started_new_line) {
200  int64_t nTimeMicros = GetTimeMicros();
201  strStamped = FormatISO8601DateTime(nTimeMicros/1000000);
202  if (m_log_time_micros) {
203  strStamped.pop_back();
204  strStamped += strprintf(".%06dZ", nTimeMicros%1000000);
205  }
206  int64_t mocktime = GetMockTime();
207  if (mocktime) {
208  strStamped += " (mocktime: " + FormatISO8601DateTime(mocktime) + ")";
209  }
210  strStamped += ' ' + str;
211  } else
212  strStamped = str;
213 
214  return strStamped;
215 }
216 
217 namespace BCLog {
225  std::string LogEscapeMessage(const std::string& str) {
226  std::string ret;
227  for (char ch_in : str) {
228  uint8_t ch = (uint8_t)ch_in;
229  if ((ch >= 32 || ch == '\n') && ch != '\x7f') {
230  ret += ch_in;
231  } else {
232  ret += strprintf("\\x%02x", ch);
233  }
234  }
235  return ret;
236  }
237 }
238 
239 void BCLog::Logger::LogPrintStr(const std::string& str)
240 {
241  StdLockGuard scoped_lock(m_cs);
242  std::string str_prefixed = LogEscapeMessage(str);
243 
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  setbuf(new_fileout, nullptr); // unbuffered
275  fclose(m_fileout);
276  m_fileout = new_fileout;
277  }
278  }
279  FileWriteStr(str_prefixed, m_fileout);
280  }
281 }
282 
284 {
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  // If debug.log file is more than 10% bigger the RECENT_DEBUG_HISTORY_SIZE
300  // trim it down by saving only the last RECENT_DEBUG_HISTORY_SIZE bytes
301  if (file && log_size > 11 * (RECENT_DEBUG_HISTORY_SIZE / 10))
302  {
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  {
316  fwrite(vch.data(), 1, nBytes, file);
317  fclose(file);
318  }
319  }
320  else if (file != nullptr)
321  fclose(file);
322 }
void EnableCategory(LogFlags flag)
Definition: logging.cpp:90
StdMutex m_cs
Definition: logging.h:65
BCLog::Logger & LogInstance()
Definition: logging.cpp:14
FILE * fopen(const fs::path &p, const char *mode)
Definition: fs.cpp:24
std::vector< LogCategory > LogCategoriesList()
Returns a vector of the log categories.
Definition: logging.cpp:177
fs::path m_file_path
Definition: logging.h:94
Definition: timer.h:17
#define strprintf
Format arguments and return the string or write to given std::ostream (see tinyformat::format doc for...
Definition: tinyformat.h:1164
BCLog::LogFlags flag
Definition: logging.cpp:128
std::atomic< bool > m_reopen_file
Definition: logging.h:95
static void LogPrintf(const char *fmt, const Args &... args)
Definition: logging.h:166
std::string FormatISO8601DateTime(int64_t nTime)
ISO 8601 formatting is preferred.
Definition: time.cpp:78
bool m_print_to_console
Definition: logging.h:87
bool m_print_to_file
Definition: logging.h:88
void LogPrintStr(const std::string &str)
Send a string to the log output.
Definition: logging.cpp:239
std::string category
Definition: logging.cpp:129
std::string category
Definition: logging.h:30
bool m_log_threadnames
Definition: logging.h:92
bool m_log_time_micros
Definition: logging.h:91
int64_t GetMockTime()
For testing.
Definition: time.cpp:52
void DisableCategory(LogFlags flag)
Definition: logging.cpp:103
bool WillLogCategory(LogFlags category) const
Definition: logging.cpp:116
std::atomic< uint32_t > m_categories
Log categories bitfield.
Definition: logging.h:79
void DisconnectTestLogger()
Only for testing.
Definition: logging.cpp:81
bool StartLogging()
Start logging (and flush all buffered messages)
Definition: logging.cpp:42
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:162
int64_t GetTimeMicros()
Returns the system time (not mockable)
Definition: time.cpp:65
std::atomic_bool m_started_new_line
m_started_new_line is a state variable that will suppress printing of the timestamp when multiple cal...
Definition: logging.h:76
const std::string & ThreadGetInternalName()
Get the thread&#39;s internal (in-memory) name; used e.g.
Definition: threadnames.cpp:53
static int FileWriteStr(const std::string &str, FILE *fp)
Definition: logging.cpp:37
const CLogCategoryDesc LogCategories[]
Definition: logging.cpp:132
bool fLogIPs
Definition: logging.cpp:35
bool active
Definition: logging.h:31
LogFlags
Definition: logging.h:35
bool m_log_timestamps
Definition: logging.h:90
static const bool DEFAULT_LOGIPS
Definition: logging.h:22
std::string LogEscapeMessage(const std::string &str)
Belts and suspenders: make sure outgoing log messages don&#39;t contain potentially suspicious characters...
Definition: logging.cpp:225
const char *const DEFAULT_DEBUGLOGFILE
Definition: logging.cpp:12
void ShrinkDebugFile()
Definition: logging.cpp:283
std::string LogTimestampStr(const std::string &str)
Definition: logging.cpp:192
bool DefaultShrinkDebugFile() const
Definition: logging.cpp:121