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>
40 ProfileEngine g_Profiler;
41 IProfiler *sm_profiler = &g_Profiler;
43 #if defined PLATFORM_WINDOWS
44 double WINDOWS_PERFORMANCE_FREQUENCY;
47 class EmptyProfiler : public IProfiler
50 void OnNativeBegin(IPluginContext *pContext, sp_native_t *native)
56 void OnFunctionBegin(IPluginContext *pContext, const char *name)
62 int OnCallbackBegin(IPluginContext *pContext, sp_public_t *pubfunc)
66 void OnCallbackEnd(int serial)
71 inline void InitProfPoint(prof_point_t &pt)
73 #if defined PLATFORM_WINDOWS
74 QueryPerformanceCounter(&pt.value);
75 #elif defined PLATFORM_POSIX
76 gettimeofday(&pt.value, NULL);
81 ProfileEngine::ProfileEngine()
85 #if defined PLATFORM_WINDOWS
88 if (QueryPerformanceFrequency(&pf))
90 WINDOWS_PERFORMANCE_FREQUENCY = 1.0 / (double)(pf.QuadPart);
94 WINDOWS_PERFORMANCE_FREQUENCY = -1.0;
100 InitProfPoint(m_ProfStart);
104 sm_profiler = &s_EmptyProfiler;
108 bool ProfileEngine::IsEnabled()
110 #if defined PLATFORM_WINDOWS
111 return (WINDOWS_PERFORMANCE_FREQUENCY > 0.0);
112 #elif defined PLATFORM_POSIX
117 inline double DiffProfPoints(const prof_point_t &start, const prof_point_t &end)
121 #if defined PLATFORM_WINDOWS
124 diff = end.value.QuadPart - start.value.QuadPart;
125 seconds = diff * WINDOWS_PERFORMANCE_FREQUENCY;
126 #elif defined PLATFORM_POSIX
127 seconds = (double)(end.value.tv_sec - start.value.tv_sec);
129 if (start.value.tv_usec > end.value.tv_usec)
132 seconds += (double)(1000000 - (start.value.tv_usec - end.value.tv_usec)) / 1000000.0;
136 seconds += (double)(end.value.tv_usec - start.value.tv_usec) / 1000000.0;
143 inline double CalcAtomTime(const prof_atom_t &atom)
145 if (!atom.end.is_set)
147 return atom.base_time;
150 return atom.base_time + DiffProfPoints(atom.start, atom.end);
153 void ProfileEngine::OnNativeBegin(IPluginContext *pContext, sp_native_t *native)
155 PushProfileStack(pContext, SP_PROF_NATIVES, native->name);
158 void ProfileEngine::OnNativeEnd()
160 assert(!m_AtomStack.empty());
161 assert(m_AtomStack.front().atom_type == SP_PROF_NATIVES);
163 PopProfileStack(&m_Natives);
166 void ProfileEngine::OnFunctionBegin(IPluginContext *pContext, const char *name)
168 PushProfileStack(pContext, SP_PROF_FUNCTIONS, name);
171 void ProfileEngine::OnFunctionEnd()
173 assert(!m_AtomStack.empty());
174 assert(m_AtomStack.front().atom_type == SP_PROF_FUNCTIONS);
176 PopProfileStack(&m_Functions);
179 int ProfileEngine::OnCallbackBegin(IPluginContext *pContext, sp_public_t *pubfunc)
181 PushProfileStack(pContext, SP_PROF_CALLBACKS, pubfunc->name);
186 void ProfileEngine::OnCallbackEnd(int serial)
188 assert(!m_AtomStack.empty());
191 * Account for the situation where the JIT discards the
192 * stack because there was an RTE of sorts.
194 if (m_AtomStack.front().atom_type != SP_PROF_CALLBACKS
195 && m_AtomStack.front().atom_serial != serial)
200 /* There was an error, and we need to discard things. */
202 while (!m_AtomStack.empty()
203 && m_AtomStack.front().atom_type != SP_PROF_CALLBACKS
204 && m_AtomStack.front().atom_serial != serial)
206 total_time += CalcAtomTime(m_AtomStack.front());
211 * Now we can end and discard ourselves, without saving the data.
212 * Since this data is all erroneous anyway, we don't care if it's
213 * not totally accurate.
216 assert(!m_AtomStack.empty());
217 atom = m_AtomStack.front();
220 /* Note: We don't need to resume ourselves because end is set by Pause(). */
221 total_time += CalcAtomTime(atom);
223 ResumeParent(total_time);
227 PopProfileStack(&m_Callbacks);
230 void ProfileEngine::PushProfileStack(IPluginContext *ctx, int type, const char *name)
236 atom.atom_type = type;
237 atom.base_time = 0.0;
238 atom.ctx = ctx->GetContext();
240 atom.end.is_set = false;
242 if (type == SP_PROF_CALLBACKS)
244 atom.atom_serial = ++m_serial;
248 atom.atom_serial = 0;
251 m_AtomStack.push(atom);
253 /* Note: We do this after because the stack could grow and skew results */
254 InitProfPoint(m_AtomStack.front().start);
257 void ProfileEngine::PopProfileStack(ProfileReport *reporter)
261 prof_atom_t &atom = m_AtomStack.front();
263 /* We're okay to cache our used time. */
264 InitProfPoint(atom.end);
265 total_time = CalcAtomTime(atom);
267 /* Now it's time to save this! This may do a lot of computations which
268 * is why we've cached the time beforehand.
270 reporter->SaveAtom(atom);
273 /* Finally, tell our parent how much time we used. */
274 ResumeParent(total_time);
277 void ProfileEngine::PauseParent()
279 if (m_AtomStack.empty())
284 InitProfPoint(m_AtomStack.front().end);
287 void ProfileEngine::ResumeParent(double addTime)
289 if (m_AtomStack.empty())
294 prof_atom_t &atom = m_AtomStack.front();
296 /* Move its "paused time" to its base (known) time,
297 * then reset the start/end. Note that since CalcAtomTime()
298 * reads the base time, we SHOULD NOT use += to add.
300 atom.base_time = CalcAtomTime(atom);
301 atom.base_time += addTime;
302 InitProfPoint(atom.start);
303 atom.end.is_set = false;
306 void ProfileEngine::Clear()
311 InitProfPoint(m_ProfStart);
314 void ProfileEngine::OnSourceModAllInitialized()
316 rootmenu->AddRootConsoleCommand2("profiler", "Profiler commands", this);
319 void ProfileEngine::OnSourceModShutdown()
321 rootmenu->RemoveRootConsoleCommand("profiler", this);
324 void ProfileEngine::OnRootConsoleCommand2(const char *cmdname, const ICommandArgs *command)
326 if (command->ArgC() >= 3)
328 if (strcmp(command->Arg(2), "flush") == 0)
333 g_pSM->BuildPath(Path_SM, path, sizeof(path), "logs/profile_%d.xml", (int)time(NULL));
335 if ((fp = fopen(path, "wt")) == NULL)
337 rootmenu->ConsolePrint("Failed, could not open file for writing: %s", path);
345 rootmenu->ConsolePrint("Profiler report generated as: %s\n", path);
351 rootmenu->ConsolePrint("Profiler commands:");
352 rootmenu->DrawGenericOption("flush", "Flushes statistics to disk and starts over");
355 bool ProfileEngine::GenerateReport(FILE *fp)
359 prof_point_t end_time;
361 InitProfPoint(end_time);
362 total_time = DiffProfPoints(m_ProfStart, end_time);
366 fprintf(fp, "<?xml version=\"1.0\" encoding=\"UTF-8\"?>\n\n");
367 fprintf(fp, "<profile time=\"%d\" uptime=\"%f\">\n", (int)t, total_time);
368 WriteReport(fp, &m_Natives, "natives");
369 WriteReport(fp, &m_Callbacks, "callbacks");
370 WriteReport(fp, &m_Functions, "functions");
371 fprintf(fp, "</profile>\n");
376 void ProfileEngine::WriteReport(FILE *fp, ProfileReport *report, const char *name)
379 prof_atom_report_t *ar;
382 fprintf(fp, " <report name=\"%s\">\n", name);
384 num = report->GetNumReports();
385 for (i = 0; i < num; i++)
387 ar = report->GetReport(i);
389 smcore.strncopy(new_name, ar->atom_name, sizeof(new_name));
390 smcore.ReplaceAll(new_name, sizeof(new_name), "<", "<", true);
391 smcore.ReplaceAll(new_name, sizeof(new_name), ">", ">", true);
393 fprintf(fp, " <item name=\"%s\" numcalls=\"%d\" mintime=\"%f\" maxtime=\"%f\" totaltime=\"%f\"/>\n",
401 fprintf(fp, " </report>\n");
404 ProfileReport::~ProfileReport()
406 for (size_t i = 0; i < m_Reports.size(); i++)
412 void ProfileReport::Clear()
414 m_ReportLookup.clear();
415 for (size_t i = 0; i < m_Reports.size(); i++)
422 size_t ProfileReport::GetNumReports()
424 return m_Reports.size();
427 prof_atom_report_t *ProfileReport::GetReport(size_t i)
432 void ProfileReport::SaveAtom(const prof_atom_t &atom)
436 prof_atom_report_t **pReport, *report;
438 if (atom.atom_type == SP_PROF_NATIVES)
440 smcore.strncopy(full_name, atom.name, sizeof(full_name));
448 if ((pl = pluginsys->FindPluginByContext(atom.ctx)) != NULL)
450 file = pl->GetFilename();
453 smcore.Format(full_name, sizeof(full_name), "%s!%s", file, atom.name);
456 atom_time = CalcAtomTime(atom);
458 if ((pReport = m_ReportLookup.retrieve(full_name)) == NULL)
460 report = new prof_atom_report_t;
462 smcore.strncopy(report->atom_name, full_name, sizeof(report->atom_name));
463 report->max_time = atom_time;
464 report->min_time = atom_time;
465 report->num_calls = 1;
466 report->total_time = atom_time;
468 m_ReportLookup.insert(full_name, report);
469 m_Reports.push_back(report);
475 if (atom_time > report->max_time)
477 report->max_time = atom_time;
479 if (atom_time < report->min_time)
481 report->min_time = atom_time;
484 report->total_time += atom_time;