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