UNLOZE/sourcemod
10
0
Fork 0
Code Issues Pull Requests Releases Wiki Activity

Simplify Logger internals (Fixes Issue #663). (#691)

Browse Source 
* Simplify Logger internals (Issue #663).

* Avoid reformatting strings on every call.
This commit is contained in:
Kyle Sanderson 2017-12-29 19:56:25 -08:00 committed by GitHub
parent 5f5a6b3a16
commit de108cca44
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
2 changed files with 208 additions and 306 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

474
core/logic/Logger.cpp
View File

@ -40,10 +40,6 @@
Logger g_Logger; Logger g_Logger;
/**
* :TODO: This should be creating the log folder if it doesn't exist
*/
ConfigResult Logger::OnSourceModConfigChanged(const char *key, ConfigResult Logger::OnSourceModConfigChanged(const char *key,
const char *value, const char *value,
ConfigSource source, ConfigSource source,
@ -68,7 +64,7 @@ ConfigResult Logger::OnSourceModConfigChanged(const char *key,
{ {
state ? EnableLogging() : DisableLogging(); state ? EnableLogging() : DisableLogging();
} else { } else {
m_InitialState = state; m_Active = state;
} }
return ConfigResult_Accept; return ConfigResult_Accept;
@ -93,7 +89,12 @@ ConfigResult Logger::OnSourceModConfigChanged(const char *key,
void Logger::OnSourceModStartup(bool late) void Logger::OnSourceModStartup(bool late)
{ {
InitLogger(m_Mode); char buff[PLATFORM_MAX_PATH];
g_pSM->BuildPath(Path_SM, buff, sizeof(buff), "logs");
if (!libsys->IsPathDirectory(buff))
{
libsys->CreateFolder(buff);
}
} }
void Logger::OnSourceModAllShutdown() void Logger::OnSourceModAllShutdown()
@ -103,127 +104,7 @@ void Logger::OnSourceModAllShutdown()
void Logger::OnSourceModLevelChange(const char *mapName) void Logger::OnSourceModLevelChange(const char *mapName)
{ {
MapChange(mapName); _MapChange(mapName);
}
void Logger::_NewMapFile()
{
if (!m_Active)
{
return;
}
/* Append "Log file closed" to previous log file */
_CloseFile();
char _filename[256];
int i = 0;
time_t t = g_pSM->GetAdjustedTime();
tm *curtime = localtime(&t);
while (true)
{
g_pSM->BuildPath(Path_SM, _filename, sizeof(_filename), "logs/L%02d%02d%03d.log", curtime->tm_mon + 1, curtime->tm_mday, i);
FILE *fp = fopen(_filename, "r");
if (!fp)
{
break;
}
fclose(fp);
i++;
}
m_NrmFileName.assign(_filename);
FILE *fp = fopen(m_NrmFileName.c_str(), "w");
if (!fp)
{
char error[255];
libsys->GetPlatformError(error, sizeof(error));
LogFatal("[SM] Unexpected fatal logging error (file \"%s\")", m_NrmFileName.c_str());
LogFatal("[SM] Platform returned error: \"%s\"", error);
LogFatal("[SM] Logging has been disabled.");
m_Active = false;
return;
} else {
char date[32];
strftime(date, sizeof(date), "%m/%d/%Y - %H:%M:%S", curtime);
fprintf(fp, "L %s: SourceMod log file started (file \"L%02d%02d%03d.log\") (Version \"%s\")\n", date, curtime->tm_mon + 1, curtime->tm_mday, i, SOURCEMOD_VERSION);
fclose(fp);
}
}
void Logger::_CloseFile()
{
if (!m_Active)
{
return;
}
FILE *fp = NULL;
if (!m_NrmFileName.empty())
{
fp = fopen(m_NrmFileName.c_str(), "r+");
if (fp)
{
fseek(fp, 0, SEEK_END);
LogMessage("Log file closed.");
fclose(fp);
}
m_NrmFileName.clear();
}
if (!m_ErrMapStart)
{
return;
}
fp = fopen(m_ErrFileName.c_str(), "r+");
if (fp)
{
fseek(fp, 0, SEEK_END);
LogError("Error log file session closed.");
fclose(fp);
}
m_ErrFileName.clear();
}
void Logger::InitLogger(LoggingMode mode)
{
m_Mode = mode;
m_Active = m_InitialState;
time_t t = g_pSM->GetAdjustedTime();
tm *curtime = localtime(&t);
m_NrmCurDay = curtime->tm_mday;
m_ErrCurDay = curtime->tm_mday;
char _filename[256];
g_pSM->BuildPath(Path_SM, _filename, sizeof(_filename), "logs/errors_%04d%02d%02d.log", curtime->tm_year + 1900, curtime->tm_mon + 1, curtime->tm_mday);
m_ErrFileName.assign(_filename);
switch (m_Mode)
{
case LoggingMode_PerMap:
{
if (!m_Active)
{
m_DelayedStart = true;
}
break;
}
case LoggingMode_Daily:
{
g_pSM->BuildPath(Path_SM, _filename, sizeof(_filename), "logs/L%04d%02d%02d.log", curtime->tm_year + 1900, curtime->tm_mon + 1, curtime->tm_mday);
m_NrmFileName.assign(_filename);
m_DailyPrintHdr = true;
break;
}
default:
{
/* do nothing... */
break;
}
}
} }
void Logger::CloseLogger() void Logger::CloseLogger()
@ -231,6 +112,13 @@ void Logger::CloseLogger()
_CloseFile(); _CloseFile();
} }
void Logger::_CloseFile()
{
_CloseNormal();
_CloseError();
_CloseFatal();
}
void Logger::LogToOpenFile(FILE *fp, const char *msg, ...) void Logger::LogToOpenFile(FILE *fp, const char *msg, ...)
{ {
if (!m_Active) if (!m_Active)
@ -259,11 +147,6 @@ void Logger::LogToFileOnly(FILE *fp, const char *msg, ...)
void Logger::LogToOpenFileEx(FILE *fp, const char *msg, va_list ap) void Logger::LogToOpenFileEx(FILE *fp, const char *msg, va_list ap)
{ {
if (!m_Active)
{
return;
}
static ConVar *sv_logecho = bridge->FindConVar("sv_logecho"); static ConVar *sv_logecho = bridge->FindConVar("sv_logecho");
char buffer[3072]; char buffer[3072];
@ -282,15 +165,12 @@ void Logger::LogToOpenFileEx(FILE *fp, const char *msg, va_list ap)
ke::SafeSprintf(conBuffer, sizeof(conBuffer), "L %s: %s\n", date, buffer); ke::SafeSprintf(conBuffer, sizeof(conBuffer), "L %s: %s\n", date, buffer);
bridge->ConPrint(conBuffer); bridge->ConPrint(conBuffer);
} }
fflush(fp);
} }
void Logger::LogToFileOnlyEx(FILE *fp, const char *msg, va_list ap) void Logger::LogToFileOnlyEx(FILE *fp, const char *msg, va_list ap)
{ {
if (!m_Active)
{
return;
}
char buffer[3072]; char buffer[3072];
ke::SafeVsprintf(buffer, sizeof(buffer), msg, ap); ke::SafeVsprintf(buffer, sizeof(buffer), msg, ap);
@ -298,8 +178,8 @@ void Logger::LogToFileOnlyEx(FILE *fp, const char *msg, va_list ap)
time_t t = g_pSM->GetAdjustedTime(); time_t t = g_pSM->GetAdjustedTime();
tm *curtime = localtime(&t); tm *curtime = localtime(&t);
strftime(date, sizeof(date), "%m/%d/%Y - %H:%M:%S", curtime); strftime(date, sizeof(date), "%m/%d/%Y - %H:%M:%S", curtime);
fprintf(fp, "L %s: %s\n", date, buffer); fprintf(fp, "L %s: %s\n", date, buffer);
fflush(fp); fflush(fp);
} }
@ -324,63 +204,14 @@ void Logger::LogMessageEx(const char *vafmt, va_list ap)
return; return;
} }
if (m_DelayedStart) FILE *pFile = _OpenNormal();
if (!pFile)
{ {
m_DelayedStart = false;
_NewMapFile();
}
time_t t = g_pSM->GetAdjustedTime();
tm *curtime = localtime(&t);
FILE *fp = NULL;
if (m_Mode == LoggingMode_PerMap)
{
fp = fopen(m_NrmFileName.c_str(), "a+");
if (!fp)
{
_NewMapFile();
fp = fopen(m_NrmFileName.c_str(), "a+");
if (!fp)
{
goto print_error;
}
}
} else {
if (m_NrmCurDay != curtime->tm_mday)
{
char _filename[256];
g_pSM->BuildPath(Path_SM, _filename, sizeof(_filename), "logs/L%04d%02d%02d.log", curtime->tm_year + 1900, curtime->tm_mon + 1, curtime->tm_mday);
m_NrmFileName.assign(_filename);
m_NrmCurDay = curtime->tm_mday;
m_DailyPrintHdr = true;
}
fp = fopen(m_NrmFileName.c_str(), "a+");
}
if (fp)
{
if (m_DailyPrintHdr)
{
char date[32];
m_DailyPrintHdr = false;
strftime(date, sizeof(date), "%m/%d/%Y - %H:%M:%S", curtime);
fprintf(fp, "L %s: SourceMod log file session started (file \"L%04d%02d%02d.log\") (Version \"%s\")\n", date, curtime->tm_year + 1900, curtime->tm_mon + 1, curtime->tm_mday, SOURCEMOD_VERSION);
}
LogToOpenFileEx(fp, vafmt, ap);
fclose(fp);
} else {
goto print_error;
}
return; return;
print_error: }
char error[255];
libsys->GetPlatformError(error, sizeof(error)); LogToOpenFileEx(pFile, vafmt, ap);
LogFatal("[SM] Unexpected fatal logging error (file \"%s\")", m_NrmFileName.c_str()); fclose(pFile);
LogFatal("[SM] Platform returned error: \"%s\"", error);
LogFatal("[SM] Logging has been disabled.");
m_Active = false;
} }
void Logger::LogError(const char *vafmt, ...) void Logger::LogError(const char *vafmt, ...)
@ -398,72 +229,20 @@ void Logger::LogErrorEx(const char *vafmt, va_list ap)
return; return;
} }
time_t t = g_pSM->GetAdjustedTime(); FILE *pFile = _OpenError();
tm *curtime = localtime(&t); if (!pFile)
if (curtime->tm_mday != m_ErrCurDay)
{ {
char _filename[256];
g_pSM->BuildPath(Path_SM, _filename, sizeof(_filename), "logs/errors_%04d%02d%02d.log", curtime->tm_year + 1900, curtime->tm_mon + 1, curtime->tm_mday);
m_ErrFileName.assign(_filename);
m_ErrCurDay = curtime->tm_mday;
m_ErrMapStart = false;
}
FILE *fp = fopen(m_ErrFileName.c_str(), "a+");
if (fp)
{
if (!m_ErrMapStart)
{
char date[32];
strftime(date, sizeof(date), "%m/%d/%Y - %H:%M:%S", curtime);
fprintf(fp, "L %s: SourceMod error session started\n", date);
fprintf(fp, "L %s: Info (map \"%s\") (file \"errors_%04d%02d%02d.log\")\n", date, m_CurMapName.c_str(), curtime->tm_year + 1900, curtime->tm_mon + 1, curtime->tm_mday);
m_ErrMapStart = true;
}
LogToOpenFileEx(fp, vafmt, ap);
fclose(fp);
}
else
{
char error[255];
libsys->GetPlatformError(error, sizeof(error));
LogFatal("[SM] Unexpected fatal logging error (file \"%s\")", m_NrmFileName.c_str());
LogFatal("[SM] Platform returned error: \"%s\"", error);
LogFatal("[SM] Logging has been disabled.");
m_Active = false;
return; return;
} }
LogToOpenFileEx(pFile, vafmt, ap);
fclose(pFile);
} }
void Logger::MapChange(const char *mapname) void Logger::_MapChange(const char *mapname)
{ {
m_CurMapName.assign(mapname); m_CurrentMapName = mapname;
_UpdateFiles(true);
switch (m_Mode)
{
case LoggingMode_Daily:
{
LogMessage("-------- Mapchange to %s --------", mapname);
break;
}
case LoggingMode_PerMap:
{
_NewMapFile();
break;
}
default:
{
/* Do nothing... */
break;
}
}
if (m_ErrMapStart)
{
LogError("Error log file session closed.");
}
m_ErrMapStart = false;
} }
void Logger::_PrintToGameLog(const char *fmt, va_list ap) void Logger::_PrintToGameLog(const char *fmt, va_list ap)
@ -480,30 +259,6 @@ void Logger::_PrintToGameLog(const char *fmt, va_list ap)
bridge->LogToGame(msg); bridge->LogToGame(msg);
} }
const char *Logger::GetLogFileName(LogType type) const
{
switch (type)
{
case LogType_Normal:
{
return m_NrmFileName.c_str();
}
case LogType_Error:
{
return m_ErrFileName.c_str();
}
default:
{
return "";
}
}
}
LoggingMode Logger::GetLoggingMode() const
{
return m_Mode;
}
void Logger::EnableLogging() void Logger::EnableLogging()
{ {
if (m_Active) if (m_Active)
@ -539,16 +294,161 @@ void Logger::LogFatalEx(const char *msg, va_list ap)
* It's already implemented twice which is bad. * It's already implemented twice which is bad.
*/ */
char path[PLATFORM_MAX_PATH]; FILE *pFile = _OpenFatal();
if (!pFile)
g_pSM->BuildPath(Path_Game, path, sizeof(path), "sourcemod_fatal.log");
FILE *fp = fopen(path, "at");
if (fp)
{ {
m_Active = true; return;
LogToOpenFileEx(fp, msg, ap); }
m_Active = false;
fclose(fp); LogToOpenFileEx(pFile, msg, ap);
fclose(pFile);
}
void Logger::_UpdateFiles(bool bLevelChange)
{
time_t t = g_pSM->GetAdjustedTime();
tm *curtime = localtime(&t);
if (!bLevelChange && curtime->tm_mday == m_Day)
{
return;
}
m_Day = curtime->tm_mday;
char buff[PLATFORM_MAX_PATH];
ke::SafeSprintf(buff, sizeof(buff), "%04d%02d%02d", curtime->tm_year + 1900, curtime->tm_mon + 1, curtime->tm_mday);
ke::AString currentDate(buff);
if (m_Mode == LoggingMode_PerMap)
{
if (bLevelChange)
{
for (size_t iter = 0; iter < static_cast<size_t>(-1); ++iter)
{
g_pSM->BuildPath(Path_SM, buff, sizeof(buff), "logs/L%s%u.log", currentDate.chars(), iter);
if (!libsys->IsPathFile(buff))
{
break;
} }
} }
}
else
{
ke::SafeStrcpy(buff, sizeof(buff), m_NormalFileName.chars());
}
}
else
{
g_pSM->BuildPath(Path_SM, buff, sizeof(buff), "logs/L%s.log", currentDate.chars());
}
if (m_NormalFileName.compare(buff))
{
_CloseNormal();
m_NormalFileName = buff;
}
else
{
if (bLevelChange)
{
LogMessage("-------- Mapchange to %s --------", m_CurrentMapName.chars());
}
}
g_pSM->BuildPath(Path_SM, buff, sizeof(buff), "logs/errors_%s.log", currentDate.chars());
if (bLevelChange || m_ErrorFileName.compare(buff))
{
_CloseError();
m_ErrorFileName = buff;
}
}
FILE *Logger::_OpenNormal()
{
_UpdateFiles();
FILE *pFile = fopen(m_NormalFileName.chars(), "a+");
if (pFile == NULL)
{
_LogFatalOpen(m_NormalFileName);
return pFile;
}
if (!m_DamagedNormalFile)
{
time_t t = g_pSM->GetAdjustedTime();
tm *curtime = localtime(&t);
char date[32];
strftime(date, sizeof(date), "%m/%d/%Y - %H:%M:%S", curtime);
fprintf(pFile, "L %s: SourceMod log file session started (file \"%s\") (Version \"%s\")\n", date, m_NormalFileName.chars(), SOURCEMOD_VERSION);
m_DamagedNormalFile = true;
}
return pFile;
}
FILE *Logger::_OpenError()
{
_UpdateFiles();
FILE *pFile = fopen(m_ErrorFileName.chars(), "a+");
if (pFile == NULL)
{
_LogFatalOpen(m_ErrorFileName);
return pFile;
}
if (!m_DamagedErrorFile)
{
time_t t = g_pSM->GetAdjustedTime();
tm *curtime = localtime(&t);
char date[32];
strftime(date, sizeof(date), "%m/%d/%Y - %H:%M:%S", curtime);
fprintf(pFile, "L %s: SourceMod error session started\n", date);
fprintf(pFile, "L %s: Info (map \"%s\") (file \"%s\")\n", date, m_CurrentMapName.chars(), m_ErrorFileName.chars());
m_DamagedErrorFile = true;
}
return pFile;
}
FILE *Logger::_OpenFatal()
{
char path[PLATFORM_MAX_PATH];
g_pSM->BuildPath(Path_Game, path, sizeof(path), "sourcemod_fatal.log");
return fopen(path, "at");
}
void Logger::_LogFatalOpen(ke::AString &str)
{
char error[255];
libsys->GetPlatformError(error, sizeof(error));
LogFatal("[SM] Unexpected fatal logging error (file \"%s\")", str.chars());
LogFatal("[SM] Platform returned error: \"%s\"", error);
}
void Logger::_CloseNormal()
{
if (m_DamagedNormalFile)
{
LogMessage("Log file closed.");
m_DamagedNormalFile = false;
}
}
void Logger::_CloseError()
{
if (m_DamagedErrorFile)
{
LogError("Error log file session closed.");
m_DamagedErrorFile = false;
}
}
void Logger::_CloseFatal()
{
}

42
core/logic/Logger.h
View File

@ -34,11 +34,9 @@
#include "common_logic.h" #include "common_logic.h"
#include <stdio.h> #include <stdio.h>
#include <sh_string.h> #include <amtl/am-string.h>
#include <bridge/include/ILogger.h> #include <bridge/include/ILogger.h>
using namespace SourceHook;
enum LogType enum LogType
{ {
LogType_Normal, LogType_Normal,
@ -55,9 +53,7 @@ enum LoggingMode
class Logger : public SMGlobalClass, public ILogger class Logger : public SMGlobalClass, public ILogger
{ {
public: public:
Logger() : m_Mode(LoggingMode_Daily), m_ErrMapStart(false), Logger() : m_Day(-1), m_Mode(LoggingMode_Daily), m_Active(true), m_DamagedNormalFile(false), m_DamagedErrorFile(false)
m_Active(false), m_DelayedStart(false), m_DailyPrintHdr(false),
m_InitialState(true)
{ {
} }
public: //SMGlobalClass public: //SMGlobalClass
@ -70,7 +66,6 @@ public: //SMGlobalClass
void OnSourceModAllShutdown(); void OnSourceModAllShutdown();
void OnSourceModLevelChange(const char *mapName); void OnSourceModLevelChange(const char *mapName);
public: public:
void InitLogger(LoggingMode mode);
void CloseLogger(); void CloseLogger();
void EnableLogging(); void EnableLogging();
void DisableLogging(); void DisableLogging();
@ -85,25 +80,32 @@ public:
/* This version does not print to console, and is thus thread-safe */ /* This version does not print to console, and is thus thread-safe */
void LogToFileOnly(FILE *fp, const char *msg, ...); void LogToFileOnly(FILE *fp, const char *msg, ...);
void LogToFileOnlyEx(FILE *fp, const char *msg, va_list ap); void LogToFileOnlyEx(FILE *fp, const char *msg, va_list ap);
void MapChange(const char *mapname);
const char *GetLogFileName(LogType type) const;
LoggingMode GetLoggingMode() const;
private: private:
void _MapChange(const char *mapname);
void _CloseFile(); void _CloseFile();
void _NewMapFile(); void _CloseNormal();
void _CloseError();
void _CloseFatal();
FILE *_OpenNormal();
FILE *_OpenError();
FILE *_OpenFatal();
void _LogFatalOpen(ke::AString &str);
void _PrintToGameLog(const char *fmt, va_list ap); void _PrintToGameLog(const char *fmt, va_list ap);
void _UpdateFiles(bool bLevelChange = false);
private: private:
String m_NrmFileName; ke::AString m_NormalFileName;
String m_ErrFileName; ke::AString m_ErrorFileName;
String m_CurMapName; ke::AString m_CurrentMapName;
int m_Day;
LoggingMode m_Mode; LoggingMode m_Mode;
int m_NrmCurDay;
int m_ErrCurDay;
bool m_ErrMapStart;
bool m_Active; bool m_Active;
bool m_DelayedStart; bool m_DamagedNormalFile;
bool m_DailyPrintHdr; bool m_DamagedErrorFile;
bool m_InitialState;
}; };
extern Logger g_Logger; extern Logger g_Logger;