path: root/src/zenutil/logging.cpp

// Copyright Epic Games, Inc. All Rights Reserved.

#include "zenutil/logging.h"

ZEN_THIRD_PARTY_INCLUDES_START
#include <spdlog/async.h>
#include <spdlog/async_logger.h>
#include <spdlog/sinks/ansicolor_sink.h>
#include <spdlog/sinks/msvc_sink.h>
#include <spdlog/spdlog.h>
ZEN_THIRD_PARTY_INCLUDES_END

#include <zencore/callstack.h>
#include <zencore/compactbinary.h>
#include <zencore/filesystem.h>
#include <zencore/logging.h>
#include <zencore/memory/llm.h>
#include <zencore/string.h>
#include <zencore/timer.h>
#include <zenutil/logging/fullformatter.h>
#include <zenutil/logging/jsonformatter.h>
#include <zenutil/logging/rotatingfilesink.h>

#include <chrono>
#include <memory>

namespace zen {

static bool		 g_IsLoggingInitialized;
spdlog::sink_ptr g_FileSink;

spdlog::sink_ptr
GetFileSink()
{
	return g_FileSink;
}

void
InitializeLogging(const LoggingOptions& LogOptions)
{
	BeginInitializeLogging(LogOptions);
	FinishInitializeLogging(LogOptions);
}

static std::terminate_handler OldTerminateHandler = nullptr;

void
BeginInitializeLogging(const LoggingOptions& LogOptions)
{
	ZEN_MEMSCOPE(ELLMTag::Logging);

	zen::logging::InitializeLogging();
	zen::logging::EnableVTMode();

	bool IsAsync = LogOptions.AllowAsync;

	if (LogOptions.IsDebug)
	{
		IsAsync = false;
	}

	if (LogOptions.IsTest)
	{
		IsAsync = false;
	}

	if (IsAsync)
	{
		const int QueueSize	  = 8192;
		const int ThreadCount = 1;
		spdlog::init_thread_pool(QueueSize, ThreadCount, [&] { SetCurrentThreadName("spdlog_async"); });

		auto AsyncSink = spdlog::create_async<spdlog::sinks::ansicolor_stdout_sink_mt>("main");
		zen::logging::SetDefault("main");
	}

	// Sinks

	spdlog::sink_ptr FileSink;

	// spdlog can't create directories that starts with `\\?\` so we make sure the folder exists before creating the logger instance

	if (!LogOptions.AbsLogFile.empty())
	{
		if (LogOptions.AbsLogFile.has_parent_path())
		{
			zen::CreateDirectories(LogOptions.AbsLogFile.parent_path());
		}

		FileSink = std::make_shared<zen::logging::RotatingFileSink>(LogOptions.AbsLogFile,
																	/* max size */ 128 * 1024 * 1024,
																	/* max files */ 16,
																	/* rotate on open */ true);
		if (LogOptions.AbsLogFile.extension() == ".json")
		{
			FileSink->set_formatter(std::make_unique<logging::json_formatter>(LogOptions.LogId));
		}
		else
		{
			FileSink->set_formatter(std::make_unique<logging::full_formatter>(LogOptions.LogId));  // this will have a date prefix
		}
	}

	OldTerminateHandler = std::set_terminate([]() {
		try
		{
			constexpr int	 SkipFrameCount = 4;
			constexpr int	 FrameCount		= 8;
			uint8_t			 CallstackBuffer[CallstackRawMemorySize(SkipFrameCount, FrameCount)];
			CallstackFrames* Callstack = GetCallstackRaw(&CallstackBuffer[0], SkipFrameCount, FrameCount);

			fmt::basic_memory_buffer<char, 2048> Message;
			auto								 Appender = fmt::appender(Message);
			fmt::format_to(Appender, "Program exited abnormally via std::terminate()");

			if (Callstack->FrameCount > 0)
			{
				fmt::format_to(Appender, "\n");

				CallstackToStringRaw(Callstack, &Message, [](void* UserData, uint32_t FrameIndex, const char* FrameText) {
					ZEN_UNUSED(FrameIndex);
					fmt::basic_memory_buffer<char, 2048>* Message  = (fmt::basic_memory_buffer<char, 2048>*)UserData;
					auto								  Appender = fmt::appender(*Message);
					fmt::format_to(Appender, "  {}\n", FrameText);
				});
			}
			Message.push_back('\0');

			// We use direct ZEN_LOG here instead of ZEN_ERROR as we don't care about *this* code location in the log
			ZEN_LOG(Log(), zen::logging::level::Critical, "{}", Message.data());
			zen::logging::FlushLogging();
		}
		catch (const std::exception&)
		{
			// Ignore any exceptions in terminate callback
		}
		if (OldTerminateHandler)
		{
			OldTerminateHandler();
		}
	});

	// Default

	LoggerRef DefaultLogger = zen::logging::Default();
	auto&	  Sinks			= DefaultLogger.SpdLogger->sinks();

	Sinks.clear();

	if (LogOptions.NoConsoleOutput)
	{
		zen::logging::SuppressConsoleLog();
	}
	else
	{
		auto ConsoleSink = std::make_shared<spdlog::sinks::ansicolor_stdout_sink_mt>();
		if (LogOptions.QuietConsole)
		{
			ConsoleSink->set_level(spdlog::level::warn);
		}
		Sinks.push_back(ConsoleSink);
	}

	if (FileSink)
	{
		Sinks.push_back(FileSink);
	}

#if ZEN_PLATFORM_WINDOWS
	if (zen::IsDebuggerPresent() && LogOptions.IsDebug)
	{
		auto DebugSink = std::make_shared<spdlog::sinks::msvc_sink_mt>();
		DebugSink->set_level(spdlog::level::debug);
		Sinks.push_back(DebugSink);
	}
#endif

	spdlog::set_error_handler([](const std::string& msg) {
		if (msg == std::bad_alloc().what())
		{
			// Don't report out of memory in spdlog as we usually log in response to errors which will cause another OOM crashing the
			// program
			return;
		}
		// Bypass zen logging wrapping to reduce potential other error sources
		if (auto ErrLogger = zen::logging::ErrorLog())
		{
			try
			{
				ErrLogger.SpdLogger->log(spdlog::level::err, msg);
			}
			catch (const std::exception&)
			{
				// Just ignore any errors when in error handler
			}
		}
		try
		{
			Log().SpdLogger->error(msg);
		}
		catch (const std::exception&)
		{
			// Just ignore any errors when in error handler
		}
	});

	g_FileSink = std::move(FileSink);
}

void
FinishInitializeLogging(const LoggingOptions& LogOptions)
{
	ZEN_MEMSCOPE(ELLMTag::Logging);

	logging::level::LogLevel LogLevel = logging::level::Info;

	if (LogOptions.IsDebug)
	{
		LogLevel = logging::level::Debug;
	}

	if (LogOptions.IsTest || LogOptions.IsVerbose)
	{
		LogLevel = logging::level::Trace;
	}

	// Configure all registered loggers according to settings

	logging::RefreshLogLevels(LogLevel);
	spdlog::flush_on(spdlog::level::err);
	spdlog::flush_every(std::chrono::seconds{2});
	spdlog::set_formatter(std::make_unique<logging::full_formatter>(
		LogOptions.LogId,
		std::chrono::system_clock::now() - std::chrono::milliseconds(GetTimeSinceProcessStart())));	 // default to duration prefix

	// If the console logger was initialized before, the above will change the output format
	// so we need to reset it

	logging::ResetConsoleLog();

	if (g_FileSink)
	{
		if (LogOptions.AbsLogFile.extension() == ".json")
		{
			g_FileSink->set_formatter(std::make_unique<logging::json_formatter>(LogOptions.LogId));
		}
		else
		{
			g_FileSink->set_formatter(std::make_unique<logging::full_formatter>(LogOptions.LogId));	 // this will have a date prefix
		}

		const std::string StartLogTime = zen::DateTime::Now().ToIso8601();

		spdlog::apply_all([&](auto Logger) { Logger->info("log starting at {}", StartLogTime); });
	}

	g_IsLoggingInitialized = true;
}

void
ShutdownLogging()
{
	if (g_IsLoggingInitialized && g_FileSink)
	{
		auto DefaultLogger = zen::logging::Default();
		ZEN_LOG_INFO(DefaultLogger, "log ending at {}", zen::DateTime::Now().ToIso8601());
	}

	zen::logging::ShutdownLogging();

	g_FileSink.reset();
}

}  // namespace zen