3 * =============================================================================
5 * Copyright (C) 2004-2008 AlliedModders LLC. All rights reserved.
6 * =============================================================================
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.
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
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/>.
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>.
33 #include <ISourceMod.h>
34 #if defined PLATFORM_POSIX
38 #include <IPluginSys.h>
39 #include "stringutil.h"
41 ProfileEngine g_Profiler;
42 IProfiler *sm_profiler = &g_Profiler;
44 #if defined PLATFORM_WINDOWS
45 double WINDOWS_PERFORMANCE_FREQUENCY;
48 class EmptyProfiler : public IProfiler
51 void OnNativeBegin(IPluginContext *pContext, sp_native_t *native)
57 void OnFunctionBegin(IPluginContext *pContext, const char *name)
63 int OnCallbackBegin(IPluginContext *pContext, sp_public_t *pubfunc)
67 void OnCallbackEnd(int serial)
72 inline void InitProfPoint(prof_point_t &pt)
74 #if defined PLATFORM_WINDOWS
75 QueryPerformanceCounter(&pt.value);
76 #elif defined PLATFORM_POSIX
77 gettimeofday(&pt.value, NULL);
82 ProfileEngine::ProfileEngine()
86 #if defined PLATFORM_WINDOWS
89 if (QueryPerformanceFrequency(&pf))
91 WINDOWS_PERFORMANCE_FREQUENCY = 1.0 / (double)(pf.QuadPart);
95 WINDOWS_PERFORMANCE_FREQUENCY = -1.0;
101 InitProfPoint(m_ProfStart);
105 sm_profiler = &s_EmptyProfiler;
109 bool ProfileEngine::IsEnabled()
111 #if defined PLATFORM_WINDOWS
112 return (WINDOWS_PERFORMANCE_FREQUENCY > 0.0);
113 #elif defined PLATFORM_POSIX
118 inline double DiffProfPoints(const prof_point_t &start, const prof_point_t &end)
122 #if defined PLATFORM_WINDOWS
125 diff = end.value.QuadPart - start.value.QuadPart;
126 seconds = diff * WINDOWS_PERFORMANCE_FREQUENCY;
127 #elif defined PLATFORM_POSIX
128 seconds = (double)(end.value.tv_sec - start.value.tv_sec);
130 if (start.value.tv_usec > end.value.tv_usec)
133 seconds += (double)(1000000 - (start.value.tv_usec - end.value.tv_usec)) / 1000000.0;
137 seconds += (double)(end.value.tv_usec - start.value.tv_usec) / 1000000.0;
144 inline double CalcAtomTime(const prof_atom_t &atom)
146 if (!atom.end.is_set)
148 return atom.base_time;
151 return atom.base_time + DiffProfPoints(atom.start, atom.end);
154 void ProfileEngine::OnNativeBegin(IPluginContext *pContext, sp_native_t *native)
156 PushProfileStack(pContext, SP_PROF_NATIVES, native->name);
159 void ProfileEngine::OnNativeEnd()
161 assert(!m_AtomStack.empty());
162 assert(m_AtomStack.front().atom_type == SP_PROF_NATIVES);
164 PopProfileStack(&m_Natives);
167 void ProfileEngine::OnFunctionBegin(IPluginContext *pContext, const char *name)
169 PushProfileStack(pContext, SP_PROF_FUNCTIONS, name);
172 void ProfileEngine::OnFunctionEnd()
174 assert(!m_AtomStack.empty());
175 assert(m_AtomStack.front().atom_type == SP_PROF_FUNCTIONS);
177 PopProfileStack(&m_Functions);
180 int ProfileEngine::OnCallbackBegin(IPluginContext *pContext, sp_public_t *pubfunc)
182 PushProfileStack(pContext, SP_PROF_CALLBACKS, pubfunc->name);
187 void ProfileEngine::OnCallbackEnd(int serial)
189 assert(!m_AtomStack.empty());
192 * Account for the situation where the JIT discards the
193 * stack because there was an RTE of sorts.
195 if (m_AtomStack.front().atom_type != SP_PROF_CALLBACKS
196 && m_AtomStack.front().atom_serial != serial)
201 /* There was an error, and we need to discard things. */
203 while (!m_AtomStack.empty()
204 && m_AtomStack.front().atom_type != SP_PROF_CALLBACKS
205 && m_AtomStack.front().atom_serial != serial)
207 total_time += CalcAtomTime(m_AtomStack.front());
212 * Now we can end and discard ourselves, without saving the data.
213 * Since this data is all erroneous anyway, we don't care if it's
214 * not totally accurate.
217 assert(!m_AtomStack.empty());
218 atom = m_AtomStack.front();
221 /* Note: We don't need to resume ourselves because end is set by Pause(). */
222 total_time += CalcAtomTime(atom);
224 ResumeParent(total_time);
228 PopProfileStack(&m_Callbacks);
231 void ProfileEngine::PushProfileStack(IPluginContext *ctx, int type, const char *name)
237 atom.atom_type = type;
238 atom.base_time = 0.0;
239 atom.ctx = ctx->GetContext();
241 atom.end.is_set = false;
243 if (type == SP_PROF_CALLBACKS)
245 atom.atom_serial = ++m_serial;
249 atom.atom_serial = 0;
252 m_AtomStack.push(atom);
254 /* Note: We do this after because the stack could grow and skew results */
255 InitProfPoint(m_AtomStack.front().start);
258 void ProfileEngine::PopProfileStack(ProfileReport *reporter)
262 prof_atom_t &atom = m_AtomStack.front();
264 /* We're okay to cache our used time. */
265 InitProfPoint(atom.end);
266 total_time = CalcAtomTime(atom);
268 /* Now it's time to save this! This may do a lot of computations which
269 * is why we've cached the time beforehand.
271 reporter->SaveAtom(atom);
274 /* Finally, tell our parent how much time we used. */
275 ResumeParent(total_time);
278 void ProfileEngine::PauseParent()
280 if (m_AtomStack.empty())
285 InitProfPoint(m_AtomStack.front().end);
288 void ProfileEngine::ResumeParent(double addTime)
290 if (m_AtomStack.empty())
295 prof_atom_t &atom = m_AtomStack.front();
297 /* Move its "paused time" to its base (known) time,
298 * then reset the start/end. Note that since CalcAtomTime()
299 * reads the base time, we SHOULD NOT use += to add.
301 atom.base_time = CalcAtomTime(atom);
302 atom.base_time += addTime;
303 InitProfPoint(atom.start);
304 atom.end.is_set = false;
307 void ProfileEngine::Clear()
312 InitProfPoint(m_ProfStart);
315 void ProfileEngine::OnSourceModAllInitialized()
317 rootmenu->AddRootConsoleCommand2("profiler", "Profiler commands", this);
320 void ProfileEngine::OnSourceModShutdown()
322 rootmenu->RemoveRootConsoleCommand("profiler", this);
325 void ProfileEngine::OnRootConsoleCommand2(const char *cmdname, const ICommandArgs *command)
327 if (command->ArgC() >= 3)
329 if (strcmp(command->Arg(2), "flush") == 0)
334 g_pSM->BuildPath(Path_SM, path, sizeof(path), "logs/profile_%d.xml", (int)time(NULL));
336 if ((fp = fopen(path, "wt")) == NULL)
338 rootmenu->ConsolePrint("Failed, could not open file for writing: %s", path);
348 rootmenu->ConsolePrint("Profiler report generated as: %s\n", path);
352 else if (strcmp(command->Arg(2), "report") == 0)
357 g_pSM->BuildPath(Path_SM, path, sizeof(path), "logs/profile_%d.xml", (int)time(NULL));
359 if ((fp = fopen(path, "wt")) == NULL)
361 rootmenu->ConsolePrint("Failed, could not open file for writing: %s", path);
369 rootmenu->ConsolePrint("Profiler report generated as: %s\n", path);
372 else if (strcmp(command->Arg(2), "clear") == 0)
376 rootmenu->ConsolePrint("Profiler statistics cleared.\n");
381 rootmenu->ConsolePrint("Profiler commands:");
382 rootmenu->DrawGenericOption("flush", "Flushes statistics to disk and starts over");
383 rootmenu->DrawGenericOption("report", "Flushes statistics to disk");
384 rootmenu->DrawGenericOption("clear", "Clears statistics");
387 bool ProfileEngine::GenerateReport(FILE *fp)
391 prof_point_t end_time;
393 InitProfPoint(end_time);
394 total_time = DiffProfPoints(m_ProfStart, end_time);
398 fprintf(fp, "<?xml version=\"1.0\" encoding=\"UTF-8\"?>\n\n");
399 fprintf(fp, "<profile time=\"%d\" uptime=\"%f\">\n", (int)t, total_time);
400 WriteReport(fp, &m_Natives, "natives");
401 WriteReport(fp, &m_Callbacks, "callbacks");
402 WriteReport(fp, &m_Functions, "functions");
403 fprintf(fp, "</profile>\n");
408 void ProfileEngine::WriteReport(FILE *fp, ProfileReport *report, const char *name)
411 prof_atom_report_t *ar;
414 fprintf(fp, " <report name=\"%s\">\n", name);
416 num = report->GetNumReports();
417 for (i = 0; i < num; i++)
419 ar = report->GetReport(i);
421 strncopy(new_name, ar->atom_name, sizeof(new_name));
422 UTIL_ReplaceAll(new_name, sizeof(new_name), "<", "<", true);
423 UTIL_ReplaceAll(new_name, sizeof(new_name), ">", ">", true);
425 fprintf(fp, " <item name=\"%s\" numcalls=\"%d\" mintime=\"%f\" maxtime=\"%f\" totaltime=\"%f\"/>\n",
433 fprintf(fp, " </report>\n");
436 ProfileReport::~ProfileReport()
438 for (size_t i = 0; i < m_Reports.size(); i++)
444 void ProfileReport::Clear()
446 m_ReportLookup.clear();
447 for (size_t i = 0; i < m_Reports.size(); i++)
454 size_t ProfileReport::GetNumReports()
456 return m_Reports.size();
459 prof_atom_report_t *ProfileReport::GetReport(size_t i)
464 void ProfileReport::SaveAtom(const prof_atom_t &atom)
468 prof_atom_report_t **pReport, *report;
470 if (atom.atom_type == SP_PROF_NATIVES)
472 smcore.strncopy(full_name, atom.name, sizeof(full_name));
480 if ((pl = pluginsys->FindPluginByContext(atom.ctx)) != NULL)
482 file = pl->GetFilename();
485 smcore.Format(full_name, sizeof(full_name), "%s!%s", file, atom.name);
488 atom_time = CalcAtomTime(atom);
490 if ((pReport = m_ReportLookup.retrieve(full_name)) == NULL)
492 report = new prof_atom_report_t;
494 smcore.strncopy(report->atom_name, full_name, sizeof(report->atom_name));
495 report->max_time = atom_time;
496 report->min_time = atom_time;
497 report->num_calls = 1;
498 report->total_time = atom_time;
500 m_ReportLookup.insert(full_name, report);
501 m_Reports.push_back(report);
507 if (atom_time > report->max_time)
509 report->max_time = atom_time;
511 if (atom_time < report->min_time)
513 report->min_time = atom_time;
516 report->total_time += atom_time;