/**

  * vim: set ts=4 sw=4 tw=99 noet :

  * =============================================================================

  * SourceMod

  * Copyright (C) 2004-2008 AlliedModders LLC.  All rights reserved.

  * =============================================================================

  *

  * This program is free software; you can redistribute it and/or modify it under

  * the terms of the GNU General Public License, version 3.0, as published by the

  * Free Software Foundation.

  * 

  * This program is distributed in the hope that it will be useful, but WITHOUT

  * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS

  * FOR A PARTICULAR PURPOSE.  See the GNU General Public License for more

  * details.

  *

  * You should have received a copy of the GNU General Public License along with

  * this program.  If not, see <http://www.gnu.org/licenses/>.

  *

  * As a special exception, AlliedModders LLC gives you permission to link the

  * code of this program (as well as its derivative works) to "Half-Life 2," the

  * "Source Engine," the "SourcePawn JIT," and any Game MODs that run on software

  * by the Valve Corporation.  You must obey the GNU General Public License in

  * all respects for all other code used.  Additionally, AlliedModders LLC grants

  * this exception to all derivative works.  AlliedModders LLC defines further

  * exceptions, found in LICENSE.txt (as of this writing, version JULY-31-2007),

  * or <http://www.sourcemod.net/license.php>.

  *

  * Version: $Id$

  */

 #include "Profiler.h"

 #include <ISourceMod.h>

 #if defined PLATFORM_POSIX

 #include <sys/time.h>

 #include <time.h>

 #endif

 #include <IPluginSys.h>

 #include "stringutil.h"

 ProfileEngine g_Profiler;

 IProfiler *sm_profiler = &g_Profiler;

 #if defined PLATFORM_WINDOWS

 double WINDOWS_PERFORMANCE_FREQUENCY;

 #endif

 class EmptyProfiler : public IProfiler

 {

 public:

 	void OnNativeBegin(IPluginContext *pContext, sp_native_t *native)

 	{

 	}

 	void OnNativeEnd()

 	{

 	}

 	void OnFunctionBegin(IPluginContext *pContext, const char *name)

 	{

 	}

 	void OnFunctionEnd()

 	{

 	}

 	int OnCallbackBegin(IPluginContext *pContext, sp_public_t *pubfunc)

 	{

 		return 0;

 	}

 	void OnCallbackEnd(int serial)

 	{

 	}

 } s_EmptyProfiler;

 inline void InitProfPoint(prof_point_t &pt)

 {

 #if defined PLATFORM_WINDOWS

 	QueryPerformanceCounter(&pt.value);

 #elif defined PLATFORM_POSIX

 	gettimeofday(&pt.value, NULL);

 #endif

 	pt.is_set = true;

 }

 ProfileEngine::ProfileEngine()

 {

 	m_serial = 0;

 #if defined PLATFORM_WINDOWS

 	LARGE_INTEGER pf;

 	if (QueryPerformanceFrequency(&pf))

 	{

 		WINDOWS_PERFORMANCE_FREQUENCY = 1.0 / (double)(pf.QuadPart);

 	}

 	else

 	{

 		WINDOWS_PERFORMANCE_FREQUENCY = -1.0;

 	}

 #endif

 	if (IsEnabled())

 	{

 		InitProfPoint(m_ProfStart);

 	}

 	else

 	{

 		sm_profiler = &s_EmptyProfiler;

 	}

 }

 bool ProfileEngine::IsEnabled()

 {

 #if defined PLATFORM_WINDOWS

 	return (WINDOWS_PERFORMANCE_FREQUENCY > 0.0);

 #elif defined PLATFORM_POSIX

 	return true;

 #endif

 }

 inline double DiffProfPoints(const prof_point_t &start, const prof_point_t &end)

 {

 	double seconds;

 #if defined PLATFORM_WINDOWS

 	LONGLONG diff;

 	diff = end.value.QuadPart - start.value.QuadPart;

 	seconds = diff * WINDOWS_PERFORMANCE_FREQUENCY;

 #elif defined PLATFORM_POSIX

 	seconds = (double)(end.value.tv_sec - start.value.tv_sec);

 	if (start.value.tv_usec > end.value.tv_usec)

 	{

 		seconds -= 1.0;

 		seconds += (double)(1000000 - (start.value.tv_usec - end.value.tv_usec)) / 1000000.0;

 	}

 	else

 	{

 		seconds += (double)(end.value.tv_usec - start.value.tv_usec) / 1000000.0;

 	}

 #endif

 	return seconds;

 }

 inline double CalcAtomTime(const prof_atom_t &atom)

 {

 	if (!atom.end.is_set)

 	{

 		return atom.base_time;

 	}

 	return atom.base_time + DiffProfPoints(atom.start, atom.end);

 }

 void ProfileEngine::OnNativeBegin(IPluginContext *pContext, sp_native_t *native)

 {

 	PushProfileStack(pContext, SP_PROF_NATIVES, native->name);

 }

 void ProfileEngine::OnNativeEnd()

 {

 	assert(!m_AtomStack.empty());

 	assert(m_AtomStack.front().atom_type == SP_PROF_NATIVES);

 	PopProfileStack(&m_Natives);

 }

 void ProfileEngine::OnFunctionBegin(IPluginContext *pContext, const char *name)

 {

 	PushProfileStack(pContext, SP_PROF_FUNCTIONS, name);

 }

 void ProfileEngine::OnFunctionEnd()

 {

 	assert(!m_AtomStack.empty());

 	assert(m_AtomStack.front().atom_type == SP_PROF_FUNCTIONS);

 	PopProfileStack(&m_Functions);

 }

 int ProfileEngine::OnCallbackBegin(IPluginContext *pContext, sp_public_t *pubfunc)

 {

 	PushProfileStack(pContext, SP_PROF_CALLBACKS, pubfunc->name);

 	return m_serial;

 }

 void ProfileEngine::OnCallbackEnd(int serial)

 {

 	assert(!m_AtomStack.empty());

 	/**

 	 * Account for the situation where the JIT discards the 

 	 * stack because there was an RTE of sorts.

 	 */

 	if (m_AtomStack.front().atom_type != SP_PROF_CALLBACKS

 		&& m_AtomStack.front().atom_serial != serial)

 	{

 		prof_atom_t atom;

 		double total_time;

 		/* There was an error, and we need to discard things. */

 		total_time = 0.0;

 		while (!m_AtomStack.empty() 

 			&& m_AtomStack.front().atom_type != SP_PROF_CALLBACKS 

 			&& m_AtomStack.front().atom_serial != serial)

 		{

 			total_time += CalcAtomTime(m_AtomStack.front());

 			m_AtomStack.pop();

 		}

 		/**

 		 * Now we can end and discard ourselves, without saving the data.

 		 * Since this data is all erroneous anyway, we don't care if it's 

 		 * not totally accurate. 

 		 */

 		assert(!m_AtomStack.empty());

 		atom = m_AtomStack.front();

 		m_AtomStack.pop();

 		/* Note: We don't need to resume ourselves because end is set by Pause(). */

 		total_time += CalcAtomTime(atom);

 		ResumeParent(total_time);

 		return;

 	}

 	PopProfileStack(&m_Callbacks);

 }

 void ProfileEngine::PushProfileStack(IPluginContext *ctx, int type, const char *name)

 {

 	prof_atom_t atom;

 	PauseParent();

 	atom.atom_type = type;

 	atom.base_time = 0.0;

 	atom.ctx = ctx->GetContext();

 	atom.name = name;

 	atom.end.is_set = false;

 	if (type == SP_PROF_CALLBACKS)

 	{

 		atom.atom_serial = ++m_serial;

 	}

 	else

 	{

 		atom.atom_serial = 0;

 	}

 	m_AtomStack.push(atom);

 	/* Note: We do this after because the stack could grow and skew results */

 	InitProfPoint(m_AtomStack.front().start);

 }

 void ProfileEngine::PopProfileStack(ProfileReport *reporter)

 {

 	double total_time;

 	prof_atom_t &atom = m_AtomStack.front();

 	/* We're okay to cache our used time. */

 	InitProfPoint(atom.end);

 	total_time = CalcAtomTime(atom);

 	/* Now it's time to save this! This may do a lot of computations which 

 	 * is why we've cached the time beforehand.

 	 */

 	reporter->SaveAtom(atom);

 	m_AtomStack.pop();

 	/* Finally, tell our parent how much time we used. */

 	ResumeParent(total_time);

 }

 void ProfileEngine::PauseParent()

 {

 	if (m_AtomStack.empty())

 	{

 		return;

 	}

 	InitProfPoint(m_AtomStack.front().end);

 }

 void ProfileEngine::ResumeParent(double addTime)

 {

 	if (m_AtomStack.empty())

 	{

 		return;

 	}

 	prof_atom_t &atom = m_AtomStack.front();

 	/* Move its "paused time" to its base (known) time, 

 	 * then reset the start/end.  Note that since CalcAtomTime() 

 	 * reads the base time, we SHOULD NOT use += to add.

 	 */

 	atom.base_time = CalcAtomTime(atom);

 	atom.base_time += addTime;

 	InitProfPoint(atom.start);

 	atom.end.is_set = false;

 }

 void ProfileEngine::Clear()

 {

 	m_Natives.Clear();

 	m_Callbacks.Clear();

 	m_Functions.Clear();

 	InitProfPoint(m_ProfStart);

 }

 void ProfileEngine::OnSourceModAllInitialized()

 {

 	rootmenu->AddRootConsoleCommand2("profiler", "Profiler commands", this);

 }

 void ProfileEngine::OnSourceModShutdown()

 {

 	rootmenu->RemoveRootConsoleCommand("profiler", this);

 }

 void ProfileEngine::OnRootConsoleCommand2(const char *cmdname, const ICommandArgs *command)

 {

 	if (command->ArgC() >= 3)

 	{

 		if (strcmp(command->Arg(2), "flush") == 0)

 		{

 			FILE *fp;

 			char path[256];

 			g_pSM->BuildPath(Path_SM, path, sizeof(path), "logs/profile_%d.xml", (int)time(NULL));

 			if ((fp = fopen(path, "wt")) == NULL)

 			{

 				rootmenu->ConsolePrint("Failed, could not open file for writing: %s", path);

 				return;

 			}

 			GenerateReport(fp);

 			fclose(fp);

 			Clear();

 			rootmenu->ConsolePrint("Profiler report generated as: %s\n", path);

 			return;

 		}

 		else if (strcmp(command->Arg(2), "report") == 0)

 		{

 			FILE *fp;

 			char path[256];

 			g_pSM->BuildPath(Path_SM, path, sizeof(path), "logs/profile_%d.xml", (int)time(NULL));

 			if ((fp = fopen(path, "wt")) == NULL)

 			{

 				rootmenu->ConsolePrint("Failed, could not open file for writing: %s", path);

 				return;

 			}

 			GenerateReport(fp);

 			fclose(fp);

 			rootmenu->ConsolePrint("Profiler report generated as: %s\n", path);

 			return;

 		}

 		else if (strcmp(command->Arg(2), "clear") == 0)

 		{

 			Clear();

 			rootmenu->ConsolePrint("Profiler statistics cleared.\n");

 			return;

 		}

 	}

 	rootmenu->ConsolePrint("Profiler commands:");

 	rootmenu->DrawGenericOption("flush", "Flushes statistics to disk and starts over");

 	rootmenu->DrawGenericOption("report", "Flushes statistics to disk");

 	rootmenu->DrawGenericOption("clear", "Clears statistics");

 }

 bool ProfileEngine::GenerateReport(FILE *fp)

 {

 	time_t t;

 	double total_time;

 	prof_point_t end_time;

 	InitProfPoint(end_time);

 	total_time = DiffProfPoints(m_ProfStart, end_time);

 	t = time(NULL);

 	fprintf(fp, "<?xml version=\"1.0\" encoding=\"UTF-8\"?>\n\n");

 	fprintf(fp, "<profile time=\"%d\" uptime=\"%f\">\n", (int)t, total_time);

 	WriteReport(fp, &m_Natives, "natives");

 	WriteReport(fp, &m_Callbacks, "callbacks");

 	WriteReport(fp, &m_Functions, "functions");

 	fprintf(fp, "</profile>\n");

 	return true;

 }

 void ProfileEngine::WriteReport(FILE *fp, ProfileReport *report, const char *name)

 {

 	size_t i, num;

 	prof_atom_report_t *ar;

 	char new_name[512];

 	fprintf(fp, " <report name=\"%s\">\n", name);

 	num = report->GetNumReports();

 	for (i = 0; i < num; i++)

 	{

 		ar = report->GetReport(i);

 		strncopy(new_name, ar->atom_name, sizeof(new_name));

 		UTIL_ReplaceAll(new_name, sizeof(new_name), "<", "&lt;", true);

 		UTIL_ReplaceAll(new_name, sizeof(new_name), ">", ">", true);

 		fprintf(fp, "  <item name=\"%s\" numcalls=\"%d\" mintime=\"%f\" maxtime=\"%f\" totaltime=\"%f\"/>\n", 

 			new_name,

 			ar->num_calls,

 			ar->min_time,

 			ar->max_time,

 			ar->total_time);

 	}

 	fprintf(fp, " </report>\n");

 }

 ProfileReport::~ProfileReport()

 {

 	for (size_t i = 0; i < m_Reports.size(); i++)

 	{

 		delete m_Reports[i];

 	}

 }

 void ProfileReport::Clear()

 {

 	m_ReportLookup.clear();

 	for (size_t i = 0; i < m_Reports.size(); i++)

 	{

 		delete m_Reports[i];

 	}

 	m_Reports.clear();

 }

 size_t ProfileReport::GetNumReports()

 {

 	return m_Reports.size();

 }

 prof_atom_report_t *ProfileReport::GetReport(size_t i)

 {

 	return m_Reports[i];

 }

 void ProfileReport::SaveAtom(const prof_atom_t &atom)

 {

 	double atom_time;

 	char full_name[256];

 	prof_atom_report_t *report;

 	if (atom.atom_type == SP_PROF_NATIVES)

 	{

 		smcore.strncopy(full_name, atom.name, sizeof(full_name));

 	}

 	else

 	{

 		IPlugin *pl;

 		const char *file;

 		file = "unknown";

 		if ((pl = pluginsys->FindPluginByContext(atom.ctx)) != NULL)

 		{

 			file = pl->GetFilename();

 		}

 		smcore.Format(full_name, sizeof(full_name), "%s!%s", file, atom.name);

 	}

 	atom_time = CalcAtomTime(atom);

 	if (!m_ReportLookup.retrieve(full_name, &report))

 	{

 		report = new prof_atom_report_t;

 		smcore.strncopy(report->atom_name, full_name, sizeof(report->atom_name));

 		report->max_time = atom_time;

 		report->min_time = atom_time;

 		report->num_calls = 1;

 		report->total_time = atom_time;

 		m_ReportLookup.insert(full_name, report);

 		m_Reports.push_back(report);

 	}

 	else

 	{

 		if (atom_time > report->max_time)

 		{

 			report->max_time = atom_time;

 		}

 		if (atom_time < report->min_time)

 		{

 			report->min_time = atom_time;

 		}

 		report->num_calls++;

 		report->total_time += atom_time;

 	}

 }