Branch data Line data Source code
# 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/string.h>
# 9 : : #include <util/time.h>
# 10 : :
# 11 : : #include <mutex>
# 12 : :
# 13 : : const char * const DEFAULT_DEBUGLOGFILE = "debug.log";
# 14 : :
# 15 : : BCLog::Logger& LogInstance()
# 16 : 12095813 : {
# 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 ~Logger() destructor is never called, the Logger class and all
# 27 : : * its subclasses must have implicitly-defined destructors.
# 28 : : *
# 29 : : * This method of initialization was originally introduced in
# 30 : : * ee3374234c60aba2cc4c5cd5cac1c0aefc2d817c.
# 31 : : */
# 32 : 12095813 : static BCLog::Logger* g_logger{new BCLog::Logger()};
# 33 : 12095813 : return *g_logger;
# 34 : 12095813 : }
# 35 : :
# 36 : : bool fLogIPs = DEFAULT_LOGIPS;
# 37 : :
# 38 : : static int FileWriteStr(const std::string &str, FILE *fp)
# 39 : 4159549 : {
# 40 : 4159549 : return fwrite(str.data(), 1, str.size(), fp);
# 41 : 4159549 : }
# 42 : :
# 43 : : bool BCLog::Logger::StartLogging()
# 44 : 1511 : {
# 45 : 1511 : StdLockGuard scoped_lock(m_cs);
# 46 : :
# 47 : 1511 : assert(m_buffering);
# 48 : 1511 : assert(m_fileout == nullptr);
# 49 : :
# 50 [ + + ]: 1511 : if (m_print_to_file) {
# 51 : 1510 : assert(!m_file_path.empty());
# 52 : 1510 : m_fileout = fsbridge::fopen(m_file_path, "a");
# 53 [ + + ]: 1510 : if (!m_fileout) {
# 54 : 2 : return false;
# 55 : 2 : }
# 56 : :
# 57 : 1508 : setbuf(m_fileout, nullptr); // unbuffered
# 58 : :
# 59 : : // Add newlines to the logfile to distinguish this execution from the
# 60 : : // last one.
# 61 : 1508 : FileWriteStr("\n\n\n\n\n", m_fileout);
# 62 : 1508 : }
# 63 : :
# 64 : : // dump buffered messages from before we opened the log
# 65 : 1511 : m_buffering = false;
# 66 [ + + ]: 9587 : while (!m_msgs_before_open.empty()) {
# 67 : 8078 : const std::string& s = m_msgs_before_open.front();
# 68 : :
# 69 [ + + ]: 8078 : if (m_print_to_file) FileWriteStr(s, m_fileout);
# 70 [ - + ]: 8078 : if (m_print_to_console) fwrite(s.data(), 1, s.size(), stdout);
# 71 [ + + ]: 8078 : for (const auto& cb : m_print_callbacks) {
# 72 : 3392 : cb(s);
# 73 : 3392 : }
# 74 : :
# 75 : 8078 : m_msgs_before_open.pop_front();
# 76 : 8078 : }
# 77 [ - + ]: 1509 : if (m_print_to_console) fflush(stdout);
# 78 : :
# 79 : 1509 : return true;
# 80 : 1511 : }
# 81 : :
# 82 : : void BCLog::Logger::DisconnectTestLogger()
# 83 : 847 : {
# 84 : 847 : StdLockGuard scoped_lock(m_cs);
# 85 : 847 : m_buffering = true;
# 86 [ + - ]: 847 : if (m_fileout != nullptr) fclose(m_fileout);
# 87 : 847 : m_fileout = nullptr;
# 88 : 847 : m_print_callbacks.clear();
# 89 : 847 : }
# 90 : :
# 91 : : void BCLog::Logger::EnableCategory(BCLog::LogFlags flag)
# 92 : 1515 : {
# 93 : 1515 : m_categories |= flag;
# 94 : 1515 : }
# 95 : :
# 96 : : bool BCLog::Logger::EnableCategory(const std::string& str)
# 97 : 1515 : {
# 98 : 1515 : BCLog::LogFlags flag;
# 99 [ - + ]: 1515 : if (!GetLogCategory(flag, str)) return false;
# 100 : 1515 : EnableCategory(flag);
# 101 : 1515 : return true;
# 102 : 1515 : }
# 103 : :
# 104 : : void BCLog::Logger::DisableCategory(BCLog::LogFlags flag)
# 105 : 3029 : {
# 106 : 3029 : m_categories &= ~flag;
# 107 : 3029 : }
# 108 : :
# 109 : : bool BCLog::Logger::DisableCategory(const std::string& str)
# 110 : 3029 : {
# 111 : 3029 : BCLog::LogFlags flag;
# 112 [ - + ]: 3029 : if (!GetLogCategory(flag, str)) return false;
# 113 : 3029 : DisableCategory(flag);
# 114 : 3029 : return true;
# 115 : 3029 : }
# 116 : :
# 117 : : bool BCLog::Logger::WillLogCategory(BCLog::LogFlags category) const
# 118 : 3807351 : {
# 119 : 3807351 : return (m_categories.load(std::memory_order_relaxed) & category) != 0;
# 120 : 3807351 : }
# 121 : :
# 122 : : bool BCLog::Logger::DefaultShrinkDebugFile() const
# 123 : 662 : {
# 124 : 662 : return m_categories == BCLog::NONE;
# 125 : 662 : }
# 126 : :
# 127 : : struct CLogCategoryDesc
# 128 : : {
# 129 : : BCLog::LogFlags flag;
# 130 : : std::string category;
# 131 : : };
# 132 : :
# 133 : : const CLogCategoryDesc LogCategories[] =
# 134 : : {
# 135 : : {BCLog::NONE, "0"},
# 136 : : {BCLog::NONE, "none"},
# 137 : : {BCLog::NET, "net"},
# 138 : : {BCLog::TOR, "tor"},
# 139 : : {BCLog::MEMPOOL, "mempool"},
# 140 : : {BCLog::HTTP, "http"},
# 141 : : {BCLog::BENCH, "bench"},
# 142 : : {BCLog::ZMQ, "zmq"},
# 143 : : {BCLog::WALLETDB, "walletdb"},
# 144 : : {BCLog::RPC, "rpc"},
# 145 : : {BCLog::ESTIMATEFEE, "estimatefee"},
# 146 : : {BCLog::ADDRMAN, "addrman"},
# 147 : : {BCLog::SELECTCOINS, "selectcoins"},
# 148 : : {BCLog::REINDEX, "reindex"},
# 149 : : {BCLog::CMPCTBLOCK, "cmpctblock"},
# 150 : : {BCLog::RAND, "rand"},
# 151 : : {BCLog::PRUNE, "prune"},
# 152 : : {BCLog::PROXY, "proxy"},
# 153 : : {BCLog::MEMPOOLREJ, "mempoolrej"},
# 154 : : {BCLog::LIBEVENT, "libevent"},
# 155 : : {BCLog::COINDB, "coindb"},
# 156 : : {BCLog::QT, "qt"},
# 157 : : {BCLog::LEVELDB, "leveldb"},
# 158 : : {BCLog::VALIDATION, "validation"},
# 159 : : {BCLog::I2P, "i2p"},
# 160 : : {BCLog::IPC, "ipc"},
# 161 : : {BCLog::ALL, "1"},
# 162 : : {BCLog::ALL, "all"},
# 163 : : };
# 164 : :
# 165 : : bool GetLogCategory(BCLog::LogFlags& flag, const std::string& str)
# 166 : 4544 : {
# 167 [ + + ]: 4544 : if (str == "") {
# 168 : 1514 : flag = BCLog::ALL;
# 169 : 1514 : return true;
# 170 : 1514 : }
# 171 [ + - ]: 65146 : for (const CLogCategoryDesc& category_desc : LogCategories) {
# 172 [ + + ]: 65146 : if (category_desc.category == str) {
# 173 : 3030 : flag = category_desc.flag;
# 174 : 3030 : return true;
# 175 : 3030 : }
# 176 : 65146 : }
# 177 : 3030 : return false;
# 178 : 3030 : }
# 179 : :
# 180 : : std::vector<LogCategory> BCLog::Logger::LogCategoriesList() const
# 181 : 2878 : {
# 182 : 2878 : std::vector<LogCategory> ret;
# 183 [ + + ]: 80584 : for (const CLogCategoryDesc& category_desc : LogCategories) {
# 184 : : // Omit the special cases.
# 185 [ + + ][ + + ]: 80584 : if (category_desc.flag != BCLog::NONE && category_desc.flag != BCLog::ALL) {
# 186 : 69072 : LogCategory catActive;
# 187 : 69072 : catActive.category = category_desc.category;
# 188 : 69072 : catActive.active = WillLogCategory(category_desc.flag);
# 189 : 69072 : ret.push_back(catActive);
# 190 : 69072 : }
# 191 : 80584 : }
# 192 : 2878 : return ret;
# 193 : 2878 : }
# 194 : :
# 195 : : std::string BCLog::Logger::LogTimestampStr(const std::string& str)
# 196 : 4167906 : {
# 197 : 4167906 : std::string strStamped;
# 198 : :
# 199 [ - + ]: 4167906 : if (!m_log_timestamps)
# 200 : 0 : return str;
# 201 : :
# 202 [ + + ]: 4167906 : if (m_started_new_line) {
# 203 : 4054897 : int64_t nTimeMicros = GetTimeMicros();
# 204 : 4054897 : strStamped = FormatISO8601DateTime(nTimeMicros/1000000);
# 205 [ + + ]: 4054897 : if (m_log_time_micros) {
# 206 : 4045068 : strStamped.pop_back();
# 207 : 4045068 : strStamped += strprintf(".%06dZ", nTimeMicros%1000000);
# 208 : 4045068 : }
# 209 : 4054897 : std::chrono::seconds mocktime = GetMockTime();
# 210 [ + + ]: 4054897 : if (mocktime > 0s) {
# 211 : 213840 : strStamped += " (mocktime: " + FormatISO8601DateTime(count_seconds(mocktime)) + ")";
# 212 : 213840 : }
# 213 : 4054897 : strStamped += ' ' + str;
# 214 : 4054897 : } else
# 215 : 113009 : strStamped = str;
# 216 : :
# 217 : 4167906 : return strStamped;
# 218 : 4167906 : }
# 219 : :
# 220 : : namespace BCLog {
# 221 : : /** Belts and suspenders: make sure outgoing log messages don't contain
# 222 : : * potentially suspicious characters, such as terminal control codes.
# 223 : : *
# 224 : : * This escapes control characters except newline ('\n') in C syntax.
# 225 : : * It escapes instead of removes them to still allow for troubleshooting
# 226 : : * issues where they accidentally end up in strings.
# 227 : : */
# 228 : 4167910 : std::string LogEscapeMessage(const std::string& str) {
# 229 : 4167910 : std::string ret;
# 230 [ + + ]: 300703378 : for (char ch_in : str) {
# 231 : 300703378 : uint8_t ch = (uint8_t)ch_in;
# 232 [ + + ][ + + ]: 300703378 : if ((ch >= 32 || ch == '\n') && ch != '\x7f') {
# [ + + ]
# 233 : 300701297 : ret += ch_in;
# 234 : 300701297 : } else {
# 235 : 2081 : ret += strprintf("\\x%02x", ch);
# 236 : 2081 : }
# 237 : 300703378 : }
# 238 : 4167910 : return ret;
# 239 : 4167910 : }
# 240 : : }
# 241 : :
# 242 : : void BCLog::Logger::LogPrintStr(const std::string& str, const std::string& logging_function, const std::string& source_file, const int source_line)
# 243 : 4167752 : {
# 244 : 4167752 : StdLockGuard scoped_lock(m_cs);
# 245 : 4167752 : std::string str_prefixed = LogEscapeMessage(str);
# 246 : :
# 247 [ + + ][ + + ]: 4167752 : if (m_log_sourcelocations && m_started_new_line) {
# 248 : 4045068 : str_prefixed.insert(0, "[" + RemovePrefix(source_file, "./") + ":" + ToString(source_line) + "] [" + logging_function + "] ");
# 249 : 4045068 : }
# 250 : :
# 251 [ - + ][ # # ]: 4167752 : if (m_log_threadnames && m_started_new_line) {
# 252 : 0 : str_prefixed.insert(0, "[" + util::ThreadGetInternalName() + "] ");
# 253 : 0 : }
# 254 : :
# 255 : 4167752 : str_prefixed = LogTimestampStr(str_prefixed);
# 256 : :
# 257 [ + + ][ + + ]: 4167906 : m_started_new_line = !str.empty() && str[str.size()-1] == '\n';
# 258 : :
# 259 [ + + ]: 4167752 : if (m_buffering) {
# 260 : : // buffer if we haven't started logging yet
# 261 : 17936 : m_msgs_before_open.push_back(str_prefixed);
# 262 : 17936 : return;
# 263 : 17936 : }
# 264 : :
# 265 [ - + ]: 4149816 : if (m_print_to_console) {
# 266 : : // print to console
# 267 : 0 : fwrite(str_prefixed.data(), 1, str_prefixed.size(), stdout);
# 268 : 0 : fflush(stdout);
# 269 : 0 : }
# 270 [ + + ]: 4149816 : for (const auto& cb : m_print_callbacks) {
# 271 : 1578108 : cb(str_prefixed);
# 272 : 1578108 : }
# 273 [ + + ]: 4149970 : if (m_print_to_file) {
# 274 : 4149970 : assert(m_fileout != nullptr);
# 275 : :
# 276 : : // reopen the log file, if requested
# 277 [ - + ]: 4149970 : if (m_reopen_file) {
# 278 : 0 : m_reopen_file = false;
# 279 : 0 : FILE* new_fileout = fsbridge::fopen(m_file_path, "a");
# 280 [ # # ]: 0 : if (new_fileout) {
# 281 : 0 : setbuf(new_fileout, nullptr); // unbuffered
# 282 : 0 : fclose(m_fileout);
# 283 : 0 : m_fileout = new_fileout;
# 284 : 0 : }
# 285 : 0 : }
# 286 : 4149970 : FileWriteStr(str_prefixed, m_fileout);
# 287 : 4149970 : }
# 288 : 4149816 : }
# 289 : :
# 290 : : void BCLog::Logger::ShrinkDebugFile()
# 291 : 0 : {
# 292 : : // Amount of debug.log to save at end when shrinking (must fit in memory)
# 293 : 0 : constexpr size_t RECENT_DEBUG_HISTORY_SIZE = 10 * 1000000;
# 294 : :
# 295 : 0 : assert(!m_file_path.empty());
# 296 : :
# 297 : : // Scroll debug.log if it's getting too big
# 298 : 0 : FILE* file = fsbridge::fopen(m_file_path, "r");
# 299 : :
# 300 : : // Special files (e.g. device nodes) may not have a size.
# 301 : 0 : size_t log_size = 0;
# 302 : 0 : try {
# 303 : 0 : log_size = fs::file_size(m_file_path);
# 304 : 0 : } catch (const fs::filesystem_error&) {}
# 305 : :
# 306 : : // If debug.log file is more than 10% bigger the RECENT_DEBUG_HISTORY_SIZE
# 307 : : // trim it down by saving only the last RECENT_DEBUG_HISTORY_SIZE bytes
# 308 [ # # ][ # # ]: 0 : if (file && log_size > 11 * (RECENT_DEBUG_HISTORY_SIZE / 10))
# 309 : 0 : {
# 310 : : // Restart the file with some of the end
# 311 : 0 : std::vector<char> vch(RECENT_DEBUG_HISTORY_SIZE, 0);
# 312 [ # # ]: 0 : if (fseek(file, -((long)vch.size()), SEEK_END)) {
# 313 : 0 : LogPrintf("Failed to shrink debug log file: fseek(...) failed\n");
# 314 : 0 : fclose(file);
# 315 : 0 : return;
# 316 : 0 : }
# 317 : 0 : int nBytes = fread(vch.data(), 1, vch.size(), file);
# 318 : 0 : fclose(file);
# 319 : :
# 320 : 0 : file = fsbridge::fopen(m_file_path, "w");
# 321 [ # # ]: 0 : if (file)
# 322 : 0 : {
# 323 : 0 : fwrite(vch.data(), 1, nBytes, file);
# 324 : 0 : fclose(file);
# 325 : 0 : }
# 326 : 0 : }
# 327 [ # # ]: 0 : else if (file != nullptr)
# 328 : 0 : fclose(file);
# 329 : 0 : }
|
