Move logging to spdlog

This commit is contained in:
FakeMichau
2024-09-12 23:27:34 +02:00
parent 74281f20c0
commit aab720b7b1
6 changed files with 49 additions and 71 deletions
+15 -16
View File
@@ -5,20 +5,20 @@ namespace nvd {
NvAPI_Status __cdecl NvAPI_Initialize() {
IDXGIFactory1* pFactory = nullptr;
if (FAILED(CreateDXGIFactory1(__uuidof(IDXGIFactory1), (void**)&pFactory))) {
log("Failed to create DXGI Factory");
spdlog::error("Failed to create DXGI Factory");
return Error();
}
IDXGIAdapter1* pAdapter = nullptr;
if (FAILED(pFactory->EnumAdapters1(0, &pAdapter))) {
log("Failed to enumerate adapters");
spdlog::error("Failed to enumerate adapters");
pFactory->Release();
return Error();
}
DXGI_ADAPTER_DESC1 adapterDesc;
if (FAILED(pAdapter->GetDesc1(&adapterDesc))) {
log("Failed to get adapter description");
spdlog::error("Failed to get adapter description");
pAdapter->Release();
pFactory->Release();
return Error();
@@ -87,7 +87,7 @@ namespace nvd {
NvAPI_Status __cdecl NvAPI_GetErrorMessage(NvAPI_Status status, NvAPI_ShortString szMsg) {
std::string error = fromErrorNr(status);
log(std::format("NvAPI_GetErrorMessage gave this error: {}", error));
spdlog::error("NvAPI_GetErrorMessage gave this error: {}", error);
tonvss(szMsg, error);
return Ok();
}
@@ -323,17 +323,17 @@ namespace nvd {
NvAPI_Status __cdecl NvAPI_D3D_SetLatencyMarker(IUnknown* pDev, NV_LATENCY_MARKER_PARAMS* pSetLatencyMarkerParams) {
if (!pDev)
return Error();
log(std::format("markerType: {}, frame id: {}", (unsigned int)pSetLatencyMarkerParams->markerType, (unsigned long long)pSetLatencyMarkerParams->frameID));
spdlog::debug("markerType: {}, frame id: {}", (unsigned int)pSetLatencyMarkerParams->markerType, (unsigned long long)pSetLatencyMarkerParams->frameID);
lowlatency_ctx.init_al2(pDev);
switch (pSetLatencyMarkerParams->markerType) {
case SIMULATION_START:
if (lowlatency_ctx.call_spot != SimulationStart) break;
log(std::format("LowLatency update called on simulation start with result: {}", lowlatency_ctx.update()));
spdlog::debug("LowLatency update called on simulation start with result: {}", lowlatency_ctx.update());
break;
case INPUT_SAMPLE:
if (lowlatency_ctx.call_spot == SleepCall) break;
lowlatency_ctx.call_spot = InputSample;
log(std::format("LowLatency update called on input sample with result: {}", lowlatency_ctx.update()));
spdlog::debug("LowLatency update called on input sample with result: {}", lowlatency_ctx.update());
break;
case PRESENT_START:
if (lowlatency_ctx.fg) lowlatency_ctx.mark_end_of_rendering();
@@ -347,7 +347,7 @@ namespace nvd {
return Error();
lowlatency_ctx.init_al2(pDevice);
lowlatency_ctx.call_spot = SleepCall;
log(std::format("LowLatency update called on sleep with result: {}", lowlatency_ctx.update()));
spdlog::debug("LowLatency update called on sleep with result: {}", lowlatency_ctx.update());
return Ok();
}
@@ -468,13 +468,13 @@ namespace nvd {
d3dGeoDesc.AABBs = nvGeoDesc.aabbs;
break;
case NVAPI_D3D12_RAYTRACING_GEOMETRY_TYPE_OMM_TRIANGLES_EX: // GetRaytracingCaps reports no OMM caps, we shouldn't reach this
log("Triangles with OMM attachment passed to acceleration structure build when OMM is not supported");
spdlog::error("Triangles with OMM attachment passed to acceleration structure build when OMM is not supported");
return false;
case NVAPI_D3D12_RAYTRACING_GEOMETRY_TYPE_DMM_TRIANGLES_EX: // GetRaytracingCaps reports no DMM caps, we shouldn't reach this
log("Triangles with DMM attachment passed to acceleration structure build when DMM is not supported");
spdlog::error("Triangles with DMM attachment passed to acceleration structure build when DMM is not supported");
return false;
default:
log("Unknown NVAPI_D3D12_RAYTRACING_GEOMETRY_TYPE_EX");
spdlog::error("Unknown NVAPI_D3D12_RAYTRACING_GEOMETRY_TYPE_EX");
return false;
}
}
@@ -546,7 +546,7 @@ namespace nvd {
if (lowlatency_ctx.fg) lowlatency_ctx.set_fg_type(previous_frame_id == current_frame_id);
previous_frame_id = current_frame_id;
}
log(std::format("Async markerType: {}, frame id: {}", (unsigned int)pSetAsyncFrameMarkerParams->markerType, (unsigned long long)pSetAsyncFrameMarkerParams->frameID));
spdlog::debug("Async markerType: {}, frame id: {}", (unsigned int)pSetAsyncFrameMarkerParams->markerType, (unsigned long long)pSetAsyncFrameMarkerParams->frameID);
return Ok();
}
@@ -569,14 +569,13 @@ namespace nvd {
}
NvAPI_Status __cdecl NvAPI_DRS_GetSetting(NvDRSSessionHandle hSession, NvDRSProfileHandle hProfile, NvU32 settingId, NVDRS_SETTING* pSetting) {
log(std::format("Missing setting: {}", settingId));
spdlog::debug("Missing get setting: {}", settingId);
return Ok();
}
NvAPI_Status __cdecl NvAPI_DRS_SetSetting(NvDRSSessionHandle hSession, NvDRSProfileHandle hProfile, NVDRS_SETTING *pSetting) {
log("NvAPI_DRS_SetSetting");
log(std::format("\tsettingId: {}", pSetting->settingId));
return NVAPI_OK;
spdlog::debug("Missing set setting: {}", pSetting->settingId);
return Ok();
}
NvAPI_Status __cdecl NvAPI_DRS_DestroySession(NvDRSSessionHandle session) {
+17 -41
View File
@@ -1,24 +1,5 @@
#include "log.h"
std::ostream null(nullptr);
std::ostream* logStream = &null;
std::ofstream fileStream;
inline std::string getCurrentTimeFormatted() {
auto now = std::chrono::system_clock::now();
auto now_t = std::chrono::system_clock::to_time_t(now);
auto now_tm = *std::localtime(&now_t);
auto now_duration = now - std::chrono::system_clock::from_time_t(std::mktime(&now_tm));
auto now_us = std::chrono::duration_cast<std::chrono::microseconds>(now_duration);
std::ostringstream oss;
oss << std::setfill('0') << std::setw(2) << now_tm.tm_hour << ":"
<< std::setfill('0') << std::setw(2) << now_tm.tm_min << ":"
<< std::setfill('0') << std::setw(2) << now_tm.tm_sec << "."
<< std::setfill('0') << std::setw(6) << now_us.count();
return oss.str();
}
inline std::string extractFunctionName(const std::string& signature) {
size_t start = signature.find("nvd::");
if (start == std::string::npos) return {};
@@ -29,39 +10,34 @@ inline std::string extractFunctionName(const std::string& signature) {
return signature.substr(start, end - start);
}
void log(const std::string& log) {
if (logStream == &null) return;
std::ostringstream oss;
oss << "[" << getCurrentTimeFormatted() << "] " << log << std::endl;
*logStream << oss.str();
}
NvAPI_Status Ok(const std::source_location& location) {
if (logStream != &null)
log(std::format("{}: {}", extractFunctionName(location.function_name()), "OK"));
spdlog::trace("{}: {}", extractFunctionName(location.function_name()), "OK");
return NVAPI_OK;
}
NvAPI_Status Error(NvAPI_Status status, const std::source_location& location) {
if (logStream != &null)
log(std::format("{}: {}", extractFunctionName(location.function_name()), fromErrorNr(status)));
spdlog::trace("{}: {}", extractFunctionName(location.function_name()), fromErrorNr(status));
return status;
}
void prepareLogging(std::optional<std::string> fileName) {
if (fileName.has_value()) {
fileStream.open(fileName.value(), std::ios_base::out | std::ios_base::app);
if (fileStream.is_open()) {
logStream = &fileStream;
return;
}
else {
std::cerr << "Failed to open log file: " << fileName.value() << std::endl;
void prepareLogging(spdlog::level::level_enum level) {
try {
if (level != spdlog::level::off) {
auto logger = spdlog::basic_logger_mt("basic_logger", "nvapi-dummy.log");
spdlog::set_default_logger(logger);
if (level == spdlog::level::trace)
spdlog::set_pattern("[%H:%M:%S.%f] [%L] [thread %t] %v");
else
spdlog::set_pattern("[%H:%M:%S.%f] [%L] %v");
spdlog::set_level(level);
spdlog::flush_on(level);
}
} catch (const spdlog::spdlog_ex &ex) {
std::cout << "Log init failed: " << ex.what() << std::endl;
}
// logStream = &std::cout;
}
void closeLogging() {
fileStream.close();
spdlog::default_logger()->flush();
spdlog::shutdown();
}
+3 -3
View File
@@ -8,10 +8,10 @@
#include <source_location>
#include "util.h"
#include "../external/nvapi.h"
#include "spdlog/spdlog.h"
#include "spdlog/sinks/basic_file_sink.h"
std::string getCurrentTimeFormatted();
void log(const std::string& log);
NvAPI_Status Ok(const std::source_location &location = std::source_location::current());
NvAPI_Status Error(NvAPI_Status status = NVAPI_ERROR, const std::source_location &location = std::source_location::current());
void prepareLogging(std::optional<std::string> fileName);
void prepareLogging(spdlog::level::level_enum level);
void closeLogging();
+8 -6
View File
@@ -96,8 +96,8 @@ public:
else
mode = LatencyFlex;
log(std::format("LowLatency algo: {}", mode == AntiLag2 ? "AntiLag 2" : "LatencyFlex"));
log(std::format("FG status: {}", fg ? "enabled" : "disabled"));
spdlog::debug("LowLatency algo: {}", mode == AntiLag2 ? "AntiLag 2" : "LatencyFlex");
spdlog::debug("FG status: {}", fg ? "enabled" : "disabled");
if (mode == AntiLag2) {
#if _MSC_VER && _WIN64
@@ -110,7 +110,7 @@ public:
#endif
} else if (mode == LatencyFlex) {
if (lfx_stats.needs_reset) {
log("LFX Reset");
spdlog::info("LFX Reset");
lfx_stats.frame_id = 1;
lfx_stats.needs_reset = false;
lf->Reset();
@@ -122,7 +122,7 @@ public:
lf->target_frame_time = 1000 * min_interval_us;
lf->EndFrame(lfx_stats.frame_id, current_timestamp, &lfx_stats.latency, &lfx_stats.frame_time);
log(std::format("LFX latency: {}, frame_time: {}, current_timestamp: {}", lfx_stats.latency, lfx_stats.frame_time, current_timestamp));
spdlog::debug("LFX latency: {}, frame_time: {}, current_timestamp: {}", lfx_stats.latency, lfx_stats.frame_time, current_timestamp);
lfx_stats.frame_id++;
lfx_stats.target = lf->GetWaitTarget(lfx_stats.frame_id);
@@ -174,8 +174,10 @@ public:
}
void set_min_interval_us(unsigned long interval_us) {
log(std::format("Max fps: {}", interval_us > 0 ? 1000000 / interval_us : 0));
min_interval_us = interval_us;
if (min_interval_us != interval_us) {
min_interval_us = interval_us;
spdlog::info("Changed max fps: {}", interval_us > 0 ? 1000000 / interval_us : 0);
}
}
Mode get_mode() {
+5 -5
View File
@@ -25,10 +25,10 @@ BOOL WINAPI DllMain(HINSTANCE hinstDLL, DWORD fdwReason, LPVOID lpvReserved) {
switch (fdwReason) {
case DLL_PROCESS_ATTACH:
if ((logEnv && *logEnv == '1') || force_log)
prepareLogging("nvapi-dummy.log");
prepareLogging(spdlog::level::trace);
else
prepareLogging(std::nullopt);
log("--------------");
prepareLogging(spdlog::level::off);
spdlog::critical("----------------");
break;
case DLL_PROCESS_DETACH:
closeLogging();
@@ -74,7 +74,7 @@ namespace nvd {
[id](const auto& item) { return item.id == id; });
if (it == std::end(extended_interface_table)) {
log(std::format("NvAPI_QueryInterface (0x{:x}): Unknown interface ID", id));
spdlog::debug("NvAPI_QueryInterface (0x{:x}): Unknown interface ID", id);
return registry.insert({ id, nullptr }).first->second;
}
@@ -138,7 +138,7 @@ namespace nvd {
INSERT_AND_RETURN_WHEN_EQUALS(NvAPI_Unload)
INSERT_AND_RETURN_WHEN_EQUALS(Dummy_GetLatency)
log(std::format("{}: not implemented, placeholder given", it->func));
spdlog::debug("{}: not implemented, placeholder given", it->func);
return registry.insert({ id, (void*)placeholder }).first->second;
// return registry.insert({ id, nullptr }).first->second;
}
+1
View File
@@ -3,5 +3,6 @@ dll = shared_library(
['main.cpp', 'fakenvapi.cpp', 'util.cpp', 'log.cpp'],
name_prefix : '',
dependencies : [ lib_dxgi ],
include_directories: [ spdlog_headers ],
install: true
)