libsst/ZUtil/ZLog.cpp

#include <ZUtil/ZLog.hpp>
#include <ZUtil/ZAlloc.hpp>

#include <iostream>
#include <fstream>
#include <stdarg.h>
#include <algorithm>

////////////////////////////////////
/* Static Variable Initialization */
////////////////////////////////////

ZMutex ZLog::LogLock;

bool ZLog::bIsInitialized = false;

ZArray< ZPair<std::ofstream*, bool> > ZLog::LogFiles;

ZArray< ZPtr<ZLogDelegate> > ZLog::Delegates;

ZString ZLog::LogFileRoot;

uint64_t* ZLog::UserTick = NULL;
uint64_t* ZLog::UserUpdate = NULL;

uint64_t ZLog::TickEstimate = 0;
uint64_t ZLog::UpdateFrameEstimate = 0;

///////////////////////////
/* Local Helper Function */
///////////////////////////

void writeHeader(std::ofstream& logfile, const char* filename)
{

	logfile << filename << " : ZUtil version " << ZUTIL_VERSION_STRING << " default log file\n\n";

	#if ZLOG_LEVEL >= ZLOG_LEVEL_INFO
	logfile << "+------------+------------+\n";
	logfile << "| Time (sec) | Update No. |\n";
	logfile << "+------------+------------+\n";
	#endif
}

void writeFooter(std::ofstream& logfile)
{
	#if ZLOG_LEVEL >= ZLOG_LEVEL_INFO
	logfile << "+------------+------------+\n";
	#endif
}

int logAssertHandler(const char* _msg, void *_arg)
{
	URFP(_arg);

	//Log it!
	SystemLogError("Assertion Failed: \n");
	SystemLogError(_msg);

	//Let the error propagate
	return 0;
}

/////////////////////////////////
/* Static Function Declaration */
/////////////////////////////////

void ZLog::Init(const ZString& _logFileRoot, const ZString& _defaultLogFile, uint64_t* _ticks /*= NULL*/, uint64_t* _update /*= NULL*/)
{
	std::ofstream *logfile;

	//Save our root path
	ZLog::LogFileRoot = _logFileRoot;

	//Create a default log file
	ZString logFilePath = ZLog::LogFileRoot + _defaultLogFile;

	logfile = znew_notrack std::ofstream();
	logfile->open(logFilePath.Data(), std::ios::out);

	while (logfile->fail()) {
		logFilePath += "_";
		logfile->open(logFilePath.Data(), std::ios::out);
	}

	//Write the header
	writeHeader(*logfile, _defaultLogFile.Data());

	//Add the default log file to the set
	ZLog::LogFiles.Reserve(16);
	ZLog::LogFiles.Clear();
	ZLog::LogFiles.PushBack(ZPair<std::ofstream*, bool>(logfile, true));

	//Set our SST_Assert handlers
	SST_OS_SetDebugAssertHandler(logAssertHandler, NULL);
	SST_OS_SetRuntimeAssertHandler(logAssertHandler, NULL);

	ZLog::UserTick = _ticks;
	ZLog::UserUpdate = _update;

	//We're ready to rock and roll
	ZLog::bIsInitialized = true;
}

void ZLog::Shutdown()
{
	ZArray< ZPair<std::ofstream*, bool> >::Iterator itr;

	//Iterate and close out
	for (itr = ZLog::LogFiles.Begin(); itr != ZLog::LogFiles.End(); itr++)
	{
		writeFooter(*((*itr).First));

		(*itr).First->close();
		(*itr).Second = false;

		zdelete (*itr).First;
	}

	//Flush standard outputs
	std::cout.flush();
	std::cerr.flush();

	//Clear our set of log files
	ZLog::LogFiles.Clear();
}

void ZLog::AddLoggingDelegate(ZPtr<ZLogDelegate> _delegate)
{
	ZLog::LogLock.Acquire();

	ZLog::Delegates.PushBack(_delegate);

	ZLog::LogLock.Release();
}

ZLogFile ZLog::CreateLogFile(const ZString& _fileName)
{
	ZLogFile handle;
	std::ofstream *file;

	//See if we can early out
	if (!ZLog::bIsInitialized)
	{
		std::cerr << "Attempted to create log file (Before call to Init) : " << _fileName.Data() << std::endl;
		return (ZLogFile)0;
	}

	ZString logFilePath = ZLog::LogFileRoot + _fileName;

	//Synchronized Section
	{
		//Scoped lock
		ZLock scopedLock(ZLog::LogLock);

		file = znew_notrack std::ofstream();

		if (file == NULL)
		{
			fprintf(stderr, "Failed to create log file %s!\n", _fileName.Data());
			return (ZLogFile)0;
		}

		file->open(logFilePath.Data(), std::ios::out);

		if (!file->is_open())
		{
			//Nope nope nope
			fprintf(stderr, "Failed to open log file %s!\n", _fileName.Data());
			zdelete file;
			return (ZLogFile)0;
		}
		else
		{
			//Write the header
			writeHeader(*file, _fileName.Data());

			//This will give us the index where it will be going
			handle = ZLog::LogFiles.Size();

			//Add to the set of streams already activated
			ZLog::LogFiles.PushBack(ZPair<std::ofstream*, bool>(file, true));
		}
	}

	return handle;
}

void ZLog::Resume( ZLogFile _logFile )
{
	//Scoped Lock
	ZLock scopedLock(ZLog::LogLock);

	ZASSERT_RUNTIME((size_t)_logFile < LogFiles.Size(), "Cannot resume logging to file: file does not exist!");

	ZLog::LogFiles[_logFile].Second = true;
}

void ZLog::Suspend( ZLogFile _logFile )
{
	//Scoped Lock
	ZLock scopedLock(ZLog::LogLock);

	ZASSERT_RUNTIME((size_t)_logFile < LogFiles.Size(), "Cannot resume logging to file: file does not exist!");

	ZLog::LogFiles[_logFile].Second = false;
}

void ZLog::Printf(ZLogType _type, ZLogFile _file, uint64_t _ticks, uint32_t _updateFrame, const char *_function, const char *_str, ...)
{
	URFP(_function);

	va_list args;

	//Check for easy out
	if (!ZLog::bIsInitialized)
		return;

	//Make sure we're null terminated
	char string[32768];
	MemSetChar(string, 0, 32768);

	va_start(args, _str);

	#ifdef _MSC_VER
	vsnprintf_s(string, sizeof(string)-1, sizeof(string)-1, _str, args);
	#else
	vsnprintf(string, sizeof(string)-1, _str, args);
	#endif

	//Write using our existing write function
	ZLog::WriteLine(_type, _file, _ticks, _updateFrame, string);

	va_end(args);
}

void ZLog::WriteLine(ZLogType _type, ZLogFile _file, uint64_t _ticks, uint32_t _updateFrame, const char *_str)
{
	#if ZLOG_LEVEL >= ZLOG_LEVEL_INFO
	char time[32];
	char update[32];
	#endif

	//See if we can early out (should warn)
	if (!ZLog::bIsInitialized)
	{
		std::cerr << "Logging Output (Before call to Init): " << _str << std::endl;
		return;
	}

	//Synchronized Section
	{
		//Scoped Lock
		ZLock scopedLock(ZLog::LogLock);

		ZASSERT_RUNTIME((size_t)_file < LogFiles.Size(), "Cannot log to file: file not created!");

		//Get the file and find out if activated
		std::ofstream *logfile = ZLog::LogFiles[_file].First;
		bool enabled = ZLog::LogFiles[_file].Second;

		//If we are not currently enabled, we are no longer needed
		if (!enabled)
			return;

		//Get our best guesses
		if (ZLog::UserTick != NULL) {
			ZLog::TickEstimate = *ZLog::UserTick;
		} else if (_ticks > ZLog::TickEstimate) {
			ZLog::TickEstimate = _ticks;
		}

		if (ZLog::UserUpdate != NULL) {
			ZLog::UpdateFrameEstimate = *ZLog::UserUpdate;
		} else if (_updateFrame > ZLog::UpdateFrameEstimate) {
			ZLog::UpdateFrameEstimate = _updateFrame;
		}

		ZASSERT_UTIL(logfile != NULL, "ZLog Error: logfile is NULL!");

		#if ZLOG_LEVEL >= ZLOG_LEVEL_INFO

		//If we are at detailed (or higher) log level, then log the extra details, then the string
		if (_ticks == 0 && _updateFrame == 0 && ZLog::UserTick == NULL && ZLog::UserUpdate == NULL) {
			sprintf(time, "?%11.3f", ((float)ZLog::TickEstimate) / 1000.0f);
			sprintf(update, "?%11lu", ZLog::UpdateFrameEstimate);
		} else {
			sprintf(time, "%12.3f", ((float)ZLog::TickEstimate) / 1000.0f);
			sprintf(update, "%12lu", ZLog::UpdateFrameEstimate);
		}
		
		std::cout << _str << std::endl;
		*logfile << "|" << time << "|" << update << "| " << /*ZConcurrency::GetThreadName() << ": " << */_str << std::endl;

		#else

		std::cout << _str << std::endl;
		*logfile << _str << std::endl;

		#endif //ZLOG_LEVEL >= ZLOG_LEVEL_DETAILED

		//Let the delegates know what happened
		for (ZArray< ZPtr<ZLogDelegate> >::Iterator i = ZLog::Delegates.Begin(); i != ZLog::Delegates.End(); i++)
			(*i)->Execute(_type, _file, _str);
	}
}