1/*
2 * LegacyClonk
3 *
4 * Copyright (c) 1998-2000, Matthes Bender (RedWolf Design)
5 * Copyright (c) 2017-2021, The LegacyClonk Team and contributors
6 *
7 * Distributed under the terms of the ISC license; see accompanying file
8 * "COPYING" for details.
9 *
10 * "Clonk" is a registered trademark of Matthes Bender, used with permission.
11 * See accompanying file "TRADEMARK" for details.
12 *
13 * To redistribute this file separately, substitute the full license texts
14 * for the above references.
15 */
16
17/* Log file handling */
18
19#include <C4Log.h>
20
21#include <C4Console.h>
22#include <C4GameLobby.h>
23#include <C4LogBuf.h>
24#include "C4TextEncoding.h"
25#include "StdMarkup.h"
26
27#ifdef _WIN32
28#include <share.h>
29#endif
30
31#include <ranges>
32
33#include <spdlog/cfg/helpers.h>
34#include <spdlog/pattern_formatter.h>
35#include <spdlog/sinks/ringbuffer_sink.h>
36#include <spdlog/sinks/stdout_color_sinks.h>
37
38#ifdef _WIN32
39#include <spdlog/sinks/msvc_sink.h>
40#endif
41
42namespace
43{
44class LogLevelPrefixFormatterFlag : public spdlog::custom_flag_formatter
45{
46public:
47 void format(const spdlog::details::log_msg &msg, const tm &, std::string &dest) override
48 {
49 switch (msg.level)
50 {
51 case spdlog::level::trace:
52 dest += "TRACE: ";
53 break;
54
55 case spdlog::level::debug:
56 dest += "DEBUG: ";
57 break;
58
59 case spdlog::level::info:
60 break;
61
62 case spdlog::level::warn:
63 dest += "WARNING: ";
64 break;
65
66 case spdlog::level::err:
67 dest += "ERROR: ";
68 break;
69
70 case spdlog::level::critical:
71 dest += "CRITICAL: ";
72 break;
73
74 default:
75 std::unreachable();
76 }
77 }
78
79 std::unique_ptr<custom_flag_formatter> clone() const override
80 {
81 return std::make_unique<LogLevelPrefixFormatterFlag>();
82 }
83};
84
85
86class LoggerNameIfExistsFormatterFlag : public spdlog::custom_flag_formatter
87{
88public:
89 void format(const spdlog::details::log_msg &msg, const tm &, std::string &dest) override
90 {
91 if (!msg.logger_name.empty())
92 {
93 dest += std::format(fmt: "[{}] ", args: msg.logger_name);
94 }
95 }
96
97 std::unique_ptr<custom_flag_formatter> clone() const override
98 {
99 return std::make_unique<LoggerNameIfExistsFormatterFlag>();
100 }
101};
102
103class StrippedTextFormatterFlag : public spdlog::custom_flag_formatter
104{
105public:
106 void format(const spdlog::details::log_msg &msg, const tm &, std::string &dest) override
107 {
108 if (msg.payload.empty())
109 {
110 return;
111 }
112
113 dest.resize_and_overwrite(n: dest.size() + msg.payload.size(), op: [&msg, oldSize{dest.size()}](char *const ptr, const std::size_t size)
114 {
115 std::fill_n(first: ptr + oldSize, n: size - oldSize, value: 0xAB);
116 auto oldSize2 = oldSize;
117 auto &payload = msg.payload;
118 auto copied = msg.payload.copy(str: ptr + oldSize, n: msg.payload.size());
119 ptr[oldSize + copied] = '\0';
120
121 CMarkup markup{false};
122 if (markup.StripMarkup(szText: ptr + oldSize))
123 {
124 return std::strlen(s: ptr);
125 }
126 else
127 {
128 return size;
129 }
130 });
131 }
132
133 std::unique_ptr<custom_flag_formatter> clone() const override
134 {
135 return std::make_unique<StrippedTextFormatterFlag>();
136 }
137};
138}
139
140C4LogSystem::LogSink::LogSink(std::unique_ptr<spdlog::formatter> formatter)
141 : base_sink{std::move(formatter)}
142{
143 std::string logFileName{C4CFN_Log};
144 // open
145 int iLog = 2;
146#ifdef _WIN32
147 while (!(file = _fsopen(logFileName.c_str(), "wb", _SH_DENYWR)))
148#else
149 while (!(file = fopen(filename: logFileName.c_str(), modes: "wb")))
150#endif
151 {
152 if (errno == EACCES)
153 {
154#ifdef _WIN32
155 if (GetLastError() != ERROR_SHARING_VIOLATION)
156#endif
157 throw CStdApp::StartupException{"Cannot create log file (Permission denied).\nPlease ensure that LegacyClonk is allowed to write in its installation directory."};
158 }
159
160 if (iLog == 100)
161 {
162 // it is extremely unlikely that someone is running 100 clonk instances at the same time in the same directory
163 throw CStdApp::StartupException{std::string{"Cannot create log file ("} + strerror(errno) + ")"};
164 }
165
166 // try different name
167 logFileName = std::format(C4CFN_LogEx, args: iLog++);
168 }
169}
170
171C4LogSystem::LogSink::~LogSink()
172{
173 std::fclose(stream: file);
174}
175
176void C4LogSystem::LogSink::sink_it_(const spdlog::details::log_msg &msg)
177{
178 std::string formatted;
179 formatter_->format(msg, dest&: formatted);
180 std::fwrite(ptr: formatted.data(), size: sizeof(char), n: formatted.size(), s: file);
181}
182
183void C4LogSystem::LogSink::flush_()
184{
185 std::fflush(stream: file);
186}
187
188C4LogSystem::GuiSink::GuiSink(const spdlog::level::level_enum level, const bool showLoggerNameInGui)
189{
190 set_level(level);
191
192 auto guiFormatter = std::make_unique<spdlog::pattern_formatter>();
193 guiFormatter->add_flag<LogLevelPrefixFormatterFlag>(flag: '*');
194 guiFormatter->add_flag<StrippedTextFormatterFlag>(flag: 'v');
195
196 if (showLoggerNameInGui)
197 {
198 guiFormatter->add_flag<LoggerNameIfExistsFormatterFlag>(flag: '~').set_pattern("%~%*%v");
199 }
200 else
201 {
202 guiFormatter->set_pattern("%*%v");
203 }
204
205 set_formatter(std::move(guiFormatter));
206}
207
208void C4LogSystem::GuiSink::sink_it_(const spdlog::details::log_msg &msg)
209{
210 std::string formatted;
211 formatter_->format(msg, dest&: formatted);
212
213 if (Application.IsMainThread())
214 {
215 DoLog(message: formatted);
216 }
217 else
218 {
219 Application.InteractiveThread.ExecuteInMainThread(function: [formatted{std::move(formatted)}, weak{weak_from_this()}]
220 {
221 if (auto strong = weak.lock())
222 {
223 strong->DoLog(message: formatted);
224 }
225 });
226 }
227}
228
229void C4LogSystem::GuiSink::DoLog(const std::string &message)
230{
231 if (C4GameLobby::MainDlg *const lobby{Game.Network.GetLobby()}; lobby && Game.pGUI)
232 {
233 lobby->OnLog(szLogMsg: message.c_str());
234 }
235
236 Console.Out(text: message);
237
238 if (Game.GraphicsSystem.MessageBoard.Active)
239 {
240 Game.GraphicsSystem.MessageBoard.AddLog(szMessage: message.c_str());
241 Game.GraphicsSystem.MessageBoard.LogNotify();
242 }
243}
244
245std::vector<std::string> C4LogSystem::RingbufferSink::TakeMessages()
246{
247 const std::lock_guard lock{mutex_};
248
249 const std::size_t size{ringbuffer.size()};
250 std::vector<std::string> result;
251 result.reserve(n: size);
252
253 std::ranges::generate_n(std::back_inserter(x&: result), size, [this]
254 {
255 auto &msg = ringbuffer.front();
256 std::string formatted;
257 formatter_->format(msg, dest&: formatted);
258
259 ringbuffer.pop_front();
260 return formatted;
261 });
262
263 return result;
264}
265
266void C4LogSystem::RingbufferSink::Clear()
267{
268 const std::lock_guard lock{mutex_};
269 ringbuffer = spdlog::details::circular_q<spdlog::details::log_msg_buffer>{size};
270}
271
272void C4LogSystem::RingbufferSink::sink_it_(const spdlog::details::log_msg &msg)
273{
274 ringbuffer.push_back(item: spdlog::details::log_msg_buffer{msg});
275}
276
277void C4LogSystem::ClonkToUtf8Sink::log(const spdlog::details::log_msg &msg)
278{
279 const std::string payloadAsUtf8{TextEncodingConverter.ClonkToUtf8<char>(input: msg.payload)};
280
281 spdlog::details::log_msg utf8Msg{msg};
282 utf8Msg.payload = payloadAsUtf8;
283
284 for (const auto &sink : sinks)
285 {
286 sink->log(msg: utf8Msg);
287 }
288}
289
290void C4LogSystem::ClonkToUtf8Sink::flush()
291{
292 for (const auto &sink : sinks)
293 {
294 sink->flush();
295 }
296}
297
298C4LogSystem::C4LogSystem()
299{
300 spdlog::set_automatic_registration(false);
301
302 defaultPatternFormatter = std::make_unique<spdlog::pattern_formatter>();
303 defaultPatternFormatter->add_flag<LoggerNameIfExistsFormatterFlag>(flag: '~');
304 defaultPatternFormatter->add_flag<StrippedTextFormatterFlag>(flag: 'v');
305 defaultPatternFormatter->set_pattern("[%Y-%m-%d %H:%M:%S.%e] [%^%l%$] %~%v");
306
307 loggerSilentGuiSink = std::make_shared<GuiSink>(args: spdlog::level::warn, args: true);
308
309#ifdef _WIN32
310 debugSink = std::make_shared<spdlog::sinks::msvc_sink_mt>();
311 debugSink->set_formatter(defaultPatternFormatter->clone());
312
313 loggerSilent = std::make_shared<spdlog::logger>("", std::initializer_list<spdlog::sink_ptr>{loggerSilentGuiSink, debugSink});
314#else
315 loggerSilent = std::make_shared<spdlog::logger>(args: "", args&: loggerSilentGuiSink);
316#endif
317
318 loggerSilent->set_level(spdlog::level::trace);
319 loggerSilent->flush_on(log_level: spdlog::level::trace);
320
321 spdlog::set_default_logger(loggerSilent);
322 spdlog::flush_on(log_level: spdlog::level::debug);
323
324 logger = loggerSilent;
325
326#ifdef _WIN32
327 loggerDebug = std::make_shared<spdlog::logger>("DebugLog", debugSink);
328#else
329 loggerDebug = std::make_shared<spdlog::logger>(args: "DebugLog");
330#endif
331 loggerDebug->set_level(spdlog::level::trace);
332 loggerDebug->flush_on(log_level: spdlog::level::trace);
333
334 ringbufferSink = std::make_shared<RingbufferSink>(args: defaultPatternFormatter->clone(), args: 100);
335 logger->sinks().emplace_back(args&: ringbufferSink);
336}
337
338void C4LogSystem::OpenLog(const bool verbose)
339{
340#ifdef _WIN32
341 SetConsoleOutputCP(CP_UTF8);
342#endif
343
344 this->verbose = verbose;
345
346 if (verbose)
347 {
348 loggerSilentGuiSink->set_level(spdlog::level::trace);
349 }
350
351 {
352 auto stdoutSink = std::make_shared<spdlog::sinks::stdout_color_sink_mt>();
353 stdoutSink->set_formatter(defaultPatternFormatter->clone());
354 stdoutSink->set_level(AdjustLevelIfVerbose(level: Config.Logging.LogLevelStdout));
355
356 auto clonkLogSink = std::make_shared<LogSink>(args: defaultPatternFormatter->clone());
357 clonkLogFD = clonkLogSink->GetFD();
358
359 clonkToUtf8Sink = std::make_shared<ClonkToUtf8Sink>(
360 args: std::initializer_list<spdlog::sink_ptr>{
361 std::static_pointer_cast<spdlog::sinks::sink>(r: std::move(stdoutSink)),
362 std::static_pointer_cast<spdlog::sinks::sink>(r: std::move(clonkLogSink))
363 });
364 }
365
366 loggerSilent->sinks().emplace_back(args&: clonkToUtf8Sink);
367
368 logger = std::make_shared<spdlog::logger>(args: "", args: loggerSilent->sinks().begin() + 1, args: loggerSilent->sinks().end());
369 logger->set_level(spdlog::level::trace);
370 logger->flush_on(log_level: spdlog::level::trace);
371
372 auto guiSink = std::make_shared<GuiSink>(args: std::make_unique<spdlog::pattern_formatter>(args: "%v"));
373
374 logger->sinks().insert(position: logger->sinks().begin(), x: std::move(guiSink));
375
376 loggerDebug->sinks().emplace_back(args&: clonkToUtf8Sink);
377 loggerDebug->sinks().emplace_back(args&: ringbufferSink);
378
379 loggerDebugGuiSink = std::make_shared<GuiSink>(args: spdlog::level::off, args: false);
380 loggerDebug->sinks().insert(position: loggerDebug->sinks().begin(), x: loggerDebugGuiSink);
381}
382
383void C4LogSystem::EnableDebugLog(const bool enable)
384{
385 if (loggerDebugGuiSink)
386 {
387 loggerDebugGuiSink->set_level(enable ? spdlog::level::debug : spdlog::level::off);
388 }
389}
390
391void C4LogSystem::AddFatalError(std::string message)
392{
393 logger->critical(fmt: "{}", args: LoadResStr(id: C4ResStrTableKey::IDS_ERR_FATAL, args&: message));
394
395 if (!std::ranges::contains(fatalErrors, message))
396 {
397 fatalErrors.emplace_back(args: std::move(message));
398 }
399}
400
401std::string C4LogSystem::GetFatalErrorString()
402{
403 std::string result;
404 for (const auto &error : fatalErrors)
405 {
406 if (!result.empty())
407 {
408 result += '|';
409 }
410
411 result += error;
412 }
413 return result;
414}
415
416void C4LogSystem::ResetFatalErrors()
417{
418 fatalErrors.clear();
419}
420
421std::vector<std::string> C4LogSystem::GetRingbufferLogEntries()
422{
423 return ringbufferSink->TakeMessages();
424}
425
426void C4LogSystem::ClearRingbuffer()
427{
428 ringbufferSink->Clear();
429}
430
431#ifdef _WIN32
432
433void C4LogSystem::SetConsoleInputCharset(const std::int32_t charset)
434{
435 SetConsoleCP(charset);
436}
437
438#endif
439
440spdlog::level::level_enum C4LogSystem::AdjustLevelIfVerbose(const spdlog::level::level_enum level) const noexcept
441{
442 return verbose ? spdlog::level::trace : level;
443}
444
445std::shared_ptr<spdlog::logger> C4LogSystem::CreateLogger(std::string name, const C4LoggerConfig::ConfigBase config)
446{
447 auto newLogger = std::make_shared<spdlog::logger>(args: std::move(name));
448 newLogger->set_level(AdjustLevelIfVerbose(level: config.LogLevel));
449 newLogger->flush_on(log_level: spdlog::level::trace);
450
451 spdlog::level::level_enum guiLogLevel;
452 if (verbose)
453 {
454 guiLogLevel = spdlog::level::trace;
455 }
456 else if (config.GuiLogLevel == spdlog::level::n_levels)
457 {
458 guiLogLevel = loggerSilentGuiSink->level();
459 }
460 else
461 {
462 guiLogLevel = config.GuiLogLevel;
463 }
464
465 newLogger->sinks().emplace_back(args: std::make_shared<GuiSink>(args&: guiLogLevel, args: config.ShowLoggerNameInGui));
466
467#ifdef _WIN32
468 newLogger->sinks().emplace_back(debugSink);
469#endif
470
471 newLogger->sinks().emplace_back(args&: clonkToUtf8Sink);
472
473 return newLogger;
474}
475
476std::shared_ptr<spdlog::logger> C4LogSystem::GetOrCreate(std::string name, C4LoggerConfig::ConfigBase config)
477{
478 const std::lock_guard lock{getOrCreateMutex};
479 if (const auto logger = spdlog::get(name); logger)
480 {
481 return logger;
482 }
483
484 auto logger = CreateLogger(name: std::move(name), config: std::move(config));
485 spdlog::register_logger(logger);
486 return logger;
487}
488
489void LogNTr(const spdlog::level::level_enum level, const std::string_view message)
490{
491 Application.LogSystem.GetLogger()->log(lvl: level, msg: message);
492}
493
494void LogFatalNTr(std::string message)
495{
496 Application.LogSystem.AddFatalError(message: std::move(message));
497}
498
499bool DebugLog(const spdlog::level::level_enum level, const std::string_view message)
500{
501 Application.LogSystem.GetLoggerDebug()->log(lvl: level, msg: message);
502 return true;
503}
504
505int GetLogFD()
506{
507 return Application.LogSystem.GetLogFD();
508}
509