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