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