TimeLogger.java - for checking what slows down the game

Any community contributions to libgdx go here! Some may get included in the core API when permission is granted.

TimeLogger.java - for checking what slows down the game

Postby Magnesus » Wed Apr 16, 2014 8:42 am

A simple class I wrote for myself that logs what causes slow downs in my game - basically it calculates how long different parts of the game execute. It is designed for games working at constant FPS. Keep in mind that it was supposed to be my internal code so it's not pretty, works though and helped me a lot in optimising my games.

How to use:
1. Put at the beginning: TimeLogger.log = true; TimeLogger.gather = 240; // turns on logging and sets that it will average the results for 240 frames.
2. Put at the beginning of your game loop: TimeLogger.timeStart();
3. Put anywhere, to measure difference in time between last point and the current: TimeLogger.timeLog("JustFinishedDrawing");
4. To count how many times some event was executed add for example: TimeLogger.gatherEventCount("DROPPED FRAME");

When TimeLogger.gather is set to 1 it will just show results for each frame. It's better to set it for a greater value to get averaged result. The results are in milliseconds.
This line in logs: *** AVERAGE FRAME: 28.26667 - shows how many ms on average each frame executed - this value shows that the game is far too slow (16ms is for 60FPS), now you can find what took the most time. In my case it was afterPhysicsTick: 18.079166ms - far too long, I have to optimise the physics. :)

Example:
Code: Select all
TimeLogger.timeStart();
stage.act(1);
TimeLogger.timeLog("JustFinishedActing");
if(droppedFrame)
    TimeLogger.gatherEventCount("DROPPED FRAME");
stage.draw();
TimeLogger.timeLog("JustFinishedDrawing");
phys.tick();
TimeLogger.timeLog("JustFinishedPhysics");


Source code:

Code: Select all
package magory.lib;

import java.util.LinkedHashMap;

import com.badlogic.gdx.Gdx;

public class TimeLogger
{
   public static boolean log = false;
   public static long gatherFor = 1; // how many frames before logging
   public static long starttime;
   public static long gatherStart;
   private static LinkedHashMap<String, Long> times = new LinkedHashMap<String, Long>();
   private static LinkedHashMap<String, Long> counts = new LinkedHashMap<String, Long>();
   private static long currentFrame = 0;
   public static int nrLog = 0;
   
   public static void timeStart()
   {      
      if(log)
      {
         if(gatherFor==1)
         {
            starttime = System.currentTimeMillis();
            Gdx.app.log("timeLog", "start."+starttime);
         }
         else
         {
            gatherStart();
            starttime = System.currentTimeMillis();            
         }
      }
   }
   
   public static void gatherEventCount(String str)
   {
      String nrLogStr = "COUNT . ";
      if(times.containsKey(nrLogStr+str))
      {
         times.put(nrLogStr+str, times.get(nrLogStr+str)+1);
      }
      else
      {
         times.put(nrLogStr+str, 1l);
      }
   }
   
   public static void timeLog(String str)
   {
      if(log)
      {
         if(gatherFor==1)
            Gdx.app.log("timeLog", str+":"+(System.currentTimeMillis()-starttime));
         else
            gatherLog(str);
      }
   }
   
   public static void gatherLog(String str)
   {
      long time = System.currentTimeMillis()-starttime;
      String nrLogStr = ""+nrLog+" . ";
      if(nrLog<10)
         nrLogStr = "0"+nrLog+" . ";
      if(times.containsKey(nrLogStr+str))
      {
         times.put(nrLogStr+str, times.get(nrLogStr+str)+time);
      }
      else
      {
         times.put(nrLogStr+str, time);
      }
      starttime = System.currentTimeMillis();
      nrLog++;
   }
   
   public static void gatherPrintSummary()
   {
      float now = (System.currentTimeMillis()-gatherStart)/(float)gatherFor;
      Gdx.app.log("timeLog", "*** AVERAGE FRAME: "+now);
      float sum = 0;
      for(String key : times.keySet())
      {
         if(key.startsWith("COUNT"))
         {
            Gdx.app.log("timeLog", key+": "+times.get(key)/(float)gatherFor);
         }
         else
         {
            Gdx.app.log("timeLog", key+": "+times.get(key)/(float)gatherFor);
            sum+=times.get(key)/(float)gatherFor;
         }
      }
      Gdx.app.log("timeLog", "SUM: "+sum);
   }
   
   public static void gatherStart()
   {
      nrLog = 0;
      if(currentFrame>gatherFor)
      {
         gatherPrintSummary();
         times.clear();
         currentFrame = 0;      
         gatherStart = System.currentTimeMillis();
      }      
      currentFrame++;      
   }

}
Magnesus
 
Posts: 1537
Joined: Sun Sep 25, 2011 3:50 pm

Re: TimeLogger.java - for checking what slows down the game

Postby Djal » Mon Apr 21, 2014 11:51 am

Thank you!
Djal
 
Posts: 104
Joined: Wed Mar 02, 2011 11:26 am
Location: Paris, France

Re: TimeLogger.java - for checking what slows down the game

Postby dangelobr » Fri Mar 11, 2016 4:19 pm

Hello,

First of all I would like to thanks, Time Logger helped me a lot.
Just like to understand a little better time scales.
In the example below I put

public void render (float delta) {

TimeLogger.log = true;
TimeLogger.gatherFor = 60;
TimeLogger.timeStart ();

// Render All stufs.

TimeLogger.timeLog ("All Render");

}

Result:
TimeLog: *** AVERAGE FRAME: 16.933332 // Here are ms, 60FPS
TimeLog: 00. ½ Render: 0.31666666 // This time is in s or ms?
TimeLog: SUM: 0.31666666 // This time is in s or ms?

Is there a way to use that Time Logger on the Android?
dangelobr
 
Posts: 19
Joined: Thu Sep 24, 2015 10:38 am

Re: TimeLogger.java - for checking what slows down the game

Postby Magnesus » Fri Mar 11, 2016 8:46 pm

Hard question because I wrote that so long ago and use it so rarely, I don't remember how it works. :oops:
It works on Android too - you can see results in LogCat. From looking at that (ugly, ulgy) code of mine it seems to be in ms. But the result is clearly wrong because the sum should be 60 times the average.... unless you stop after one frame or something.
Are you using fixed frame rate? Because it won't work with variable frame rate.
Magnesus
 
Posts: 1537
Joined: Sun Sep 25, 2011 3:50 pm


Return to Libgdx Contributions

Who is online

Users browsing this forum: No registered users and 3 guests