Lunatic: time every event and actor call and print summary at game exit.

git-svn-id: https://svn.eduke32.com/eduke32@2842 1a8010ca-5511-0410-912e-c29ae57300e0

polymer/eduke32/build/include/baselayer.h

@@ -144,6 +144,7 @@ uint32_t getticks(void);
 int32_t gettimerfreq(void);
 uint64_t gethiticks(void);
 uint64_t gethitickspersec(void);
+double gethitickms(void);  // TODO: Windows
 void (*installusertimercallback(void (*callback)(void)))(void);
 
 int32_t checkvideomode(int32_t *x, int32_t *y, int32_t c, int32_t fs, int32_t forced);

polymer/eduke32/source/game.c

@@ -2086,6 +2086,9 @@ extern int32_t g_doQuickSave;
 
 void G_GameExit(const char *msg)
 {
+#ifdef LUNATIC
+    El_PrintTimes();
+#endif
     if (*msg != 0) g_player[myconnectindex].ps->palette = BASEPAL;
 
     if (ud.recstat == 1) G_CloseDemoWrite();

polymer/eduke32/source/gameexec.c

@@ -97,6 +97,8 @@ void VM_ScriptInfo(void)
 int32_t VM_OnEvent(int32_t iEventID, int32_t iActor, int32_t iPlayer, int32_t lDist, int32_t iReturn)
 {
 #ifdef LUNATIC
+    const double t = gethitickms();
+
     if (El_IsInitialized(&g_ElState) && El_HaveEvent(iEventID))
         El_CallEvent(&g_ElState, iEventID, iActor, iPlayer, lDist);
 #endif
@@ -140,6 +142,10 @@ int32_t VM_OnEvent(int32_t iEventID, int32_t iActor, int32_t iPlayer, int32_t lD
         iReturn = aGameVars[g_iReturnVarID].val.lValue;
         aGameVars[g_iReturnVarID].val.lValue = backupReturnVar;
 
+#ifdef LUNATIC
+        g_eventTotalMs[iEventID] += gethitickms()-t;
+        g_eventCalls[iEventID]++;
+#endif
         return iReturn;
     }
 }
@@ -5025,6 +5031,9 @@ void A_LoadActor(int32_t iActor)
 // NORECURSE
 void A_Execute(int32_t iActor,int32_t iPlayer,int32_t lDist)
 {
+#ifdef LUNATIC
+    double t;
+#endif
     vmstate_t tempvm = { iActor, iPlayer, lDist, &actor[iActor].t_data[0],
                          &sprite[iActor], 0
                        };
@@ -5083,6 +5092,8 @@ void A_Execute(int32_t iActor,int32_t iPlayer,int32_t lDist)
     }
 
 #ifdef LUNATIC
+    t = gethitickms();
+
     if (El_IsInitialized(&g_ElState) && El_HaveActor(vm.g_sp->picnum))
         El_CallActor(&g_ElState, vm.g_sp->picnum, iActor, iPlayer, lDist);
 #endif
@@ -5091,6 +5102,11 @@ void A_Execute(int32_t iActor,int32_t iPlayer,int32_t lDist)
     VM_Execute(1);
     insptr = NULL;
 
+#ifdef LUNATIC
+    g_actorTotalMs[vm.g_sp->picnum] += gethitickms()-t;
+    g_actorCalls[vm.g_sp->picnum]++;
+#endif
+
     if (vm.g_flags & VM_KILL)
     {
         // if player was set to squish, first stop that...

polymer/eduke32/source/lunatic/defs.ilua

@@ -90,7 +90,8 @@ local gv_ = {
 
 local dummy_empty_table = {}
 
--- this is for declarations of arrays or pointers
+-- This is for declarations of arrays or pointers which should not be
+-- accessible through the gv global.
 -- NOTE: don't declare multiple pointers on one line (like int32_t *a, *b;)!
 local function decl(str)
     for varname in string.gmatch(str, "([%a_][%w_]*)[[(;]") do
@@ -806,7 +807,7 @@ local tmpmt = {
 }
 oG.setmetatable(wall, tmpmt)
 
--- create a safe indirection for a ffi.C array
+-- create a safe indirection for an ffi.C array
 local function creategtab(ctab, maxidx, name)
     local tab = {}
     local tmpmt = {

polymer/eduke32/source/lunatic/lunatic.c

@@ -23,6 +23,10 @@ uint8_t g_elActors[MAXTILES];
 // Lua-registry key for debug.traceback
 static uint8_t debug_traceback_key;
 
+// for timing events and actors
+uint32_t g_eventCalls[MAXEVENTS], g_actorCalls[MAXTILES];
+double g_eventTotalMs[MAXEVENTS], g_actorTotalMs[MAXTILES];
+
 
 // forward-decls...
 static int32_t SetEvent_luacf(lua_State *L);
@@ -31,6 +35,27 @@ static int32_t SetActor_luacf(lua_State *L);
 // in lpeg.o
 extern int luaopen_lpeg(lua_State *L);
 
+void El_PrintTimes(void)
+{
+    int32_t i;
+
+    OSD_Printf("{\n {\n");
+    OSD_Printf("  -- event times, [event]={ total calls, total time in ms, time per call in us }\n");
+    for (i=0; i<MAXEVENTS; i++)
+        if (g_eventCalls[i])
+            OSD_Printf("  [%2d]={ %8d, %9.3f, %9.3f },\n",
+                       i, g_eventCalls[i], g_eventTotalMs[i],
+                       1000*g_eventTotalMs[i]/g_eventCalls[i]);
+
+    OSD_Printf(" },\n\n {\n");
+    OSD_Printf("  -- actor times, [tile]={ total calls, total time in ms, time per call in us }\n");
+    for (i=0; i<MAXTILES; i++)
+        if (g_actorCalls[i])
+            OSD_Printf("  [%5d]={ %8d, %9.3f, %9.3f },\n",
+                       i, g_actorCalls[i], g_actorTotalMs[i],
+                       1000*g_actorTotalMs[i]/g_actorCalls[i]);
+    OSD_Printf(" },\n}\n");
+}
 
 static void check_and_register_function(lua_State *L, void *keyaddr)
 {

polymer/eduke32/source/lunatic/lunatic.h

@@ -17,7 +17,12 @@ typedef struct
 extern uint8_t g_elEvents[MAXEVENTS];  // shouldn't be used directly
 extern uint8_t g_elActors[MAXTILES];  // shouldn't be used directly
 
+extern uint32_t g_eventCalls[MAXEVENTS], g_actorCalls[MAXTILES];
+extern double g_eventTotalMs[MAXEVENTS], g_actorTotalMs[MAXTILES];
+
 // -- functions --
+void El_PrintTimes(void);
+
 int32_t El_CreateState(El_State *estate, const char *name);
 void El_DestroyState(El_State *estate);
 int32_t El_RunOnce(El_State *estate, const char *fn);