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 const char * const DEFAULT_DEBUGVMLOGFILE = "vm.log";
14
LogInstance()15 BCLog::Logger& LogInstance()
16 {
17 /**
18 * NOTE: the logger instances is leaked on exit. This is ugly, but will be
19 * cleaned up by the OS/libc. Defining a logger as a global object doesn't work
20 * since the order of destruction of static/global objects is undefined.
21 * Consider if the logger gets destroyed, and then some later destructor calls
22 * LogPrintf, maybe indirectly, and you get a core dump at shutdown trying to
23 * access the logger. When the shutdown sequence is fully audited and tested,
24 * explicit destruction of these objects can be implemented by changing this
25 * from a raw pointer to a std::unique_ptr.
26 * Since the destructor is never called, the logger and all its members must
27 * have a trivial destructor.
28 *
29 * This method of initialization was originally introduced in
30 * ee3374234c60aba2cc4c5cd5cac1c0aefc2d817c.
31 */
32 static BCLog::Logger* g_logger{new BCLog::Logger()};
33 return *g_logger;
34 }
35
36 bool fLogIPs = DEFAULT_LOGIPS;
37
FileWriteStr(const std::string & str,FILE * fp)38 static int FileWriteStr(const std::string &str, FILE *fp)
39 {
40 return fwrite(str.data(), 1, str.size(), fp);
41 }
42
StartLogging()43 bool BCLog::Logger::StartLogging()
44 {
45 std::lock_guard<std::mutex> scoped_lock(m_cs);
46
47 assert(m_buffering);
48 assert(m_fileout == nullptr);
49 assert(m_fileoutVM == nullptr); // qtum
50
51 if (m_print_to_file) {
52 assert(!m_file_path.empty());
53 assert(!m_file_pathVM.empty()); // qtum
54 m_fileout = fsbridge::fopen(m_file_path, "a");
55 m_fileoutVM = fsbridge::fopen(m_file_pathVM, "a");
56 if (!m_fileout || !m_fileoutVM) {
57 return false;
58 }
59
60 setbuf(m_fileout, nullptr); // unbuffered
61 setbuf(m_fileoutVM, nullptr); // unbuffered
62
63 // Add newlines to the logfile to distinguish this execution from the
64 // last one.
65 FileWriteStr("\n\n\n\n\n", m_fileout);
66 }
67
68 if (m_fileout) {
69 m_buffering = false;
70 }
71
72 ///////////////////////////////////////////// // qtum
73 if (m_fileoutVM) {
74 m_buffering = false;
75 }
76
77 // dump buffered messages from before we opened the log
78 while (!m_msgs_before_open.empty()) {
79 LogMsg logmsg= m_msgs_before_open.front();
80
81 FILE* file = logmsg.useVMLog ? m_fileoutVM : m_fileout;
82 if (file && m_print_to_file) FileWriteStr(logmsg.msg, file);
83 bool print_to_console = m_print_to_console;
84 if(print_to_console && logmsg.useVMLog && !m_show_evm_logs) print_to_console = false;
85 if (print_to_console) fwrite(logmsg.msg.data(), 1, logmsg.msg.size(), stdout);
86 for (const auto& cb : m_print_callbacks) {
87 cb(logmsg.msg);
88 }
89
90 m_msgs_before_open.pop_front();
91 }
92 /////////////////////////////////////////////
93 if (m_print_to_console) fflush(stdout);
94
95 return true;
96 }
97
DisconnectTestLogger()98 void BCLog::Logger::DisconnectTestLogger()
99 {
100 std::lock_guard<std::mutex> scoped_lock(m_cs);
101 m_buffering = true;
102 if (m_fileout != nullptr) fclose(m_fileout);
103 m_fileout = nullptr;
104 if (m_fileoutVM != nullptr) fclose(m_fileoutVM);
105 m_fileoutVM = nullptr;
106 m_print_callbacks.clear();
107 }
108
EnableCategory(BCLog::LogFlags flag)109 void BCLog::Logger::EnableCategory(BCLog::LogFlags flag)
110 {
111 m_categories |= flag;
112 }
113
EnableCategory(const std::string & str)114 bool BCLog::Logger::EnableCategory(const std::string& str)
115 {
116 BCLog::LogFlags flag;
117 if (!GetLogCategory(flag, str)) {
118 if (str == "db") {
119 // DEPRECATION: Added in 0.20, should start returning an error in 0.21
120 LogPrintf("Warning: logging category 'db' is deprecated, use 'walletdb' instead\n");
121 EnableCategory(BCLog::WALLETDB);
122 return true;
123 }
124 return false;
125 }
126 EnableCategory(flag);
127 return true;
128 }
129
DisableCategory(BCLog::LogFlags flag)130 void BCLog::Logger::DisableCategory(BCLog::LogFlags flag)
131 {
132 m_categories &= ~flag;
133 }
134
DisableCategory(const std::string & str)135 bool BCLog::Logger::DisableCategory(const std::string& str)
136 {
137 BCLog::LogFlags flag;
138 if (!GetLogCategory(flag, str)) return false;
139 DisableCategory(flag);
140 return true;
141 }
142
WillLogCategory(BCLog::LogFlags category) const143 bool BCLog::Logger::WillLogCategory(BCLog::LogFlags category) const
144 {
145 return (m_categories.load(std::memory_order_relaxed) & category) != 0;
146 }
147
DefaultShrinkDebugFile() const148 bool BCLog::Logger::DefaultShrinkDebugFile() const
149 {
150 return m_categories == BCLog::NONE;
151 }
152
153 struct CLogCategoryDesc
154 {
155 BCLog::LogFlags flag;
156 std::string category;
157 };
158
159 const CLogCategoryDesc LogCategories[] =
160 {
161 {BCLog::NONE, "0"},
162 {BCLog::NONE, "none"},
163 {BCLog::NET, "net"},
164 {BCLog::TOR, "tor"},
165 {BCLog::MEMPOOL, "mempool"},
166 {BCLog::HTTP, "http"},
167 {BCLog::BENCH, "bench"},
168 {BCLog::ZMQ, "zmq"},
169 {BCLog::WALLETDB, "walletdb"},
170 {BCLog::RPC, "rpc"},
171 {BCLog::ESTIMATEFEE, "estimatefee"},
172 {BCLog::ADDRMAN, "addrman"},
173 {BCLog::SELECTCOINS, "selectcoins"},
174 {BCLog::REINDEX, "reindex"},
175 {BCLog::CMPCTBLOCK, "cmpctblock"},
176 {BCLog::RAND, "rand"},
177 {BCLog::PRUNE, "prune"},
178 {BCLog::PROXY, "proxy"},
179 {BCLog::MEMPOOLREJ, "mempoolrej"},
180 {BCLog::LIBEVENT, "libevent"},
181 {BCLog::COINDB, "coindb"},
182 {BCLog::QT, "qt"},
183 {BCLog::LEVELDB, "leveldb"},
184 {BCLog::VALIDATION, "validation"},
185 {BCLog::COINSTAKE, "coinstake"},
186 {BCLog::HTTPPOLL, "http-poll"},
187 {BCLog::ALL, "1"},
188 {BCLog::ALL, "all"},
189 };
190
GetLogCategory(BCLog::LogFlags & flag,const std::string & str)191 bool GetLogCategory(BCLog::LogFlags& flag, const std::string& str)
192 {
193 if (str == "") {
194 flag = BCLog::ALL;
195 return true;
196 }
197 for (const CLogCategoryDesc& category_desc : LogCategories) {
198 if (category_desc.category == str) {
199 flag = category_desc.flag;
200 return true;
201 }
202 }
203 return false;
204 }
205
ListLogCategories()206 std::string ListLogCategories()
207 {
208 std::string ret;
209 int outcount = 0;
210 for (const CLogCategoryDesc& category_desc : LogCategories) {
211 // Omit the special cases.
212 if (category_desc.flag != BCLog::NONE && category_desc.flag != BCLog::ALL) {
213 if (outcount != 0) ret += ", ";
214 ret += category_desc.category;
215 outcount++;
216 }
217 }
218 return ret;
219 }
220
ListActiveLogCategories()221 std::vector<CLogCategoryActive> ListActiveLogCategories()
222 {
223 std::vector<CLogCategoryActive> ret;
224 for (const CLogCategoryDesc& category_desc : LogCategories) {
225 // Omit the special cases.
226 if (category_desc.flag != BCLog::NONE && category_desc.flag != BCLog::ALL) {
227 CLogCategoryActive catActive;
228 catActive.category = category_desc.category;
229 catActive.active = LogAcceptCategory(category_desc.flag);
230 ret.push_back(catActive);
231 }
232 }
233 return ret;
234 }
235
LogTimestampStr(const std::string & str)236 std::string BCLog::Logger::LogTimestampStr(const std::string& str)
237 {
238 std::string strStamped;
239
240 if (!m_log_timestamps)
241 return str;
242
243 if (m_started_new_line) {
244 int64_t nTimeMicros = GetTimeMicros();
245 strStamped = FormatISO8601DateTime(nTimeMicros/1000000);
246 if (m_log_time_micros) {
247 strStamped.pop_back();
248 strStamped += strprintf(".%06dZ", nTimeMicros%1000000);
249 }
250 int64_t mocktime = GetMockTime();
251 if (mocktime) {
252 strStamped += " (mocktime: " + FormatISO8601DateTime(mocktime) + ")";
253 }
254 strStamped += ' ' + str;
255 } else
256 strStamped = str;
257
258 return strStamped;
259 }
260
261 namespace BCLog {
262 /** Belts and suspenders: make sure outgoing log messages don't contain
263 * potentially suspicious characters, such as terminal control codes.
264 *
265 * This escapes control characters except newline ('\n') in C syntax.
266 * It escapes instead of removes them to still allow for troubleshooting
267 * issues where they accidentally end up in strings.
268 */
LogEscapeMessage(const std::string & str)269 std::string LogEscapeMessage(const std::string& str) {
270 std::string ret;
271 for (char ch_in : str) {
272 uint8_t ch = (uint8_t)ch_in;
273 if ((ch >= 32 || ch == '\n') && ch != '\x7f') {
274 ret += ch_in;
275 } else {
276 ret += strprintf("\\x%02x", ch);
277 }
278 }
279 return ret;
280 }
281 }
282
LogPrintStr(const std::string & str,bool useVMLog)283 void BCLog::Logger::LogPrintStr(const std::string& str, bool useVMLog)
284 {
285 std::lock_guard<std::mutex> scoped_lock(m_cs);
286 std::string str_prefixed = LogEscapeMessage(str);
287
288 if (m_log_threadnames && m_started_new_line) {
289 str_prefixed.insert(0, "[" + util::ThreadGetInternalName() + "] ");
290 }
291
292 str_prefixed = LogTimestampStr(str_prefixed);
293
294 m_started_new_line = !str.empty() && str[str.size()-1] == '\n';
295
296 if (m_buffering) {
297 // buffer if we haven't started logging yet
298 LogMsg logmsg(str_prefixed, useVMLog);
299 m_msgs_before_open.push_back(logmsg);
300 return;
301 }
302
303 bool print_to_console = m_print_to_console;
304 if(print_to_console && useVMLog && !m_show_evm_logs) print_to_console = false;
305
306 if (print_to_console) {
307 // print to console
308 fwrite(str_prefixed.data(), 1, str_prefixed.size(), stdout);
309 fflush(stdout);
310 }
311 for (const auto& cb : m_print_callbacks) {
312 cb(str_prefixed);
313 }
314 if (m_print_to_file) {
315 //////////////////////////////// // qtum
316 FILE* file = m_fileout;
317 if(useVMLog){
318 file = m_fileoutVM;
319 }
320 ////////////////////////////////
321 assert(file != nullptr);
322
323 // reopen the log file, if requested
324 if (m_reopen_file) {
325 m_reopen_file = false;
326 fs::path file_path = m_file_path;
327 if(useVMLog)
328 file_path = m_file_pathVM;
329 FILE* new_fileout = fsbridge::fopen(file_path, "a");
330 if (new_fileout) {
331 setbuf(new_fileout, nullptr); // unbuffered
332 fclose(file);
333 file = new_fileout;
334 }
335 }
336 FileWriteStr(str_prefixed, file);
337 }
338 }
339
ShrinkDebugFile()340 void BCLog::Logger::ShrinkDebugFile()
341 {
342 // Amount of debug.log to save at end when shrinking (must fit in memory)
343 constexpr size_t RECENT_DEBUG_HISTORY_SIZE = 10 * 1000000;
344
345 assert(!m_file_path.empty());
346
347 // Scroll debug.log if it's getting too big
348 FILE* file = fsbridge::fopen(m_file_path, "r");
349
350 // Special files (e.g. device nodes) may not have a size.
351 size_t log_size = 0;
352 try {
353 log_size = fs::file_size(m_file_path);
354 } catch (const fs::filesystem_error&) {}
355
356 // If debug.log file is more than 10% bigger the RECENT_DEBUG_HISTORY_SIZE
357 // trim it down by saving only the last RECENT_DEBUG_HISTORY_SIZE bytes
358 if (file && log_size > 11 * (RECENT_DEBUG_HISTORY_SIZE / 10))
359 {
360 // Restart the file with some of the end
361 std::vector<char> vch(RECENT_DEBUG_HISTORY_SIZE, 0);
362 if (fseek(file, -((long)vch.size()), SEEK_END)) {
363 LogPrintf("Failed to shrink debug log file: fseek(...) failed\n");
364 fclose(file);
365 return;
366 }
367 int nBytes = fread(vch.data(), 1, vch.size(), file);
368 fclose(file);
369
370 file = fsbridge::fopen(m_file_path, "w");
371 if (file)
372 {
373 fwrite(vch.data(), 1, nBytes, file);
374 fclose(file);
375 }
376 }
377 else if (file != nullptr)
378 fclose(file);
379 }
380