Backport some CON profiling stuff from Lunatic. Use "printtimes" in the console.

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

source/duke3d/src/actors.cpp

@@ -8337,7 +8337,8 @@ static void G_DoEventGame(int const nEventID)
 
 void G_MoveWorld(void)
 {
-    extern double g_moveActorsTime;
+    extern double g_moveActorsTime, g_moveWorldTime;
+    const double worldTime = gethiticks();
 
     VM_OnEvent(EVENT_PREWORLD, -1, -1);
 
@@ -8351,11 +8352,11 @@ void G_MoveWorld(void)
     G_MoveFallers();          //ST 12
     G_MoveMisc();             //ST 5
 
-    double t = gethiticks();
+    const double actorsTime = gethiticks();
 
     G_MoveActors();           //ST 1
 
-    g_moveActorsTime = (1-0.033)*g_moveActorsTime + 0.033*(gethiticks()-t);
+    g_moveActorsTime = (1-0.033)*g_moveActorsTime + 0.033*(gethiticks()-actorsTime);
 
     // XXX: Has to be before effectors, in particular movers?
     // TODO: lights in moving sectors ought to be interpolated
@@ -8371,4 +8372,6 @@ void G_MoveWorld(void)
     G_RefreshLights();
     G_DoSectorAnimations();
     G_MoveFX();               //ST 11
+
+    g_moveWorldTime = (1-0.033)*g_moveWorldTime + 0.033*(gethiticks()-worldTime);
 }

source/duke3d/src/game.cpp

@@ -5646,15 +5646,19 @@ static void G_CompileScripts(void)
     {
         char *newlabel;
         int32_t *newlabelcode;
+        int32_t *newlabeltype;
 
-        newlabel     = (char *)Xmalloc(g_labelCnt<<6);
+        newlabel     = (char *)Xmalloc(g_labelCnt << 6);
-        newlabelcode = (int32_t *)Xmalloc(g_labelCnt*sizeof(int32_t));
+        newlabelcode = (int32_t *)Xmalloc(g_labelCnt * sizeof(int32_t));
+        newlabeltype = (int32_t *)Xmalloc(g_labelCnt * sizeof(int32_t));
 
         Bmemcpy(newlabel, label, g_labelCnt*64);
         Bmemcpy(newlabelcode, labelcode, g_labelCnt*sizeof(int32_t));
+        Bmemcpy(newlabeltype, labeltype, g_labelCnt*sizeof(int32_t));
 
         label = newlabel;
         labelcode = newlabelcode;
+        labeltype = newlabeltype;
     }
 
     Bmemset(sprite, 0, MAXSPRITES*sizeof(spritetype));

source/duke3d/src/gamedef.cpp

@@ -73,17 +73,6 @@ int32_t g_errorCnt,g_warningCnt;
 
 extern int32_t g_maxSoundPos;
 
-enum
-{
-    LABEL_ANY    = -1,
-    LABEL_DEFINE = 1,
-    LABEL_STATE  = 2,
-    LABEL_ACTOR  = 4,
-    LABEL_ACTION = 8,
-    LABEL_AI     = 16,
-    LABEL_MOVE   = 32,
-};
-
 #if !defined LUNATIC
 static char *C_GetLabelType(int32_t type)
 {
@@ -6503,8 +6492,11 @@ void C_Compile(const char *fileName)
     Bmemset(apScriptEvents, 0, sizeof(apScriptEvents));
     Bmemset(apScriptGameEventEnd, 0, sizeof(apScriptGameEventEnd));
 
-    for (int i=MAXTILES-1; i>=0; i--)
+    for (int i=0; i<MAXTILES; i++)
+    {
         Bmemset(&g_tile[i], 0, sizeof(tiledata_t));
+        g_actorMinMs[i] = 1e308;
+    }
 
     C_InitHashes();
     Gv_Init();

source/duke3d/src/gamedef.h

@@ -31,6 +31,17 @@ Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA  02110-1301, USA.
 extern "C" {
 #endif
 
+enum
+{
+    LABEL_ANY    = -1,
+    LABEL_DEFINE = 1,
+    LABEL_STATE  = 2,
+    LABEL_ACTOR  = 4,
+    LABEL_ACTION = 8,
+    LABEL_AI     = 16,
+    LABEL_MOVE   = 32,
+};
+
 #define LABEL_HASPARM2  1
 #define LABEL_ISSTRING  2
 

source/duke3d/src/gameexec.cpp

@@ -71,6 +71,10 @@ int32_t g_textureVarID   = -1;  // var ID of "TEXTURE"
 int32_t g_thisActorVarID = -1;  // var ID of "THISACTOR"
 int32_t g_structVarIDs   = -1;
 
+// for timing events and actors
+uint32_t g_eventCalls[MAXEVENTS], g_actorCalls[MAXTILES];
+double g_eventTotalMs[MAXEVENTS], g_actorTotalMs[MAXTILES], g_actorMinMs[MAXTILES], g_actorMaxMs[MAXTILES];
+
 GAMEEXEC_STATIC void VM_Execute(int loop);
 
 # include "gamestructures.cpp"
@@ -166,6 +170,8 @@ static void VM_DummySprite(void)
 static FORCE_INLINE int32_t VM_EventCommon_(int const eventNum, int const spriteNum, int const playerNum,
                                      int const playerDist, int32_t returnValue)
 {
+    const double t = gethiticks();
+
     const vmstate_t tempvm = { spriteNum, playerNum, playerDist, 0, NULL, NULL, g_player[playerNum].ps, NULL };
 
     int const backupReturnVar = aGameVars[g_returnVarID].global;
@@ -209,6 +215,9 @@ static FORCE_INLINE int32_t VM_EventCommon_(int const eventNum, int const sprite
 
     aGameVars[g_returnVarID].global  = backupReturnVar;
 
+    g_eventTotalMs[eventNum] += gethiticks()-t;
+    g_eventCalls[eventNum]++;
+
     return returnValue;
 }
 #endif
@@ -5893,9 +5902,17 @@ void A_Execute(int spriteNum, int playerNum, int playerDist)
         g_actorCalls[picnum]++;
     }
 #else
+    double t = gethiticks();
+    int const picnum = vm.pSprite->picnum;
     insptr = 4 + (g_tile[vm.pSprite->picnum].execPtr);
     VM_Execute(1);
     insptr = NULL;
+
+    t = gethiticks()-t;
+    g_actorTotalMs[picnum] += t;
+    g_actorMinMs[picnum] = min(g_actorMinMs[picnum], t);
+    g_actorMaxMs[picnum] = max(g_actorMaxMs[picnum], t);
+    g_actorCalls[picnum]++;
 #endif
 
 #ifdef LUNATIC

source/duke3d/src/gameexec.h

@@ -47,6 +47,9 @@ extern int32_t g_currentEventExec;
 void A_LoadActor(int32_t spriteNum);
 #endif
 
+extern uint32_t g_eventCalls[MAXEVENTS], g_actorCalls[MAXTILES];
+extern double g_eventTotalMs[MAXEVENTS], g_actorTotalMs[MAXTILES], g_actorMinMs[MAXTILES], g_actorMaxMs[MAXTILES];
+
 void A_Execute(int spriteNum, int playerNum, int playerDist);
 void A_Fall(int const spriteNum);
 int32_t A_GetFurthestAngle(int const spriteNum, int const angDiv);

source/duke3d/src/lunatic/lunatic_game.cpp

@@ -50,8 +50,6 @@ int32_t g_RETURN;
 
 // for timing events and actors
 static int32_t g_timingInited = 0;
-uint32_t g_eventCalls[MAXEVENTS], g_actorCalls[MAXTILES];
-double g_eventTotalMs[MAXEVENTS], g_actorTotalMs[MAXTILES], g_actorMinMs[MAXTILES], g_actorMaxMs[MAXTILES];
 
 // Used as Lua registry key to the tweak_traceback_msg() function, set to 1 if
 // such a function has been registered.

source/duke3d/src/lunatic/lunatic_game.h

@@ -28,9 +28,6 @@ extern el_actor_t g_elActors[MAXTILES];
 
 extern int32_t g_elEventError;
 
-extern uint32_t g_eventCalls[MAXEVENTS], g_actorCalls[MAXTILES];
-extern double g_eventTotalMs[MAXEVENTS], g_actorTotalMs[MAXTILES], g_actorMinMs[MAXTILES], g_actorMaxMs[MAXTILES];
-
 // -- functions --
 void El_PrintTimes(void);
 

source/duke3d/src/osdcmds.cpp

@@ -852,6 +852,7 @@ void onvideomodechange(int32_t newmode)
     g_crosshairSum = -1;
 }
 
+#if !defined NETCODE_DISABLE
 static int32_t osdcmd_name(osdfuncparm_t const * const parm)
 {
     char namebuf[32];
@@ -876,7 +877,7 @@ static int32_t osdcmd_name(osdfuncparm_t const * const parm)
 
     return OSDCMD_OK;
 }
-
+#endif
 
 static int32_t osdcmd_button(osdfuncparm_t const * const parm)
 {
@@ -1265,6 +1266,7 @@ static int32_t osdcmd_inittimer(osdfuncparm_t const * const parm)
 }
 #endif
 
+#if !defined NETCODE_DISABLE
 static int32_t osdcmd_disconnect(osdfuncparm_t const * const UNUSED(parm))
 {
     UNREFERENCED_CONST_PARAMETER(parm);
@@ -1294,7 +1296,6 @@ static int32_t osdcmd_password(osdfuncparm_t const * const parm)
     return OSDCMD_OK;
 }
 
-#if !defined NETCODE_DISABLE
 static int32_t osdcmd_listplayers(osdfuncparm_t const * const parm)
 {
     ENetPeer *currentPeer;
@@ -1409,6 +1410,74 @@ static int32_t osdcmd_kickban(osdfuncparm_t const * const parm)
 }
 #endif
 
+static int32_t osdcmd_printtimes(osdfuncparm_t const * const UNUSED(parm))
+{
+    UNREFERENCED_CONST_PARAMETER(parm);
+
+    char buf[32];
+    int32_t maxlen = 0;
+    int32_t haveev=0, haveac=0;
+    const char nn = Bstrlen("EVENT_");
+
+    for (int i=0; i<MAXEVENTS; i++)
+    {
+        int32_t len = Bstrlen(EventNames[i]+nn);
+        Bassert(len < (int32_t)sizeof(buf));
+        maxlen = max(len, maxlen);
+    }
+
+    for (int i=0; i<MAXEVENTS; i++)
+        if (g_eventCalls[i])
+        {
+            int32_t n=Bsprintf(buf, "%s", EventNames[i]+nn);
+
+            if (!haveev)
+            {
+                haveev = 1;
+                OSD_Printf("\n  -- event times: [event]={ total calls, total time [ms], mean time/call [us] }\n");
+            }
+
+            for (; n<maxlen; n++)
+                buf[n] = ' ';
+            buf[maxlen] = 0;
+
+            OSD_Printf("  [%-26s]={ %8d, %10.3f, %10.3f },\n",
+                buf, g_eventCalls[i], g_eventTotalMs[i],
+                1000*g_eventTotalMs[i]/g_eventCalls[i]);
+        }
+
+    for (int i=0; i<MAXTILES; i++)
+        if (g_actorCalls[i])
+        {
+            if (!haveac)
+            {
+                haveac = 1;
+                OSD_Printf("\n  -- actor times: [tile]={ total calls, total time [ms], {min,mean,max} time/call [us] }\n");
+            }
+
+            buf[0] = 0;
+
+            for (int ii=0; ii<g_labelCnt; ii++)
+            {
+                if (labelcode[ii] == i && labeltype[ii] == LABEL_DEFINE)
+                {
+                    Bstrcpy(buf, label+(ii<<6));
+                    break;
+                }
+            }
+
+            if (!buf[0]) Bsprintf(buf, "%5d", i);
+
+            OSD_Printf("  [%-26s]={ %8d, %9.3f, %9.3f, %9.3f, %9.3f },\n",
+                buf, g_actorCalls[i], g_actorTotalMs[i],
+                1000*g_actorMinMs[i],
+                1000*g_actorTotalMs[i]/g_actorCalls[i],
+                1000*g_actorMaxMs[i]);
+        }
+
+    return OSDCMD_OK;
+}
+
 static int32_t osdcmd_cvar_set_game(osdfuncparm_t const * const parm)
 {
     int32_t r = osdcmd_cvar_set(parm);
@@ -1700,8 +1769,10 @@ int32_t registerosdcommands(void)
     OSD_RegisterFunction("cmenu","cmenu <#>: jumps to menu", osdcmd_cmenu);
     OSD_RegisterFunction("crosshaircolor","crosshaircolor: changes the crosshair color", osdcmd_crosshaircolor);
 
+#if !defined NETCODE_DISABLE
     OSD_RegisterFunction("connect","connect: connects to a multiplayer game", osdcmd_connect);
     OSD_RegisterFunction("disconnect","disconnect: disconnects from the local multiplayer game", osdcmd_disconnect);
+#endif
 
     for (i=0; i<NUMGAMEFUNCTIONS; i++)
     {
@@ -1736,10 +1807,18 @@ int32_t registerosdcommands(void)
     OSD_RegisterFunction("listplayers","listplayers: lists currently connected multiplayer clients", osdcmd_listplayers);
 #endif
     OSD_RegisterFunction("music","music E<ep>L<lev>: change music", osdcmd_music);
+
+#if !defined NETCODE_DISABLE
     OSD_RegisterFunction("name","name: change your multiplayer nickname", osdcmd_name);
+#endif
+
     OSD_RegisterFunction("noclip","noclip: toggles clipping mode", osdcmd_noclip);
 
+#if !defined NETCODE_DISABLE
     OSD_RegisterFunction("password","password: sets multiplayer game password", osdcmd_password);
+#endif
+
+    OSD_RegisterFunction("printtimes", "printtimes: prints VM timing statistics", osdcmd_printtimes);
 
     OSD_RegisterFunction("quicksave","quicksave: performs a quick save", osdcmd_quicksave);
     OSD_RegisterFunction("quickload","quickload: performs a quick load", osdcmd_quickload);

source/duke3d/src/screens.cpp

@@ -46,7 +46,7 @@ palette_t DefaultCrosshairColors = { 0, 0, 0, 0 };
 int32_t g_crosshairSum = -1;
 // yxaspect and viewingrange just before the 'main' drawrooms call
 int32_t dr_yxaspect, dr_viewingrange;
-double g_moveActorsTime = 0;  // in ms, smoothed
+double g_moveActorsTime, g_moveWorldTime;  // in ms, smoothed
 int32_t g_noLogoAnim = 0;
 int32_t g_noLogo = 0;
 
@@ -685,6 +685,8 @@ static void G_PrintCoords(int32_t snum)
     printext256(x, y+72, COLOR_WHITE, -1, tempbuf, 0);
     Bsprintf(tempbuf, "MOVEACTORS [ms]= %.3e", g_moveActorsTime);
     printext256(x, y+81, COLOR_WHITE, -1, tempbuf, 0);
+    Bsprintf(tempbuf, "MOVEWORLD [ms]= %.3e", g_moveWorldTime);
+    printext256(x, y+90, COLOR_WHITE, -1, tempbuf, 0);
 
 #ifdef USE_OPENGL
     if (ud.coords == 2)