Recording Time associated with AppStates and ViewPorts

iwgeric · July 9, 2012, 5:07pm

Just sharing what I did in case anyone else had the same question about thier app or anyone has a better way.

I’m working on an app for Android and I was troubled because I didn’t understand where my framerate was going. I wanted to find out if the code I implemented in AppStates, Bullet physics processing, or the graphics I’m displaying was having the biggest impact.

Below are a couple patch files I made to log the amount of time spent in each of these areas. It includes time logging for the amount of time spent inside each of the method calls inside each AppState (update routine, render routine, and postRender routine), as well as the amount of time spent inside each of the major rendering processes for each active ViewPort (Processor PreFrame, Scene Rendering, Processor PostQueue, flushQueue, Processor PostFrame, TranslucentQueue, clearQueue).

It was actually very helpful to allow me to understand that Bullet is taking a lot more time when I have Mesh collision shapes vs a compound collision shape with multiple native shapes inside it. I didn’t know if the majority of the time was due to having multiple ViewPorts displayed or if it was due to Native Bullet taking a long time. As it turned out, the multiple ViewPorts have little effect, but the BulletAppState Render method was MUCH higher when using Mesh collision shapes.

As I said, I was just in a sharing mood today.

I display the data in simpleUpdate once every 5 sec (so not to bog down Android :)).

The output is in milliSeconds and looks something like this (I have a few AppStates and 4 ViewPorts) running on Android.

[java]

tpf: 0.047, Frames Per Second: 21.487, milliSeconds Per Frame: 46.539

AppState: com.jme3.app.ResetStatsState, Last Update Time: 0, Last Render Time: 0.025, Last PostRender Time: 0

AppState: com.jme3.bullet.BulletAppState, Last Update Time: 1.679, Last Render Time: 19.595, Last PostRender Time: 0

AppState: com.jme3.app.FlyCamAppState, Last Update Time: 0, Last Render Time: 0, Last PostRender Time: 0

AppState: com.interstatewebgroup.cubiclelife.hud.screens.ScreenManager, Last Update Time: 0.123, Last Render Time: 0, Last PostRender Time: 0

AppState: com.jme3.app.StatsAppState, Last Update Time: 0.025, Last Render Time: 0, Last PostRender Time: 0

AppState: com.interstatewebgroup.cubiclelife.hud.TwoSingleAxisJoySticks, Last Update Time: 0.025, Last Render Time: 0, Last PostRender Time: 0

AppState: com.interstatewebgroup.cubiclelife.world.World, Last Update Time: 0.033, Last Render Time: 0, Last PostRender Time: 0

AppState: com.jme3.app.DebugKeysAppState, Last Update Time: 0.033, Last Render Time: 0.033, Last PostRender Time: 0

ViewPort: NavStick Viewport, procPreFrameTime: 0.033, renderSceneTime: 0.123, procPostQueueTime: 0, flushQueueTime: 0.459, procPostFrameTime: 0, renderTranslucentQueueTime: 0, clearQueueTime: 0

ViewPort: Gui Default, procPreFrameTime: 0.033, renderSceneTime: 0.246, procPostQueueTime: 0.057, flushQueueTime: 4.309, procPostFrameTime: 0, renderTranslucentQueueTime: 0.025, clearQueueTime: 0

ViewPort: Default, procPreFrameTime: 0.033, renderSceneTime: 0.762, procPostQueueTime: 0, flushQueueTime: 13.853, procPostFrameTime: 0, renderTranslucentQueueTime: 0.033, clearQueueTime: 0

ViewPort: NavStick Viewport, procPreFrameTime: 0.025, renderSceneTime: 0.09, procPostQueueTime: 0, flushQueueTime: 0.336, procPostFrameTime: 0, renderTranslucentQueueTime: 0, clearQueueTime: 0

[/java]

simpleUpdate code to display the data:

[java]

timeElapsed += tpf;

numFrames++;

if (timeElapsed >= 5) {

logger.log(Level.INFO, “Elasped Time (sec): {0}, Number of Frames: {1}, Frames Per Second: {2}, milliSeconds Per Frame: {3}”,

new Object[]{timeElapsed, numFrames, numFrames/timeElapsed, (timeElapsed1000) / numFrames});

logger.log(Level.INFO, “tpf: {0}, Frames Per Second: {1}, milliSeconds Per Frame: {2}”,

new Object[]{tpf, 1/tpf, (tpf1000)});

for (AppStateManager.StateTimes stateTimes: stateManager.getStatesTimes()) {

logger.log(Level.INFO,

"AppState: {0}, "

"Last Update Time: {1}, "
"Last Render Time: {2}, "
"Last PostRender Time: {3}",

new Object[]{

stateTimes.getStateClass(),

stateTimes.getUpdateTime()*1000f,

stateTimes.getRenderTime()*1000f,

stateTimes.getPostRenderTime()*1000f

});

}

for (RenderManager.ViewPortRenderTimes renderTimes: renderManager.getViewPortRenderTimes()) {

logger.log(Level.INFO,

"ViewPort: {0}, "
"procPreFrameTime: {1}, "
"renderSceneTime: {2}, "
"procPostQueueTime: {3}, "
"flushQueueTime: {4}, "
"procPostFrameTime: {5}, "
"renderTranslucentQueueTime: {6}, "
"clearQueueTime: {7}",

new Object[]{

renderTimes.getViewPortName(),

renderTimes.getProcPreFrameTime()*1000f,

renderTimes.getRenderSceneTime()*1000f,

renderTimes.getProcPostQueueTime()*1000f,

renderTimes.getFlushQueueTime()*1000f,

renderTimes.getProcPostFrameTime()*1000f,

renderTimes.getRenderTranslucentQueueTime()*1000f,

renderTimes.getClearQueueTime()*1000f

});

}

numFrames = 0;

timeElapsed = 0;

}

[/java]

AppStateManager patch:

[java]

This patch file was generated by NetBeans IDE

Following Index: paths are relative to: D:UserspotterecDocumentsjMonkeyProjectsjME3srccorecomjme3appstate

This patch can be applied using context Tools: Patch action on respective folder.

It uses platform neutral UTF-8 encoding and n newlines.

Above lines and this line are ignored by the patching process.

Index: AppStateManager.java

— AppStateManager.java Base (BASE)

+++ AppStateManager.java Locally Modified (Based On LOCAL)

@@ -34,9 +34,16 @@

import com.jme3.app.Application;

import com.jme3.renderer.RenderManager;

+import com.jme3.system.Timer;

import com.jme3.util.SafeArrayList;

import java.util.Arrays;

+import java.util.Collection;

+import java.util.Collections;

import java.util.List;

+import java.util.Map;

+import java.util.concurrent.ConcurrentHashMap;

+import java.util.logging.Level;

+import java.util.logging.Logger;

/**

The <code>AppStateManager</code> holds a list of {@link AppState}s which

@@ -78,6 +85,67 @@

private final SafeArrayList<AppState> states = new SafeArrayList<AppState>(AppState.class);

/**

*  Class to hold the last update, render, and postRender times for an AppState.<br />

```
*/ 
```
public class StateTimes {

   String stateClass = &quot;&quot;;<br />

```
 float updateTime = 0f; 
```
```
 float renderTime = 0f; 
```
```
 float postRenderTime = 0f; 
```

+

   public StateTimes(String stateClass) {<br />

       this.stateClass = stateClass;<br />

```
 } 
```

+

   public String getStateClass() {<br />

```
 return stateClass; 
```
```
 } 
```

   public float getUpdateTime() {<br />

```
 return updateTime; 
```
```
 } 
```

   public float getRenderTime() {<br />

```
 return renderTime; 
```
```
 } 
```

   public float getPostRenderTime() {<br />

```
 return postRenderTime; 
```
```
 } 
```
}

+
/**

*  Internal Map for the last times for each active AppState.<br />

```
*/ 
```
private Map<AppState, StateTimes> stateTimes = new ConcurrentHashMap<AppState, StateTimes>();

+
// logStateTimes enables the time logging for each AppState (timer must also be set using setTimer(Timer timer)
private boolean logStateTimes = false;
private Timer timer = null;

+
/**

* Enables/Disables time logging for AppStates.  timer must also be set<br />

* @param enable When True, time for each stage of the AppState is logged.<br />

```
*/ 
```
public void setStateTimeLogging(boolean enable) {
```
 logStateTimes = enable; 
```
}

+
/**

* Sets the timer implementation to use to record times<br />

* @param timer Timer implentation to use<br />

```
*/ 
```
public void setTimer(Timer timer) {
```
 this.timer = timer; 
```
}

+
/**

* Retrieve the last times for each AppState<br />

* @return Collection of times for each ViewPort<br />

```
*/ 
```
public Collection<StateTimes> getStatesTimes(){

   return Collections.unmodifiableCollection(stateTimes.values());<br />

}

+

+
/**

List holding the detached app states that are pending
cleanup.

*/

@@ -145,6 +213,7 @@

if (states.contains(state)){

state.stateDetached(this);

states.remove(state);

           stateTimes.remove(state);<br />

terminating.add(state);

return true;

} else if(initializing.contains(state)){

@@ -213,6 +282,9 @@

// did it after then it couldn’t.

List<AppState> transfer = Arrays.asList(array);

states.addAll(transfer);

       for (AppState appState: transfer) {<br />

           stateTimes.put(appState, new StateTimes(appState.getClass().getName()));<br />

```
 } 
```

initializing.removeAll(transfer);

}

for (AppState state : array) {

@@ -251,11 +323,22 @@

// Update enabled states

AppState[] array = getStates();

for (AppState state : array){

       boolean logTimes = logStateTimes &amp;&amp; (timer != null) &amp;&amp; (stateTimes.get(state) != null);<br />

```
 float startTime = 0f; 
```

+

       if (logTimes &amp;&amp; (stateTimes.get(state) != null)) {<br />

           startTime = timer.getTime();<br />

```
 } 
```

+

if (state.isEnabled()) {

state.update(tpf);

}

+

       if (logTimes &amp;&amp; (stateTimes.get(state) != null)) {<br />

           stateTimes.get(state).updateTime = (timer.getTime() - startTime) / (float)timer.getResolution();<br />

}

}

}

/**

Calls render for all attached and initialized states, do not call directly.

@@ -264,11 +347,22 @@

public void render(RenderManager rm){

AppState[] array = getStates();

for (AppState state : array){

       boolean logTimes = logStateTimes &amp;&amp; (timer != null) &amp;&amp; (stateTimes.get(state) != null);<br />

```
 float startTime = 0f; 
```

+

       if (logTimes &amp;&amp; (stateTimes.get(state) != null)) {<br />

           startTime = timer.getTime();<br />

```
 } 
```

+

if (state.isEnabled()) {

state.render(rm);

}

+

       if (logTimes &amp;&amp; (stateTimes.get(state) != null)) {<br />

           stateTimes.get(state).renderTime = (timer.getTime() - startTime) / (float)timer.getResolution();<br />

}

}

}

/**

Calls render for all attached and initialized states, do not call directly.

@@ -276,11 +370,22 @@

public void postRender(){

AppState[] array = getStates();

for (AppState state : array){

       boolean logTimes = logStateTimes &amp;&amp; (timer != null) &amp;&amp; (stateTimes.get(state) != null);<br />

```
 float startTime = 0f; 
```

+

       if (logTimes &amp;&amp; (stateTimes.get(state) != null)) {<br />

           startTime = timer.getTime();<br />

```
 } 
```

+

if (state.isEnabled()) {

state.postRender();

}

+

       if (logTimes &amp;&amp; (stateTimes.get(state) != null)) {<br />

           stateTimes.get(state).postRenderTime = (timer.getTime() - startTime) / (float)timer.getResolution();<br />

}

}

}

/**

Calls cleanup on attached states, do not call directly.

[/java]

RenderManager patch:

[java]

This patch file was generated by NetBeans IDE

Following Index: paths are relative to: D:UserspotterecDocumentsjMonkeyProjectsjME3srccorecomjme3renderer

This patch can be applied using context Tools: Patch action on respective folder.

It uses platform neutral UTF-8 encoding and n newlines.

Above lines and this line are ignored by the patching process.

Index: RenderManager.java

— RenderManager.java Base (BASE)

+++ RenderManager.java Locally Modified (Based On LOCAL)

@@ -31,6 +31,7 @@

*/

package com.jme3.renderer;

+import com.jme3.app.state.AppStateManager.StateTimes;

import com.jme3.material.Material;

import com.jme3.material.MaterialDef;

import com.jme3.material.RenderState;

@@ -49,8 +50,11 @@

import com.jme3.system.Timer;

import com.jme3.util.TempVars;

import java.util.ArrayList;

+import java.util.Collection;

import java.util.Collections;

import java.util.List;

+import java.util.Map;

+import java.util.concurrent.ConcurrentHashMap;

import java.util.logging.Logger;

/

@@ -93,6 +97,74 @@

private boolean handleTranlucentBucket = true;

/

*  Class to hold the last times for the Rendering process for a given ViewPort.<br />

```
*/ 
```
public class ViewPortRenderTimes {

   String viewPortName = &quot;&quot;;<br />

```
 float procPreFrameTime = 0f; 
```
```
 float renderSceneTime = 0f; 
```
```
 float procPostQueueTime = 0f; 
```
```
 float flushQueueTime = 0f; 
```
```
 float procPostFrameTime = 0f; 
```

   float renderTranslucentQueueTime = 0f;<br />

```
 float clearQueueTime = 0f; 
```

+

   public ViewPortRenderTimes(String viewPortName) {<br />

       this.viewPortName = viewPortName;<br />

```
 } 
```

+

   public String getViewPortName() {<br />

```
 return viewPortName; 
```
```
 } 
```

   public float getProcPreFrameTime() {<br />

```
 return procPreFrameTime; 
```
```
 } 
```

   public float getRenderSceneTime() {<br />

```
 return renderSceneTime; 
```
```
 } 
```

   public float getProcPostQueueTime() {<br />

```
 return procPostQueueTime; 
```
```
 } 
```

   public float getFlushQueueTime() {<br />

```
 return flushQueueTime; 
```
```
 } 
```

   public float getProcPostFrameTime() {<br />

```
 return procPostFrameTime; 
```
```
 } 
```

   public float getRenderTranslucentQueueTime() {<br />

       return renderTranslucentQueueTime;<br />

```
 } 
```

   public float getClearQueueTime() {<br />

```
 return clearQueueTime; 
```
```
 } 
```
}

+
/**

*  Internal Map for the last times for each active ViewPort.<br />

```
*/ 
```
private Map<ViewPort, ViewPortRenderTimes> viewPortTimes = new ConcurrentHashMap<ViewPort, ViewPortRenderTimes>();

+
// logViewPortTimes enables the time logging for each ViewPort (timer must also be set, but should be by default
private boolean logViewPortTimes = false;

+
/**

* Enables/Disables time logging for ViewPorts.  timer must also be set, but should<br />

```
* be by default 
```

* @param enable When True, time for each stage of the rendering process is logged.<br />

```
*/ 
```
public void setViewPortTimeLogging(boolean enable) {
```
 logViewPortTimes = enable; 
```
}

+
/**

* Retrieve the last scan times for each ViewPort<br />

* @return Collection of times for each ViewPort<br />

```
*/ 
```
public Collection<ViewPortRenderTimes> getViewPortRenderTimes(){

   return Collections.unmodifiableCollection(viewPortTimes.values());<br />

}

+
/**

Create a high-level rendering interface over the
low-level rendering interface.
@param renderer

@@ -128,6 +200,7 @@
@see #createPreView(java.lang.String, com.jme3.renderer.Camera)

*/

public boolean removePreView(ViewPort view) {

   viewPortTimes.remove(view); // add ViewPort to time logging<br />

return preViewPorts.remove(view);

}

@@ -160,6 +233,7 @@

for (int i = 0; i < viewPorts.size(); i++) {

if (viewPorts.get(i).getName().equals(viewName)) {

viewPorts.remove(i);

           viewPortTimes.remove(viewPorts.get(i)); // remove ViewPort from time logging<br />

return true;

}

}

@@ -175,6 +249,7 @@

@see #createMainView(java.lang.String, com.jme3.renderer.Camera)

*/

public boolean removeMainView(ViewPort view) {

   viewPortTimes.remove(view); // remove ViewPort from time logging<br />

return viewPorts.remove(view);

}

@@ -207,6 +282,7 @@

for (int i = 0; i < postViewPorts.size(); i++) {

if (postViewPorts.get(i).getName().equals(viewName)) {

postViewPorts.remove(i);

           viewPortTimes.remove(postViewPorts.get(i)); // remove ViewPort from time logging<br />

return true;
}
@@ -223,6 +299,7 @@
* @see #createPostView(java.lang.String, com.jme3.renderer.Camera)
*/
public boolean removePostView(ViewPort view) {
+ viewPortTimes.remove(view); // remove ViewPort from time logging
return postViewPorts.remove(view);
}

@@ -261,6 +338,7 @@
public ViewPort createPreView(String viewName, Camera cam) {
ViewPort vp = new ViewPort(viewName, cam);
preViewPorts.add(vp);
+ viewPortTimes.put(vp, new ViewPortRenderTimes(viewName)); // add ViewPort to time logging
return vp;
}

@@ -273,6 +351,7 @@
public ViewPort createMainView(String viewName, Camera cam) {
ViewPort vp = new ViewPort(viewName, cam);
viewPorts.add(vp);
+ viewPortTimes.put(vp, new ViewPortRenderTimes(viewName)); // add ViewPort to time logging
return vp;
}

@@ -284,6 +363,7 @@
public ViewPort createPostView(String viewName, Camera cam) {
ViewPort vp = new ViewPort(viewName, cam);
postViewPorts.add(vp);
+ viewPortTimes.put(vp, new ViewPortRenderTimes(viewName)); // add ViewPort to time logging
return vp;
}

@@ -1083,7 +1163,24 @@
* @param tpf
*/
public void renderViewPort(ViewPort vp, float tpf) {
+ boolean logTimes = logViewPortTimes && (timer != null) && (viewPortTimes.get(vp) != null);
+ float startTime = 0f;
+
+ if (logTimes && (viewPortTimes.get(vp) != null)) {
+ startTime = timer.getTime();
+ }
+
if (!vp.isEnabled()) {
+ if (logTimes && (viewPortTimes.get(vp) != null)) {
+ ViewPortRenderTimes times = viewPortTimes.get(vp);
+ times.clearQueueTime = 0f;
+ times.flushQueueTime = 0f;
+ times.procPostFrameTime = 0f;
+ times.procPostQueueTime = 0f;
+ times.procPreFrameTime = 0f;
+ times.renderSceneTime = 0f;
+ times.renderTranslucentQueueTime = 0f;
+ }
return;
}
List<SceneProcessor> processors = vp.getProcessors();
@@ -1100,6 +1197,11 @@
}
}

+ if (logTimes && (viewPortTimes.get(vp) != null)) {
+ viewPortTimes.get(vp).procPreFrameTime = (timer.getTime() - startTime) / (float)timer.getResolution();
+ startTime = timer.getTime();
+ }
+
renderer.setFrameBuffer(vp.getOutputFrameBuffer());
setCamera(vp.getCamera(), false);
if (vp.isClearDepth() || vp.isClearColor() || vp.isClearStencil()) {
@@ -1116,25 +1218,57 @@
renderScene(scenes.get(i), vp);
}

+ if (logTimes && (viewPortTimes.get(vp) != null)) {
+ viewPortTimes.get(vp).renderSceneTime = (timer.getTime() - startTime) / (float)timer.getResolution();
+ startTime = timer.getTime();
+ }
+
if (processors != null) {
for (SceneProcessor proc : processors) {
proc.postQueue(vp.getQueue());
}
}

+ if (logTimes && (viewPortTimes.get(vp) != null)) {
+ viewPortTimes.get(vp).procPostQueueTime = (timer.getTime() - startTime) / (float)timer.getResolution();
+ startTime = timer.getTime();
+ }
+
flushQueue(vp);

+ if (logTimes && (viewPortTimes.get(vp) != null)) {
+ viewPortTimes.get(vp).flushQueueTime = (timer.getTime() - startTime) / (float)timer.getResolution();
+ startTime = timer.getTime();
+ }
+
if (processors != null) {
for (SceneProcessor proc : processors) {
proc.postFrame(vp.getOutputFrameBuffer());
}
}
+
+ if (logTimes && (viewPortTimes.get(vp) != null)) {
+ viewPortTimes.get(vp).procPostFrameTime = (timer.getTime() - startTime) / (float)timer.getResolution();
+ startTime = timer.getTime();
+ }
+
//renders the translucent objects queue after processors have been rendered
renderTranslucentQueue(vp);
+
+ if (logTimes && (viewPortTimes.get(vp) != null)) {
+ viewPortTimes.get(vp).renderTranslucentQueueTime = (timer.getTime() - startTime) / (float)timer.getResolution();
+ startTime = timer.getTime();
+ }
+
// clear any remaining spatials that were not rendered.
clearQueue(vp);
+
+ if (logTimes && (viewPortTimes.get(vp) != null)) {
+ viewPortTimes.get(vp).clearQueueTime = (timer.getTime() - startTime) / (float)timer.getResolution();
}

+ }
+
/**
* Called by the application to render any ViewPorts
* added to this RenderManager.
[/java]

wezrule · July 9, 2012, 5:13pm

thx for this!! as well as all the other helpful patches and useful posts you have done, which I and a lot of people have benefited from. Thanks!! again

(@normen give this guy a contributor tag already :))

iwgeric · July 9, 2012, 5:19pm

@wezrule Thanks It’s actally a lot of fun for me. Using the engine and contributing some patches is a whole lot better than creating everything from scratch!

zarch · July 9, 2012, 5:20pm

Nice idea, one suggestion though. From what I see the stats just keep the most recent frame? You may well find that storing: longest time, shortest time, total time, and num runs (from which you get average time) are very useful.

Either wipe them every 5 seconds when you do the log or keep them accumulating for ever (or make those two behaviours switch-able).

This is useful to catch things like an appstate that only occasionally takes a long time to process but generally runs fine … as you may not otherwise spot that.

pspeed · July 9, 2012, 5:26pm

I have similar code that I’ve added to a local copy of JME that I build against. It can be useful on some levels but many of the things you are tracking can also be adequately shown in the profiler, I think. I guess on Android that is not as much of an option and maybe it’s useful there. It is nice to have access to the stats in game.

Anyway, you might be better of using System.nanoTime() and long instead of float to track time. This will provide the maximum precision. I assume System.nanoTime() is available on Android. Timer may not be for accurate timing because it is returning “game time” and things can mess with that.

normen · July 9, 2012, 7:37pm

@wezrule: I’m not giving out the contributor tags ^^ @iwgeric: yeah, like we say in the manual, using primitive shapes is the best in bullet, using dynamic mesh shapes (GImpact shapes) is the worst. Mesh shapes should generally only be used for static objects and for dynamic objects hull shapes should be used, that is what the RigidBodyControls automatically do when adding them to a spatial depending on their mass (0 == mesh).

iwgeric · July 9, 2012, 8:03pm

@zarch I originally went down that path, but my goal (selfishly) at the time was to have a tpf and be able to associate the parts that made up that specific tpf. If I was making this as a patch to the engine that was going to be committed, I would agree that these extra fields would be nice to include as well.

@pspeed When I was looking around at what time to use, I noticed that both AndroidTimer and NanoTimer use System.nanoTime() in their getTime methods so I just used Timer. RenderManager already had a reference to it and I wasn’t sure if all the platforms had the same System.nanoTime() or not. It was just easier to use the Timer class and not worry about it. As far as resolution goes, I though anything less than a milliSecond was overkill for this, but point taken about keeping the resolution.

@normen I did already understand that primitive shapes were the best to use, but until I did this activity, I really didn’t understand the size of impact. I saved about 15 fps just from bullet. We have a vehicle based game we’re working on and making the ramps that the vehicles can jump are going to be difficult to make with primitive shapes so we left the vehicles, floor and arena walls as primitives and the ramps as static mesh shapes. Seems to be OK for now. The game is still running in the mid to upper 30s like this.

madjack · July 9, 2012, 9:11pm

Feel free to flail me, but I think it would be really nice if we could have something like a SimpleApplicationDebug containing lots of stuff like the above. I know I’ve seen many suggestion proposing tracking, stats and other things.

Essentially, if we simply could switch from one to the other, it would be great to have while in heavy development.

pspeed · July 10, 2012, 1:09am

@madjack said:
Feel free to flail me, but I think it would be really nice if we could have something like a SimpleApplicationDebug containing lots of stuff like the above. I know I've seen many suggestion proposing tracking, stats and other things.

Essentially, if we simply could switch from one to the other, it would be great to have while in heavy development.

That's the trick, though... since the above requires changes to core classes.

pspeed · July 10, 2012, 1:23am

@iwgeric said:
@pspeed When I was looking around at what time to use, I noticed that both AndroidTimer and NanoTimer use System.nanoTime() in their getTime methods so I just used Timer. RenderManager already had a reference to it and I wasn't sure if all the platforms had the same System.nanoTime() or not. It was just easier to use the Timer class and not worry about it. As far as resolution goes, I though anything less than a milliSecond was overkill for this, but point taken about keeping the resolution.

But other things will pause and/or reset the timer so you have to be careful.

I guess float doesn't start to lose millisecond accuracy until the game is run for a few hours... but long would never lose it and can track nanosecond accuracy. And for timing, it's better to track nanoseconds because otherwise you accumulate tons of error for stuff that takes less than a millisecond to run, ie: you will think an appstate takes many times longer than it does just because you happen to hit a millisecond boundary at the right time. Float will lose nanosecond accuracy right away.

madjack · July 10, 2012, 11:58am

@pspeed said:
That's the trick, though... since the above requires changes to core classes.

As you say that's the trick. The engine is getting very stable now and having this kind of "debug branch" would mean more maintaining, but I think down the line it would be very interesting to consider having.

pspeed · July 10, 2012, 4:15pm

@madjack said:
As you say that's the trick. The engine is getting very stable now and having this kind of "debug branch" would mean more maintaining, but I think down the line it would be very interesting to consider having.

I don't think the changes above necessarily require a separate branch. They can be turned on and off and when off they don't add a drain on performance. I'd probably do it a little differently for core but the concept is sound to me.

Momoko_Fan · July 10, 2012, 4:25pm

Android does have profilers, there’s DDMS and TraceView (new). I used DDMS before to optimize jME3 for Android.

madjack · July 10, 2012, 7:08pm

Debug branch was in quotes. I don’t mean a real development branch.