Branch data Line data Source code
1 : : // Copyright (c) 2009-2010 Satoshi Nakamoto
2 : : // Copyright (c) 2009-present 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 : : #ifndef BITCOIN_LOGGING_H
7 : : #define BITCOIN_LOGGING_H
8 : :
9 : : #include <crypto/siphash.h>
10 : : #include <threadsafety.h>
11 : : #include <tinyformat.h>
12 : : #include <util/fs.h>
13 : : #include <util/string.h>
14 : : #include <util/time.h>
15 : :
16 : : #include <atomic>
17 : : #include <cstdint>
18 : : #include <cstring>
19 : : #include <functional>
20 : : #include <list>
21 : : #include <mutex>
22 : : #include <source_location>
23 : : #include <string>
24 : : #include <unordered_map>
25 : : #include <unordered_set>
26 : : #include <vector>
27 : :
28 : : static const bool DEFAULT_LOGTIMEMICROS = false;
29 : : static const bool DEFAULT_LOGIPS = false;
30 : : static const bool DEFAULT_LOGTIMESTAMPS = true;
31 : : static const bool DEFAULT_LOGTHREADNAMES = false;
32 : : static const bool DEFAULT_LOGSOURCELOCATIONS = false;
33 : : static constexpr bool DEFAULT_LOGLEVELALWAYS = false;
34 : : extern const char * const DEFAULT_DEBUGLOGFILE;
35 : :
36 : : extern bool fLogIPs;
37 : :
38 : : struct SourceLocationEqual {
39 : 197500 : bool operator()(const std::source_location& lhs, const std::source_location& rhs) const noexcept
40 : : {
41 [ + - + - : 909160 : return lhs.line() == rhs.line() && std::string_view(lhs.file_name()) == std::string_view(rhs.file_name());
+ + + - -
+ ]
42 : : }
43 : : };
44 : :
45 : : struct SourceLocationHasher {
46 : 318913 : size_t operator()(const std::source_location& s) const noexcept
47 : : {
48 : : // Use CSipHasher(0, 0) as a simple way to get uniform distribution.
49 [ + - ]: 318913 : return static_cast<size_t>(CSipHasher(0, 0)
50 [ + - ]: 318913 : .Write(std::hash<std::string_view>{}(s.file_name()))
51 : 318913 : .Write(s.line())
52 : 318913 : .Finalize());
53 : : }
54 : : };
55 : :
56 : 474264 : struct LogCategory {
57 : : std::string category;
58 : : bool active;
59 : : };
60 : :
61 : : namespace BCLog {
62 : : using CategoryMask = uint64_t;
63 : : enum LogFlags : CategoryMask {
64 : : NONE = CategoryMask{0},
65 : : NET = (CategoryMask{1} << 0),
66 : : TOR = (CategoryMask{1} << 1),
67 : : MEMPOOL = (CategoryMask{1} << 2),
68 : : HTTP = (CategoryMask{1} << 3),
69 : : BENCH = (CategoryMask{1} << 4),
70 : : ZMQ = (CategoryMask{1} << 5),
71 : : WALLETDB = (CategoryMask{1} << 6),
72 : : RPC = (CategoryMask{1} << 7),
73 : : ESTIMATEFEE = (CategoryMask{1} << 8),
74 : : ADDRMAN = (CategoryMask{1} << 9),
75 : : SELECTCOINS = (CategoryMask{1} << 10),
76 : : REINDEX = (CategoryMask{1} << 11),
77 : : CMPCTBLOCK = (CategoryMask{1} << 12),
78 : : RAND = (CategoryMask{1} << 13),
79 : : PRUNE = (CategoryMask{1} << 14),
80 : : PROXY = (CategoryMask{1} << 15),
81 : : MEMPOOLREJ = (CategoryMask{1} << 16),
82 : : LIBEVENT = (CategoryMask{1} << 17),
83 : : COINDB = (CategoryMask{1} << 18),
84 : : QT = (CategoryMask{1} << 19),
85 : : LEVELDB = (CategoryMask{1} << 20),
86 : : VALIDATION = (CategoryMask{1} << 21),
87 : : I2P = (CategoryMask{1} << 22),
88 : : IPC = (CategoryMask{1} << 23),
89 : : #ifdef DEBUG_LOCKCONTENTION
90 : : LOCK = (CategoryMask{1} << 24),
91 : : #endif
92 : : BLOCKSTORAGE = (CategoryMask{1} << 25),
93 : : TXRECONCILIATION = (CategoryMask{1} << 26),
94 : : SCAN = (CategoryMask{1} << 27),
95 : : TXPACKAGES = (CategoryMask{1} << 28),
96 : : ALL = ~NONE,
97 : : };
98 : : enum class Level {
99 : : Trace = 0, // High-volume or detailed logging for development/debugging
100 : : Debug, // Reasonably noisy logging, but still usable in production
101 : : Info, // Default
102 : : Warning,
103 : : Error,
104 : : };
105 : : constexpr auto DEFAULT_LOG_LEVEL{Level::Debug};
106 : : constexpr size_t DEFAULT_MAX_LOG_BUFFER{1'000'000}; // buffer up to 1MB of log data prior to StartLogging
107 : : constexpr uint64_t RATELIMIT_MAX_BYTES{1024 * 1024}; // maximum number of bytes that can be logged within one window
108 : :
109 : : //! Keeps track of an individual source location and how many available bytes are left for logging from it.
110 : : class LogLimitStats
111 : : {
112 : : private:
113 : : //! Remaining bytes in the current window interval.
114 : : uint64_t m_available_bytes;
115 : : //! Number of bytes that were not consumed within the current window.
116 : : uint64_t m_dropped_bytes{0};
117 : :
118 : : public:
119 : 51548 : LogLimitStats(uint64_t max_bytes) : m_available_bytes{max_bytes} {}
120 : : //! Consume bytes from the window if enough bytes are available.
121 : : //!
122 : : //! Returns whether enough bytes were available.
123 : : bool Consume(uint64_t bytes);
124 : :
125 : 4 : uint64_t GetAvailableBytes() const
126 : : {
127 [ + - + - : 4 : return m_available_bytes;
+ - + - ]
128 : : }
129 : :
130 : 210032 : uint64_t GetDroppedBytes() const
131 : : {
132 [ + - + + : 210032 : return m_dropped_bytes;
+ - + - ]
[ + + + + ]
133 : : }
134 : : };
135 : :
136 : : /**
137 : : * Fixed window rate limiter for logging.
138 : : */
139 : 2 : class LogRateLimiter
140 : : {
141 : : private:
142 : : mutable StdMutex m_mutex;
143 : :
144 : : //! Counters for each source location that has attempted to log something.
145 : : std::unordered_map<std::source_location, LogLimitStats, SourceLocationHasher, SourceLocationEqual> m_source_locations GUARDED_BY(m_mutex);
146 : : //! True if at least one log location is suppressed. Cached view on m_source_locations for performance reasons.
147 : : std::atomic<bool> m_suppression_active{false};
148 : :
149 : : public:
150 : : using SchedulerFunction = std::function<void(std::function<void()>, std::chrono::milliseconds)>;
151 : : /**
152 : : * @param scheduler_func Callable object used to schedule resetting the window. The first
153 : : * parameter is the function to be executed, and the second is the
154 : : * reset_window interval.
155 : : * @param max_bytes Maximum number of bytes that can be logged for each source
156 : : * location.
157 : : * @param reset_window Time window after which the byte counters are reset.
158 : : */
159 : : LogRateLimiter(SchedulerFunction scheduler_func, uint64_t max_bytes, std::chrono::seconds reset_window);
160 : : //! Maximum number of bytes logged per location per window.
161 : : const uint64_t m_max_bytes;
162 : : //! Interval after which the window is reset.
163 : : const std::chrono::seconds m_reset_window;
164 : : //! Suppression status of a source log location.
165 : : enum class Status {
166 : : UNSUPPRESSED, // string fits within the limit
167 : : NEWLY_SUPPRESSED, // suppression has started since this string
168 : : STILL_SUPPRESSED, // suppression is still ongoing
169 : : };
170 : : //! Consumes `source_loc`'s available bytes corresponding to the size of the (formatted)
171 : : //! `str` and returns its status.
172 : : [[nodiscard]] Status Consume(
173 : : const std::source_location& source_loc,
174 : : const std::string& str) EXCLUSIVE_LOCKS_REQUIRED(!m_mutex);
175 : : //! Resets all usage to zero. Called periodically by the scheduler.
176 : : void Reset() EXCLUSIVE_LOCKS_REQUIRED(!m_mutex);
177 : : //! Returns true if any log locations are currently being suppressed.
178 [ + + + - : 209876 : bool SuppressionsActive() const { return m_suppression_active; }
+ - + - +
- + - +
- ][ + + ]
179 : : };
180 : :
181 : : class Logger
182 : : {
183 : : public:
184 : 32574 : struct BufferedLog {
185 : : SystemClock::time_point now;
186 : : std::chrono::seconds mocktime;
187 : : std::string str, threadname;
188 : : std::source_location source_loc;
189 : : LogFlags category;
190 : : Level level;
191 : : };
192 : :
193 : : private:
194 : : mutable StdMutex m_cs; // Can not use Mutex from sync.h because in debug mode it would cause a deadlock when a potential deadlock was detected
195 : :
196 : : FILE* m_fileout GUARDED_BY(m_cs) = nullptr;
197 : : std::list<BufferedLog> m_msgs_before_open GUARDED_BY(m_cs);
198 : : bool m_buffering GUARDED_BY(m_cs) = true; //!< Buffer messages before logging can be started.
199 : : size_t m_max_buffer_memusage GUARDED_BY(m_cs){DEFAULT_MAX_LOG_BUFFER};
200 : : size_t m_cur_buffer_memusage GUARDED_BY(m_cs){0};
201 : : size_t m_buffer_lines_discarded GUARDED_BY(m_cs){0};
202 : :
203 : : //! Manages the rate limiting of each log location.
204 : : std::unique_ptr<LogRateLimiter> m_limiter GUARDED_BY(m_cs);
205 : :
206 : : //! Category-specific log level. Overrides `m_log_level`.
207 : : std::unordered_map<LogFlags, Level> m_category_log_levels GUARDED_BY(m_cs);
208 : :
209 : : //! If there is no category-specific log level, all logs with a severity
210 : : //! level lower than `m_log_level` will be ignored.
211 : : std::atomic<Level> m_log_level{DEFAULT_LOG_LEVEL};
212 : :
213 : : /** Log categories bitfield. */
214 : : std::atomic<CategoryMask> m_categories{BCLog::NONE};
215 : :
216 : : void FormatLogStrInPlace(std::string& str, LogFlags category, Level level, const std::source_location& source_loc, std::string_view threadname, SystemClock::time_point now, std::chrono::seconds mocktime) const;
217 : :
218 : : std::string LogTimestampStr(SystemClock::time_point now, std::chrono::seconds mocktime) const;
219 : :
220 : : /** Slots that connect to the print signal */
221 : : std::list<std::function<void(const std::string&)>> m_print_callbacks GUARDED_BY(m_cs) {};
222 : :
223 : : /** Send a string to the log output (internal) */
224 : : void LogPrintStr_(std::string_view str, std::source_location&& source_loc, BCLog::LogFlags category, BCLog::Level level, bool should_ratelimit)
225 : : EXCLUSIVE_LOCKS_REQUIRED(m_cs);
226 : :
227 : : std::string GetLogPrefix(LogFlags category, Level level) const;
228 : :
229 : : public:
230 : : bool m_print_to_console = false;
231 : : bool m_print_to_file = false;
232 : :
233 : : bool m_log_timestamps = DEFAULT_LOGTIMESTAMPS;
234 : : bool m_log_time_micros = DEFAULT_LOGTIMEMICROS;
235 : : bool m_log_threadnames = DEFAULT_LOGTHREADNAMES;
236 : : bool m_log_sourcelocations = DEFAULT_LOGSOURCELOCATIONS;
237 : : bool m_always_print_category_level = DEFAULT_LOGLEVELALWAYS;
238 : :
239 : : fs::path m_file_path;
240 : : std::atomic<bool> m_reopen_file{false};
241 : :
242 : : /** Send a string to the log output */
243 : : void LogPrintStr(std::string_view str, std::source_location&& source_loc, BCLog::LogFlags category, BCLog::Level level, bool should_ratelimit)
244 : : EXCLUSIVE_LOCKS_REQUIRED(!m_cs);
245 : :
246 : : /** Returns whether logs will be written to any output */
247 : 5474464 : bool Enabled() const EXCLUSIVE_LOCKS_REQUIRED(!m_cs)
248 : : {
249 : 5474464 : StdLockGuard scoped_lock(m_cs);
250 [ + + + - : 5474464 : return m_buffering || m_print_to_console || m_print_to_file || !m_print_callbacks.empty();
+ + - + ]
251 : 5474464 : }
252 : :
253 : : /** Connect a slot to the print signal and return the connection */
254 : 2721 : std::list<std::function<void(const std::string&)>>::iterator PushBackCallback(std::function<void(const std::string&)> fun) EXCLUSIVE_LOCKS_REQUIRED(!m_cs)
255 : : {
256 : 2721 : StdLockGuard scoped_lock(m_cs);
257 [ + - ]: 2721 : m_print_callbacks.push_back(std::move(fun));
258 : 2721 : return --m_print_callbacks.end();
259 : 2721 : }
260 : :
261 : : /** Delete a connection */
262 : 2115 : void DeleteCallback(std::list<std::function<void(const std::string&)>>::iterator it) EXCLUSIVE_LOCKS_REQUIRED(!m_cs)
263 : : {
264 : 2115 : StdLockGuard scoped_lock(m_cs);
265 : 2115 : m_print_callbacks.erase(it);
266 : 2115 : }
267 : :
268 : : /** Start logging (and flush all buffered messages) */
269 : : bool StartLogging() EXCLUSIVE_LOCKS_REQUIRED(!m_cs);
270 : : /** Only for testing */
271 : : void DisconnectTestLogger() EXCLUSIVE_LOCKS_REQUIRED(!m_cs);
272 : :
273 : 1048 : void SetRateLimiting(std::unique_ptr<LogRateLimiter>&& limiter) EXCLUSIVE_LOCKS_REQUIRED(!m_cs)
274 : : {
275 : 1048 : StdLockGuard scoped_lock(m_cs);
276 : 1048 : m_limiter = std::move(limiter);
277 : 1048 : }
278 : :
279 : : /** Disable logging
280 : : * This offers a slight speedup and slightly smaller memory usage
281 : : * compared to leaving the logging system in its default state.
282 : : * Mostly intended for libbitcoin-kernel apps that don't want any logging.
283 : : * Should be used instead of StartLogging().
284 : : */
285 : : void DisableLogging() EXCLUSIVE_LOCKS_REQUIRED(!m_cs);
286 : :
287 : : void ShrinkDebugFile();
288 : :
289 : 9 : std::unordered_map<LogFlags, Level> CategoryLevels() const EXCLUSIVE_LOCKS_REQUIRED(!m_cs)
290 : : {
291 : 9 : StdLockGuard scoped_lock(m_cs);
292 [ + - ]: 9 : return m_category_log_levels;
293 : 9 : }
294 : 17 : void SetCategoryLogLevel(const std::unordered_map<LogFlags, Level>& levels) EXCLUSIVE_LOCKS_REQUIRED(!m_cs)
295 : : {
296 : 17 : StdLockGuard scoped_lock(m_cs);
297 [ + - ]: 17 : m_category_log_levels = levels;
298 : 17 : }
299 : : bool SetCategoryLogLevel(std::string_view category_str, std::string_view level_str) EXCLUSIVE_LOCKS_REQUIRED(!m_cs);
300 : :
301 [ + - ][ + - : 5049815 : Level LogLevel() const { return m_log_level.load(); }
+ - + - +
- ]
302 [ + - ]: 24 : void SetLogLevel(Level level) { m_log_level = level; }
303 : : bool SetLogLevel(std::string_view level);
304 : :
305 [ - + ]: 20 : CategoryMask GetCategoryMask() const { return m_categories.load(); }
306 : :
307 : : void EnableCategory(LogFlags flag);
308 : : bool EnableCategory(std::string_view str);
309 : : void DisableCategory(LogFlags flag);
310 : : bool DisableCategory(std::string_view str);
311 : :
312 : : bool WillLogCategory(LogFlags category) const;
313 : : bool WillLogCategoryLevel(LogFlags category, Level level) const EXCLUSIVE_LOCKS_REQUIRED(!m_cs);
314 : :
315 : : /** Returns a vector of the log categories in alphabetical order. */
316 : : std::vector<LogCategory> LogCategoriesList() const;
317 : : /** Returns a string with the log categories in alphabetical order. */
318 : 5636 : std::string LogCategoriesString() const
319 : : {
320 [ + - + - ]: 163444 : return util::Join(LogCategoriesList(), ", ", [&](const LogCategory& i) { return i.category; });
321 : : };
322 : :
323 : : //! Returns a string with all user-selectable log levels.
324 : : std::string LogLevelsString() const;
325 : :
326 : : //! Returns the string representation of a log level.
327 : : static std::string LogLevelToStr(BCLog::Level level);
328 : :
329 : : bool DefaultShrinkDebugFile() const;
330 : : };
331 : :
332 : : } // namespace BCLog
333 : :
334 : : BCLog::Logger& LogInstance();
335 : :
336 : : /** Return true if log accepts specified category, at the specified level. */
337 : 5107583 : static inline bool LogAcceptCategory(BCLog::LogFlags category, BCLog::Level level)
338 : : {
339 : 5107583 : return LogInstance().WillLogCategoryLevel(category, level);
340 : : }
341 : :
342 : : /** Return true if str parses as a log category and set the flag */
343 : : bool GetLogCategory(BCLog::LogFlags& flag, std::string_view str);
344 : :
345 : : template <typename... Args>
346 : 5474464 : inline void LogPrintFormatInternal(std::source_location&& source_loc, const BCLog::LogFlags flag, const BCLog::Level level, const bool should_ratelimit, util::ConstevalFormatString<sizeof...(Args)> fmt, const Args&... args)
347 : : {
348 [ + + ]: 5474464 : if (LogInstance().Enabled()) {
349 [ + - ]: 5474307 : std::string log_msg;
350 : : try {
351 [ + - ]: 5474307 : log_msg = tfm::format(fmt, args...);
352 [ - - ]: 0 : } catch (tinyformat::format_error& fmterr) {
353 [ - - - - : 0 : log_msg = "Error \"" + std::string{fmterr.what()} + "\" while formatting log message: " + fmt.fmt;
- - ]
354 : : }
355 [ + - + - ]: 5474307 : LogInstance().LogPrintStr(log_msg, std::move(source_loc), flag, level, should_ratelimit);
356 : 5474307 : }
357 : 5474464 : }
358 : :
359 : : #define LogPrintLevel_(category, level, should_ratelimit, ...) LogPrintFormatInternal(std::source_location::current(), category, level, should_ratelimit, __VA_ARGS__)
360 : :
361 : : // Log unconditionally. Uses basic rate limiting to mitigate disk filling attacks.
362 : : // Be conservative when using functions that unconditionally log to debug.log!
363 : : // It should not be the case that an inbound peer can fill up a user's storage
364 : : // with debug.log entries.
365 : : #define LogInfo(...) LogPrintLevel_(BCLog::LogFlags::ALL, BCLog::Level::Info, /*should_ratelimit=*/true, __VA_ARGS__)
366 : : #define LogWarning(...) LogPrintLevel_(BCLog::LogFlags::ALL, BCLog::Level::Warning, /*should_ratelimit=*/true, __VA_ARGS__)
367 : : #define LogError(...) LogPrintLevel_(BCLog::LogFlags::ALL, BCLog::Level::Error, /*should_ratelimit=*/true, __VA_ARGS__)
368 : :
369 : : // Deprecated unconditional logging.
370 : : #define LogPrintf(...) LogInfo(__VA_ARGS__)
371 : :
372 : : // Use a macro instead of a function for conditional logging to prevent
373 : : // evaluating arguments when logging for the category is not enabled.
374 : :
375 : : // Log by prefixing the output with the passed category name and severity level. This can either
376 : : // log conditionally if the category is allowed or unconditionally if level >= BCLog::Level::Info
377 : : // is passed. If this function logs unconditionally, logging to disk is rate-limited. This is
378 : : // important so that callers don't need to worry about accidentally introducing a disk-fill
379 : : // vulnerability if level >= Info is used. Additionally, users specifying -debug are assumed to be
380 : : // developers or power users who are aware that -debug may cause excessive disk usage due to logging.
381 : : #define LogPrintLevel(category, level, ...) \
382 : : do { \
383 : : if (LogAcceptCategory((category), (level))) { \
384 : : bool rate_limit{level >= BCLog::Level::Info}; \
385 : : LogPrintLevel_(category, level, rate_limit, __VA_ARGS__); \
386 : : } \
387 : : } while (0)
388 : :
389 : : // Log conditionally, prefixing the output with the passed category name.
390 : : #define LogDebug(category, ...) LogPrintLevel(category, BCLog::Level::Debug, __VA_ARGS__)
391 : : #define LogTrace(category, ...) LogPrintLevel(category, BCLog::Level::Trace, __VA_ARGS__)
392 : :
393 : : #endif // BITCOIN_LOGGING_H
|
