RTech: implement pak and async read logging per channel

The engine assigns channel ID's to paks, which it then uses to determine whether to error out or warn when a certain pak file failed to load.

Paks loaded with a higher channel ID, such as the load screens or gladiator cards, won't call Error() in the engine if the loading thereof failed, where paks with a lower channel ID, such as common.rpak will.

Paks with a higher channel ID are quite verbose in the console, as the game often switches between gladiator card rpaks from scripts to update the banners in the world dynamically. User can now explicitly set the channel ID, with the default being 4 which only logs core engine and sdk paks, along with preloaded and level paks.

The async file read system uses a similar concept, this was confirmed when reversing Pak_SetupBuffersAndLoad as this calls FS_OpenAsyncFile for its patch files with the log channel that was assigned during Pak_LoadAsync. This code already had logging, but has been adjusted to follow the design of the system. Async file reads however are disabled by default as these are very verbose and will degrade performance of the game.
This commit is contained in:
Kawe Mazidjatari 2024-11-16 15:28:53 +01:00
parent 0dde788aa7
commit 03d19344fe
5 changed files with 42 additions and 28 deletions

View File

@ -301,9 +301,10 @@ public:
JobID_t loadJobId;
uint32_t padding_maybe;
// the log level of the pak, this is also used for errors if a pak failed
// to load; the higher the level, the more important this pak file is
int logLevel;
// the log channel of the pak, see [r5apex.exe+43E873]; this is used
// for errors if a pak failed to load. the value is assigned when the
// pak is loaded through Pak_LoadAsync or Pak_LoadAsyncAndWaitOrHelp.
int logChannel;
uint32_t assetCount;
const char* fileName;

View File

@ -7,19 +7,19 @@
#include "rtech/pak/paktools.h"
#include "asyncio.h"
ConVar async_debug_level("async_debug_level", "0", FCVAR_DEVELOPMENTONLY | FCVAR_ACCESSIBLE_FROM_THREADS, "The debug level for async reads", false, 0.f, false, 0.f, "0 = disabled");
ConVar async_debug_close("async_debug_close", "0", FCVAR_DEVELOPMENTONLY | FCVAR_ACCESSIBLE_FROM_THREADS, "Debug async file closing", false, 0.f, false, 0.f, "0 = disabled");
static ConVar async_debugchannel("async_debugchannel", "0", FCVAR_DEVELOPMENTONLY | FCVAR_ACCESSIBLE_FROM_THREADS, "Log async read handles created or destroyed with this channel ID", false, 0.f, false, 0.f, "0 = disabled, -1 = all");
static int s_fileHandleLogChannelIDs[ASYNC_MAX_FILE_HANDLES];
//----------------------------------------------------------------------------------
// open a file and add it to the async file handle array
//----------------------------------------------------------------------------------
int FS_OpenAsyncFile(const char* const filePath, const int logLevel, size_t* const fileSizeOut)
int FS_OpenAsyncFile(const char* const filePath, const int logChannel, size_t* const fileSizeOut)
{
const CHAR* fileToLoad = filePath;
char overridePath[1024];
// function can be called with null strings, for example if optional
// streaming sets are missing; check for it
// streaming sets are missing; check for it
if (fileToLoad && *fileToLoad)
{
// is this a pak file and do we have an override
@ -54,7 +54,10 @@ int FS_OpenAsyncFile(const char* const filePath, const int logLevel, size_t* con
tracker.handle = hFile;
tracker.state = 1;
if (async_debug_level.GetInt() >= logLevel)
s_fileHandleLogChannelIDs[slotNum] = logChannel;
const int selectedLogChannel = async_debugchannel.GetInt();
if (selectedLogChannel && (selectedLogChannel == -1 || logChannel == selectedLogChannel))
Msg(eDLL_T::RTECH, "%s: Opened file: '%s' to slot #%d\n", __FUNCTION__, fileToLoad, slotNum);
return fileIdx;
@ -74,9 +77,13 @@ void FS_CloseAsyncFile(const int fileHandle)
tracker.handle = INVALID_HANDLE_VALUE;
g_pAsyncFileSlotMgr->FreeSlot(slotNum);
const int selectedLogChannel = async_debugchannel.GetInt();
if (async_debug_close.GetBool())
if (selectedLogChannel && (selectedLogChannel == -1 || s_fileHandleLogChannelIDs[slotNum] == selectedLogChannel))
Msg(eDLL_T::RTECH, "%s: Closed file from slot #%d\n", __FUNCTION__, slotNum);
assert(s_fileHandleLogChannelIDs[slotNum] != 0);
s_fileHandleLogChannelIDs[slotNum] = 0;
}
}

View File

@ -47,17 +47,15 @@ struct AsyncHandleStatus_t
};
static_assert(sizeof(AsyncHandleStatus_t) == 0x40);
extern int FS_OpenAsyncFile(const char* const filePath, const int logLevel, size_t* const fileSizeOut);
extern int FS_OpenAsyncFile(const char* const filePath, const int logChannel, size_t* const fileSizeOut);
extern void FS_CloseAsyncFile(const int fileHandle);
inline int(*v_FS_OpenAsyncFile)(const char* const filePath, const int logLevel, size_t* const outFileSize);
inline int(*v_FS_OpenAsyncFile)(const char* const filePath, const int logChannel, size_t* const outFileSize);
inline void(*v_FS_CloseAsyncFile)(const int fileHandle);
inline int(*v_FS_ReadAsyncFile)(const int fileHandle, __int64 readOffset, unsigned __int64 readSize, void* a4, void* a5, void* a6, int a7);
inline uint8_t(*v_FS_CheckAsyncRequest)(AsyncHandleStatus_t* pakStatus, size_t* bytesProcessed, const char** stateString);
extern ConVar async_debug_level;
inline AsyncHandleTracker_t* g_pAsyncFileSlots; // bufSize=1024*sizeof(FileHandleTracker_t).
inline RHashMap_MT* g_pAsyncFileSlotMgr; // Manages 'g_pakFileSlots'.
inline AsyncHandleStatus_t* g_pAsyncStatusSlots; // bufSize=256*sizeof(PakStatus_t).

View File

@ -15,9 +15,10 @@
#include "pakstream.h"
static ConVar pak_debugrelations("pak_debugrelations", "0", FCVAR_DEVELOPMENTONLY | FCVAR_ACCESSIBLE_FROM_THREADS, "Debug RPAK asset dependency resolving");
static ConVar pak_debugchannel("pak_debugchannel", "4", FCVAR_DEVELOPMENTONLY | FCVAR_ACCESSIBLE_FROM_THREADS, "Log RPAK files loaded or unloaded with this channel ID", false, 0.f, false, 0.f, "0 = disabled, -1 = all");
//-----------------------------------------------------------------------------
// resolve the target guid from lookuo table
// resolve the target guid from lookup table
//-----------------------------------------------------------------------------
static bool Pak_ResolveAssetDependency(const PakFile_s* const pak, PakGuid_t currentGuid,
const PakGuid_t targetGuid, int& currentIndex, const bool shouldCheckTwo)
@ -190,23 +191,25 @@ void Pak_RunAssetLoadingJobs(PakFile_s* const pak)
//-----------------------------------------------------------------------------
// load user-requested pak files on-demand
//-----------------------------------------------------------------------------
PakHandle_t Pak_LoadAsync(const char* const fileName, CAlignedMemAlloc* const allocator, const int nIdx, const bool bUnk)
PakHandle_t Pak_LoadAsync(const char* const fileName, CAlignedMemAlloc* const allocator, const int logChannel, const bool bUnk)
{
PakHandle_t pakId = PAK_INVALID_HANDLE;
if (Pak_FileExists(fileName))
{
Msg(eDLL_T::RTECH, "Loading pak file: '%s'\n", fileName);
pakId = v_Pak_LoadAsync(fileName, allocator, nIdx, bUnk);
if (pakId == PAK_INVALID_HANDLE)
Error(eDLL_T::RTECH, NO_ERROR, "%s: Failed read '%s' results '%d'\n", __FUNCTION__, fileName, pakId);
}
else
if (!Pak_FileExists(fileName))
{
Error(eDLL_T::RTECH, NO_ERROR, "%s: Failed; file '%s' doesn't exist\n", __FUNCTION__, fileName);
return PAK_INVALID_HANDLE;
}
// NOTE: errors are always logged, regardless of the selected channel ID!
const int selectedLogChannel = pak_debugchannel.GetInt();
if (selectedLogChannel && (selectedLogChannel == -1 || logChannel == selectedLogChannel))
Msg(eDLL_T::RTECH, "Loading pak file: '%s'\n", fileName);
const PakHandle_t pakId = v_Pak_LoadAsync(fileName, allocator, logChannel, bUnk);
if (pakId == PAK_INVALID_HANDLE)
Error(eDLL_T::RTECH, NO_ERROR, "%s: Failed read '%s' results '%d'\n", __FUNCTION__, fileName, pakId);
return pakId;
}
@ -218,7 +221,12 @@ void Pak_UnloadAsync(PakHandle_t handle)
const PakLoadedInfo_s* const pakInfo = Pak_GetPakInfo(handle);
if (pakInfo->fileName)
Msg(eDLL_T::RTECH, "Unloading pak file: '%s'\n", pakInfo->fileName);
{
const int selectedLogChannel = pak_debugchannel.GetInt();
if (selectedLogChannel && (selectedLogChannel == -1 || pakInfo->logChannel == selectedLogChannel))
Msg(eDLL_T::RTECH, "Unloading pak file: '%s'\n", pakInfo->fileName);
}
v_Pak_UnloadAsync(handle);
}

View File

@ -67,7 +67,7 @@ void Pak_OpenAssociatedStreamingFiles(PakLoadedInfo_s* const loadedInfo, PakLoad
// must advance over null character as well for the next read
lenRead += strnlen(streamingFilePath, fileNamesBufSize - lenRead) + 1;
const int fileNumber = FS_OpenAsyncFile(streamingFilePath, loadedInfo->logLevel, nullptr);
const int fileNumber = FS_OpenAsyncFile(streamingFilePath, loadedInfo->logChannel, nullptr);
// make sure we successfully loaded mandatory streaming files, as we
// would otherwise error in the game itself