core/Logger.cpp
author Nicholas Hastings <skamonkey@gmail.com>
Fri Aug 30 14:15:02 2013 -0400 (2013-08-30)
changeset 4102 0eb66c45a884
parent 3926 ff7231bfdd0b
child 4188 89782d5fc91b
permissions -rw-r--r--
Reserved slot fixes for OB games when SourceTV or Replay are enabled (bug 5499, r=drifter).
     1 /**
     2  * vim: set ts=4 sw=4 :
     3  * =============================================================================
     4  * SourceMod
     5  * Copyright (C) 2004-2009 AlliedModders LLC.  All rights reserved.
     6  * =============================================================================
     7  *
     8  * This program is free software; you can redistribute it and/or modify it under
     9  * the terms of the GNU General Public License, version 3.0, as published by the
    10  * Free Software Foundation.
    11  * 
    12  * This program is distributed in the hope that it will be useful, but WITHOUT
    13  * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS
    14  * FOR A PARTICULAR PURPOSE.  See the GNU General Public License for more
    15  * details.
    16  *
    17  * You should have received a copy of the GNU General Public License along with
    18  * this program.  If not, see <http://www.gnu.org/licenses/>.
    19  *
    20  * As a special exception, AlliedModders LLC gives you permission to link the
    21  * code of this program (as well as its derivative works) to "Half-Life 2," the
    22  * "Source Engine," the "SourcePawn JIT," and any Game MODs that run on software
    23  * by the Valve Corporation.  You must obey the GNU General Public License in
    24  * all respects for all other code used.  Additionally, AlliedModders LLC grants
    25  * this exception to all derivative works.  AlliedModders LLC defines further
    26  * exceptions, found in LICENSE.txt (as of this writing, version JULY-31-2007),
    27  * or <http://www.sourcemod.net/license.php>.
    28  *
    29  * Version: $Id$
    30  */
    31 
    32 #include <time.h>
    33 #include "sourcemod.h"
    34 #include "sourcemm_api.h"
    35 #include "sm_stringutil.h"
    36 #include "Logger.h"
    37 #include "LibrarySys.h"
    38 #include "TimerSys.h"
    39 #include <sourcemod_version.h>
    40 #include "logic_bridge.h"
    41 
    42 Logger g_Logger;
    43 
    44 SH_DECL_HOOK1_void(IVEngineServer, LogPrint, SH_NOATTRIB, false, const char *);
    45 
    46 /**
    47  * :TODO: This should be creating the log folder if it doesn't exist
    48  */
    49 
    50 ConfigResult Logger::OnSourceModConfigChanged(const char *key, 
    51 									  const char *value, 
    52 									  ConfigSource source,
    53 									  char *error, 
    54 									  size_t maxlength)
    55 {
    56 	if (strcasecmp(key, "Logging") == 0)
    57 	{
    58 		bool state;
    59 
    60 		if (strcasecmp(value, "on") == 0)
    61 		{
    62 			state = true;
    63 		} else if (strcasecmp(value, "off") == 0) {
    64 			state = false;
    65 		} else {
    66 			UTIL_Format(error, maxlength, "Invalid value: must be \"on\" or \"off\"");
    67 			return ConfigResult_Reject;
    68 		}
    69 
    70 		if (source == ConfigSource_Console)
    71 		{
    72 			state ? EnableLogging() : DisableLogging();
    73 		} else {
    74 			m_InitialState = state;
    75 		}
    76 
    77 		return ConfigResult_Accept;
    78 	} else if (strcasecmp(key, "LogMode") == 0) {
    79 		if (strcasecmp(value, "daily") == 0) 
    80 		{
    81 			m_Mode = LoggingMode_Daily;
    82 		} else if (strcasecmp(value, "map") == 0) {
    83 			m_Mode = LoggingMode_PerMap;
    84 		} else if (strcasecmp(value, "game") == 0) {
    85 			m_Mode = LoggingMode_Game;
    86 		} else {
    87 			UTIL_Format(error, maxlength, "Invalid value: must be [daily|map|game]");
    88 			return ConfigResult_Reject;
    89 		}
    90 
    91 		return ConfigResult_Accept;
    92 	}
    93 
    94 	return ConfigResult_Ignore;
    95 }
    96 
    97 static void HookLogPrint(const char *message)
    98 {
    99 	g_in_game_log_hook = true;
   100 	bool stopped = logicore.OnLogPrint(message);
   101 	g_in_game_log_hook = false;
   102 
   103 	if (stopped)
   104 		RETURN_META(MRES_SUPERCEDE);
   105 }
   106 
   107 void Logger::OnSourceModStartup(bool late)
   108 {
   109 	InitLogger(m_Mode);
   110 
   111 	SH_ADD_HOOK(IVEngineServer, LogPrint, engine, SH_STATIC(HookLogPrint), false);
   112 }
   113 
   114 void Logger::OnSourceModAllShutdown()
   115 {
   116 	CloseLogger();
   117 	SH_REMOVE_HOOK(IVEngineServer, LogPrint, engine, SH_STATIC(HookLogPrint), false);
   118 }
   119 
   120 void Logger::OnSourceModLevelChange(const char *mapName)
   121 {
   122 	MapChange(mapName);
   123 }
   124 
   125 void Logger::_NewMapFile()
   126 {
   127 	if (!m_Active)
   128 	{
   129 		return;
   130 	}
   131 
   132 	/* Append "Log file closed" to previous log file */
   133 	_CloseFile();
   134 	
   135 	char _filename[256];
   136 	int i = 0;
   137 
   138 	time_t t;
   139 	GetAdjustedTime(&t);
   140 	tm *curtime = localtime(&t);
   141 
   142 	while (true)
   143 	{
   144 		g_SourceMod.BuildPath(Path_SM, _filename, sizeof(_filename), "logs/L%02d%02d%03d.log", curtime->tm_mon + 1, curtime->tm_mday, i);
   145 		FILE *fp = fopen(_filename, "r");
   146 		if (!fp)
   147 		{
   148 			break;
   149 		}
   150 		fclose(fp);
   151 		i++;
   152 	}
   153 	m_NrmFileName.assign(_filename);
   154 
   155 	FILE *fp = fopen(m_NrmFileName.c_str(), "w");
   156 	if (!fp)
   157 	{
   158 		char error[255];
   159 		g_LibSys.GetPlatformError(error, sizeof(error));
   160 		LogFatal("[SM] Unexpected fatal logging error (file \"%s\")", m_NrmFileName.c_str());
   161 		LogFatal("[SM] Platform returned error: \"%s\"", error);
   162 		LogFatal("[SM] Logging has been disabled.");
   163 		m_Active = false;
   164 		return;
   165 	} else {
   166 		char date[32];
   167 		strftime(date, sizeof(date), "%m/%d/%Y - %H:%M:%S", curtime);
   168 		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, SM_VERSION_STRING);
   169 		fclose(fp);
   170 	}
   171 }
   172 
   173 void Logger::_CloseFile()
   174 {
   175 	if (!m_Active)
   176 	{
   177 		return;
   178 	}
   179 
   180 	FILE *fp = NULL;
   181 	if (!m_NrmFileName.empty())
   182 	{
   183 		fp = fopen(m_NrmFileName.c_str(), "r+");
   184 		if (fp)
   185 		{
   186 			fseek(fp, 0, SEEK_END);
   187 			LogMessage("Log file closed.");
   188 			fclose(fp);
   189 		}
   190 		m_NrmFileName.clear();
   191 	}
   192 
   193 	if (!m_ErrMapStart)
   194 	{
   195 		return;
   196 	}
   197 	fp = fopen(m_ErrFileName.c_str(), "r+");
   198 	if (fp)
   199 	{
   200 		fseek(fp, 0, SEEK_END);
   201 		LogError("Error log file session closed.");
   202 		fclose(fp);
   203 	}
   204 	m_ErrFileName.clear();
   205 }
   206 
   207 void Logger::InitLogger(LoggingMode mode)
   208 {
   209 	m_Mode = mode;
   210 	m_Active = m_InitialState;
   211 
   212 	time_t t;
   213 	GetAdjustedTime(&t);
   214 	tm *curtime = localtime(&t);
   215 	m_NrmCurDay = curtime->tm_mday;
   216 	m_ErrCurDay = curtime->tm_mday;
   217 
   218 	char _filename[256];
   219 	g_SourceMod.BuildPath(Path_SM, _filename, sizeof(_filename), "logs/errors_%04d%02d%02d.log", curtime->tm_year + 1900, curtime->tm_mon + 1, curtime->tm_mday);
   220 	m_ErrFileName.assign(_filename);
   221 
   222 	switch (m_Mode)
   223 	{
   224 	case LoggingMode_PerMap:
   225 		{
   226 			if (!m_Active)
   227 			{
   228 				m_DelayedStart = true;
   229 			}
   230 			break;
   231 		}
   232 	case LoggingMode_Daily:
   233 		{
   234 			g_SourceMod.BuildPath(Path_SM, _filename, sizeof(_filename), "logs/L%04d%02d%02d.log", curtime->tm_year + 1900, curtime->tm_mon + 1, curtime->tm_mday);
   235 			m_NrmFileName.assign(_filename);
   236 			m_DailyPrintHdr = true;
   237 			break;
   238 		}
   239 	default:
   240 		{
   241 			/* do nothing... */
   242 			break;
   243 		}
   244 	}
   245 }
   246 
   247 void Logger::CloseLogger()
   248 {
   249 	_CloseFile();
   250 }
   251 
   252 void Logger::LogToOpenFile(FILE *fp, const char *msg, ...)
   253 {
   254 	if (!m_Active)
   255 	{
   256 		return;
   257 	}
   258 
   259 	va_list ap;
   260 	va_start(ap, msg);
   261 	LogToOpenFileEx(fp, msg, ap);
   262 	va_end(ap);
   263 }
   264 
   265 void Logger::LogToFileOnly(FILE *fp, const char *msg, ...)
   266 {
   267 	if (!m_Active)
   268 	{
   269 		return;
   270 	}
   271 
   272 	va_list ap;
   273 	va_start(ap, msg);
   274 	LogToFileOnlyEx(fp, msg, ap);
   275 	va_end(ap);
   276 }
   277 
   278 void Logger::LogToOpenFileEx(FILE *fp, const char *msg, va_list ap)
   279 {
   280 	if (!m_Active)
   281 	{
   282 		return;
   283 	}
   284 
   285 	static ConVar *sv_logecho = icvar->FindVar("sv_logecho");
   286 
   287 	char buffer[3072];
   288 	UTIL_FormatArgs(buffer, sizeof(buffer), msg, ap);
   289 
   290 	char date[32];
   291 	time_t t;
   292 	GetAdjustedTime(&t);
   293 	tm *curtime = localtime(&t);
   294 	strftime(date, sizeof(date), "%m/%d/%Y - %H:%M:%S", curtime);
   295 
   296 	fprintf(fp, "L %s: %s\n", date, buffer);
   297 
   298 	if (!sv_logecho || sv_logecho->GetBool())
   299 	{
   300 		g_SMAPI->ConPrintf("L %s: %s\n", date, buffer);
   301 	}
   302 }
   303 
   304 void Logger::LogToFileOnlyEx(FILE *fp, const char *msg, va_list ap)
   305 {
   306 	if (!m_Active)
   307 	{
   308 		return;
   309 	}
   310 
   311 	char buffer[3072];
   312 	UTIL_FormatArgs(buffer, sizeof(buffer), msg, ap);
   313 
   314 	char date[32];
   315 	time_t t;
   316 	GetAdjustedTime(&t);
   317 	tm *curtime = localtime(&t);
   318 	strftime(date, sizeof(date), "%m/%d/%Y - %H:%M:%S", curtime);
   319 
   320 	fprintf(fp, "L %s: %s\n", date, buffer);
   321 	fflush(fp);
   322 }
   323 
   324 void Logger::LogMessage(const char *vafmt, ...)
   325 {
   326 	va_list ap;
   327 	va_start(ap, vafmt);
   328 	LogMessageEx(vafmt, ap);
   329 	va_end(ap);
   330 }
   331 
   332 void Logger::LogMessageEx(const char *vafmt, va_list ap)
   333 {
   334 	if (!m_Active)
   335 	{
   336 		return;
   337 	}
   338 
   339 	if (m_Mode == LoggingMode_Game)
   340 	{
   341 		_PrintToGameLog(vafmt, ap);
   342 		return;
   343 	}
   344 
   345 	if (m_DelayedStart)
   346 	{
   347 		m_DelayedStart = false;
   348 		_NewMapFile();
   349 	}
   350 
   351 	time_t t;
   352 	GetAdjustedTime(&t);
   353 	tm *curtime = localtime(&t);
   354 
   355 	FILE *fp = NULL;
   356 	if (m_Mode == LoggingMode_PerMap)
   357 	{
   358 		fp = fopen(m_NrmFileName.c_str(), "a+");
   359 		if (!fp)
   360 		{
   361 			_NewMapFile();
   362 			fp = fopen(m_NrmFileName.c_str(), "a+");
   363 			if (!fp)
   364 			{
   365 				goto print_error;
   366 			}
   367 		}
   368 	} else {
   369 		if (m_NrmCurDay != curtime->tm_mday)
   370 		{
   371 			char _filename[256];
   372 			g_SourceMod.BuildPath(Path_SM, _filename, sizeof(_filename), "logs/L%04d%02d%02d.log", curtime->tm_year + 1900, curtime->tm_mon + 1, curtime->tm_mday);
   373 			m_NrmFileName.assign(_filename);
   374 			m_NrmCurDay = curtime->tm_mday;
   375 			m_DailyPrintHdr = true;
   376 		}
   377 		fp = fopen(m_NrmFileName.c_str(), "a+");
   378 	}
   379 
   380 	if (fp)
   381 	{
   382 		if (m_DailyPrintHdr)
   383 		{
   384 			char date[32];
   385 			m_DailyPrintHdr = false;
   386 			strftime(date, sizeof(date), "%m/%d/%Y - %H:%M:%S", curtime);
   387 			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, SM_VERSION_STRING);
   388 	 	}
   389 		LogToOpenFileEx(fp, vafmt, ap);
   390 		fclose(fp);
   391 	} else {
   392 		goto print_error;
   393 	}
   394 
   395 	return;
   396 print_error:
   397 	char error[255];
   398 	g_LibSys.GetPlatformError(error, sizeof(error));
   399 	LogFatal("[SM] Unexpected fatal logging error (file \"%s\")", m_NrmFileName.c_str());
   400 	LogFatal("[SM] Platform returned error: \"%s\"", error);
   401 	LogFatal("[SM] Logging has been disabled.");
   402 	m_Active = false;
   403 }
   404 
   405 void Logger::LogError(const char *vafmt, ...)
   406 {
   407 	va_list ap;
   408 	va_start(ap, vafmt);
   409 	LogErrorEx(vafmt, ap);
   410 	va_end(ap);
   411 }
   412 
   413 void Logger::LogErrorEx(const char *vafmt, va_list ap)
   414 {
   415 	if (!m_Active)
   416 	{
   417 		return;
   418 	}
   419 
   420 	time_t t;
   421 	GetAdjustedTime(&t);
   422 	tm *curtime = localtime(&t);
   423 
   424 	if (curtime->tm_mday != m_ErrCurDay)
   425 	{
   426 		char _filename[256];
   427 		g_SourceMod.BuildPath(Path_SM, _filename, sizeof(_filename), "logs/errors_%04d%02d%02d.log", curtime->tm_year + 1900, curtime->tm_mon + 1, curtime->tm_mday);
   428 		m_ErrFileName.assign(_filename);
   429 		m_ErrCurDay = curtime->tm_mday;
   430 		m_ErrMapStart = false;
   431 	}
   432 
   433 	FILE *fp = fopen(m_ErrFileName.c_str(), "a+");
   434 	if (fp)
   435 	{
   436 		if (!m_ErrMapStart)
   437 		{
   438 			char date[32];
   439 			strftime(date, sizeof(date), "%m/%d/%Y - %H:%M:%S", curtime);
   440 			fprintf(fp, "L %s: SourceMod error session started\n", date);
   441 			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);
   442 			m_ErrMapStart = true;
   443 		}
   444 		LogToOpenFileEx(fp, vafmt, ap);
   445 		fclose(fp);
   446 	}
   447 	else
   448 	{
   449 		char error[255];
   450 		g_LibSys.GetPlatformError(error, sizeof(error));
   451 		LogFatal("[SM] Unexpected fatal logging error (file \"%s\")", m_NrmFileName.c_str());
   452 		LogFatal("[SM] Platform returned error: \"%s\"", error);
   453 		LogFatal("[SM] Logging has been disabled.");
   454 		m_Active = false;
   455 		return;
   456 	}
   457 }
   458 
   459 void Logger::MapChange(const char *mapname)
   460 {
   461 	m_CurMapName.assign(mapname);
   462 
   463 	switch (m_Mode)
   464 	{
   465 	case LoggingMode_Daily:
   466 		{
   467 			LogMessage("-------- Mapchange to %s --------", mapname);
   468 			break;
   469 		}
   470 	case LoggingMode_PerMap:
   471 		{
   472 			_NewMapFile();
   473 			break;
   474 		}
   475 	default:
   476 		{
   477 			/* Do nothing... */
   478 			break;
   479 		}
   480 	}
   481 
   482 	if (m_ErrMapStart)
   483 	{
   484 		LogError("Error log file session closed.");
   485 	}
   486 	m_ErrMapStart = false;
   487 }
   488 
   489 void Logger::_PrintToGameLog(const char *fmt, va_list ap)
   490 {
   491 	char msg[3072];
   492 	size_t len;
   493 
   494 	len = vsnprintf(msg, sizeof(msg)-2, fmt, ap);
   495 	len = (len >= sizeof(msg)) ? (sizeof(msg) - 2) : len;
   496 
   497 	msg[len++] = '\n';
   498 	msg[len] = '\0';
   499 
   500 	Engine_LogPrintWrapper(msg);
   501 }
   502 
   503 const char *Logger::GetLogFileName(LogType type) const
   504 {
   505 	switch (type)
   506 	{
   507 	case LogType_Normal:
   508 		{
   509 			return m_NrmFileName.c_str();
   510 		}
   511 	case LogType_Error:
   512 		{
   513 			return m_ErrFileName.c_str();
   514 		}
   515 	default:
   516 		{
   517 			return "";
   518 		}
   519 	}
   520 }
   521 
   522 LoggingMode Logger::GetLoggingMode() const
   523 {
   524 	return m_Mode;
   525 }
   526 
   527 void Logger::EnableLogging()
   528 {
   529 	if (m_Active)
   530 	{
   531 		return;
   532 	}
   533 	m_Active = true;
   534 	LogMessage("[SM] Logging enabled manually by user.");
   535 }
   536 
   537 void Logger::DisableLogging()
   538 {
   539 	if (!m_Active)
   540 	{
   541 		return;
   542 	}
   543 	LogMessage("[SM] Logging disabled manually by user.");
   544 	m_Active = false;
   545 }
   546 
   547 void Logger::LogFatal(const char *msg, ...)
   548 {
   549 	va_list ap;
   550 	va_start(ap, msg);
   551 	LogFatalEx(msg, ap);
   552 	va_end(ap);
   553 }
   554 
   555 void Logger::LogFatalEx(const char *msg, va_list ap)
   556 {
   557 	/* :TODO: make this print all pretty-like
   558 	 * In fact, the pretty log printing function should be abstracted. 
   559 	 * It's already implemented twice which is bad.
   560 	 */
   561 
   562 	char path[PLATFORM_MAX_PATH];
   563 
   564 	g_SourceMod.BuildPath(Path_Game, path, sizeof(path), "sourcemod_fatal.log");
   565 
   566 	FILE *fp = fopen(path, "at");
   567 	if (fp)
   568 	{
   569 		m_Active = true;
   570 		LogToOpenFileEx(fp, msg, ap);
   571 		m_Active = false;
   572 		fclose(fp);
   573 	}
   574 }
   575 
   576 bool g_in_game_log_hook = false;
   577 
   578 void Engine_LogPrintWrapper(const char *msg)
   579 {
   580 	if (g_in_game_log_hook)
   581 	{
   582 		ENGINE_CALL(LogPrint)(msg);
   583 	}
   584 	else
   585 	{
   586 		engine->LogPrint(msg);
   587 	}
   588 }