3 * =============================================================================
5 * Copyright (C) 2004-2007 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 "PluginSys.h"
34 #include "sm_stringutil.h"
37 ProfileEngine g_Profiler;
38 IProfiler *sm_profiler = &g_Profiler;
40 #if defined PLATFORM_WINDOWS
41 double WINDOWS_PERFORMANCE_FREQUENCY;
44 class EmptyProfiler : public IProfiler
47 void OnNativeBegin(IPluginContext *pContext, sp_native_t *native)
53 void OnFunctionBegin(IPluginContext *pContext, const char *name)
59 int OnCallbackBegin(IPluginContext *pContext, sp_public_t *pubfunc)
63 void OnCallbackEnd(int serial)
68 inline void InitProfPoint(prof_point_t &pt)
70 #if defined PLATFORM_WINDOWS
71 QueryPerformanceCounter(&pt.value);
72 #elif defined PLATFORM_POSIX
73 gettimeofday(&pt.value, NULL);
78 ProfileEngine::ProfileEngine()
82 #if defined PLATFORM_WINDOWS
85 if (QueryPerformanceFrequency(&pf))
87 WINDOWS_PERFORMANCE_FREQUENCY = 1.0 / (double)(pf.QuadPart);
91 WINDOWS_PERFORMANCE_FREQUENCY = -1.0;
97 InitProfPoint(m_ProfStart);
101 sm_profiler = &s_EmptyProfiler;
105 bool ProfileEngine::IsEnabled()
107 #if defined PLATFORM_WINDOWS
108 return (WINDOWS_PERFORMANCE_FREQUENCY > 0.0);
109 #elif defined PLATFORM_POSIX
114 inline double DiffProfPoints(const prof_point_t &start, const prof_point_t &end)
118 #if defined PLATFORM_WINDOWS
121 diff = end.value.QuadPart - start.value.QuadPart;
122 seconds = diff * WINDOWS_PERFORMANCE_FREQUENCY;
123 #elif defined PLATFORM_POSIX
124 seconds = (double)(end.value.tv_sec - start.value.tv_sec);
126 if (start.value.tv_usec > after.value.tv_usec)
129 seconds += (double)(1000000 - (before.value.tv_usec - after.tv_usec)) / 1000000.0;
133 seconds += (double)(after.value.tv_usec - before.value.tv_usec) / 1000000.0;
140 inline double CalcAtomTime(const prof_atom_t &atom)
142 if (!atom.end.is_set)
144 return atom.base_time;
147 return atom.base_time + DiffProfPoints(atom.start, atom.end);
150 void ProfileEngine::OnNativeBegin(IPluginContext *pContext, sp_native_t *native)
152 PushProfileStack(pContext, SP_PROF_NATIVES, native->name);
155 void ProfileEngine::OnNativeEnd()
157 assert(!m_AtomStack.empty());
158 assert(m_AtomStack.front().atom_type == SP_PROF_NATIVES);
160 PopProfileStack(&m_Natives);
163 void ProfileEngine::OnFunctionBegin(IPluginContext *pContext, const char *name)
165 PushProfileStack(pContext, SP_PROF_FUNCTIONS, name);
168 void ProfileEngine::OnFunctionEnd()
170 assert(!m_AtomStack.empty());
171 assert(m_AtomStack.front().atom_type == SP_PROF_FUNCTIONS);
173 PopProfileStack(&m_Functions);
176 int ProfileEngine::OnCallbackBegin(IPluginContext *pContext, sp_public_t *pubfunc)
178 PushProfileStack(pContext, SP_PROF_CALLBACKS, pubfunc->name);
183 void ProfileEngine::OnCallbackEnd(int serial)
185 assert(!m_AtomStack.empty());
188 * Account for the situation where the JIT discards the
189 * stack because there was an RTE of sorts.
191 if (m_AtomStack.front().atom_type != SP_PROF_CALLBACKS
192 && m_AtomStack.front().atom_serial != serial)
197 /* There was an error, and we need to discard things. */
199 while (!m_AtomStack.empty()
200 && m_AtomStack.front().atom_type != SP_PROF_CALLBACKS
201 && m_AtomStack.front().atom_serial != serial)
203 total_time += CalcAtomTime(m_AtomStack.front());
208 * Now we can end and discard ourselves, without saving the data.
209 * Since this data is all erroneous anyway, we don't care if it's
210 * not totally accurate.
213 assert(!m_AtomStack.empty());
214 atom = m_AtomStack.front();
217 /* Note: We don't need to resume ourselves because end is set by Pause(). */
218 total_time += CalcAtomTime(atom);
220 ResumeParent(total_time);
224 PopProfileStack(&m_Callbacks);
227 void ProfileEngine::PushProfileStack(IPluginContext *ctx, int type, const char *name)
233 atom.atom_type = type;
234 atom.base_time = 0.0;
235 atom.ctx = ctx->GetContext();
237 atom.end.is_set = false;
239 if (type == SP_PROF_CALLBACKS)
241 atom.atom_serial = ++m_serial;
245 atom.atom_serial = 0;
248 m_AtomStack.push(atom);
250 /* Note: We do this after because the stack could grow and skew results */
251 InitProfPoint(m_AtomStack.front().start);
254 void ProfileEngine::PopProfileStack(ProfileReport *reporter)
258 prof_atom_t &atom = m_AtomStack.front();
260 /* We're okay to cache our used time. */
261 InitProfPoint(atom.end);
262 total_time = CalcAtomTime(atom);
264 /* Now it's time to save this! This may do a lot of computations which
265 * is why we've cached the time beforehand.
267 reporter->SaveAtom(atom);
270 /* Finally, tell our parent how much time we used. */
271 ResumeParent(total_time);
274 void ProfileEngine::PauseParent()
276 if (m_AtomStack.empty())
281 InitProfPoint(m_AtomStack.front().end);
284 void ProfileEngine::ResumeParent(double addTime)
286 if (m_AtomStack.empty())
291 prof_atom_t &atom = m_AtomStack.front();
293 /* Move its "paused time" to its base (known) time,
294 * then reset the start/end. Note that since CalcAtomTime()
295 * reads the base time, we SHOULD NOT use += to add.
297 atom.base_time = CalcAtomTime(atom);
298 atom.base_time += addTime;
299 InitProfPoint(atom.start);
300 atom.end.is_set = false;
303 void ProfileEngine::Clear()
308 InitProfPoint(m_ProfStart);
311 void ProfileEngine::OnSourceModAllInitialized()
313 g_RootMenu.AddRootConsoleCommand("profiler", "Profiler commands", this);
316 void ProfileEngine::OnSourceModShutdown()
318 g_RootMenu.RemoveRootConsoleCommand("profiler", this);
321 void ProfileEngine::OnRootConsoleCommand(const char *cmdname, const CCommand &command)
323 if (command.ArgC() >= 3)
325 if (strcmp(command.Arg(2), "flush") == 0)
330 g_SourceMod.BuildPath(Path_SM, path, sizeof(path), "logs/profile_%d.xml", (int)time(NULL));
332 if ((fp = fopen(path, "wt")) == NULL)
334 g_RootMenu.ConsolePrint("Failed, could not open file for writing: %s", path);
342 g_RootMenu.ConsolePrint("Profiler report generated as: %s\n", path);
348 g_RootMenu.ConsolePrint("Profiler commands:");
349 g_RootMenu.DrawGenericOption("flush", "Flushes statistics to disk and starts over");
352 bool ProfileEngine::GenerateReport(FILE *fp)
356 prof_point_t end_time;
358 InitProfPoint(end_time);
359 total_time = DiffProfPoints(m_ProfStart, end_time);
363 fprintf(fp, "<?xml version=\"1.0\" encoding=\"UTF-8\"?>\n\n");
364 fprintf(fp, "<profile time=\"%d\" uptime=\"%f\">\n", (int)t, total_time);
365 WriteReport(fp, &m_Natives, "natives");
366 WriteReport(fp, &m_Callbacks, "callbacks");
367 WriteReport(fp, &m_Functions, "functions");
368 fprintf(fp, "</profile>\n");
373 void ProfileEngine::WriteReport(FILE *fp, ProfileReport *report, const char *name)
376 prof_atom_report_t *ar;
379 fprintf(fp, " <report name=\"%s\">\n", name);
381 num = report->GetNumReports();
382 for (i = 0; i < num; i++)
384 ar = report->GetReport(i);
386 strncopy(new_name, ar->atom_name, sizeof(new_name));
387 UTIL_ReplaceAll(new_name, sizeof(new_name), "<", "<");
388 UTIL_ReplaceAll(new_name, sizeof(new_name), ">", ">");
390 fprintf(fp, " <item name=\"%s\" numcalls=\"%d\" mintime=\"%f\" maxtime=\"%f\" totaltime=\"%f\"/>\n",
398 fprintf(fp, " </report>\n");
401 ProfileReport::~ProfileReport()
403 for (size_t i = 0; i < m_Reports.size(); i++)
409 void ProfileReport::Clear()
411 m_ReportLookup.clear();
412 for (size_t i = 0; i < m_Reports.size(); i++)
419 size_t ProfileReport::GetNumReports()
421 return m_Reports.size();
424 prof_atom_report_t *ProfileReport::GetReport(size_t i)
429 void ProfileReport::SaveAtom(const prof_atom_t &atom)
433 prof_atom_report_t **pReport, *report;
435 if (atom.atom_type == SP_PROF_NATIVES)
437 strncopy(full_name, atom.name, sizeof(full_name));
445 if ((pl = g_PluginSys.GetPluginByCtx(atom.ctx)) != NULL)
447 file = pl->GetFilename();
450 UTIL_Format(full_name, sizeof(full_name), "%s!%s", file, atom.name);
453 atom_time = CalcAtomTime(atom);
455 if ((pReport = m_ReportLookup.retrieve(full_name)) == NULL)
457 report = new prof_atom_report_t;
459 strncopy(report->atom_name, full_name, sizeof(report->atom_name));
460 report->max_time = atom_time;
461 report->min_time = atom_time;
462 report->num_calls = 1;
463 report->total_time = atom_time;
465 m_ReportLookup.insert(full_name, report);
466 m_Reports.push_back(report);
472 if (atom_time > report->max_time)
474 report->max_time = atom_time;
476 if (atom_time < report->min_time)
478 report->min_time = atom_time;
481 report->total_time += atom_time;