Loading performance - Cotninuation

Started by Jakes, January 19, 2020, 09:43:10 PM

Previous topic - Next topic

Jakes

Hello,

after the recent topic "Low performance when using uncompiled objects", the mais issue seemed to be the preWarming of textures, which seems to be solved.

Altought, when using a huge cluster of objects of the same type, there seems to happen a loading of some sort, while the console is outputting these:

Not a triangle strip at position 1!
Remapping 2022 vertex indices!
Creating vertex cache (48528 bytes)!
Vertex indices will be mapped!
Subobject of object 0/object2 compiled to indexed data using 4932/4932 vertices in 20ms!
Checking for triangle strip...
Compiling source object...
Checking for triangle strip...
Not a triangle strip at position 1!
Remapping 68 vertex indices!
Creating vertex cache (1632 bytes)!
Vertex indices will be mapped!
Subobject of object 2/object4 compiled to indexed data using 102/102 vertices in 2ms!
Object 2/object4 compiled to 1 subobjects in 2ms!
Object 5233/object5235 precompiled!
Compiling source object...
Checking for triangle strip...
Not a triangle strip at position 1!
Remapping 162 vertex indices!
Creating vertex cache (3888 bytes)!
Vertex indices will be accessed directly!
Subobject of object 6/object8 compiled to indexed data using 960/960 vertices in 5ms!
Object 6/object8 compiled to 1 subobjects in 6ms!
Object 5234/object5236 precompiled!
Object 5235/object5237 precompiled!
Delayed pre-warming done!
VBO created for object 'object5226'
VBO created for object 'object5220'
Compiled 2 VBO!
Object 'object3482' shares compiled data with object 'object11'
Object 'object4333' shares compiled data with object 'object11'
Object 'object3152' shares compiled data with object 'object11'
Object 'object4338' shares compiled data with object 'object11'
Object 'object2954' shares compiled data with object 'object11'
[x 1000 more]
...

Checking for triangle strip...
Not a triangle strip at position 1!
Subobject of object 5239/object5241 compiled to indexed data using 24/9 vertices in 1ms!
Object 5239/object5241 compiled to 1 subobjects in 1ms!
Object 5242/object5244 precompiled!
Object 5243/object5245 precompiled!
Checking for triangle strip...
Not a triangle strip at position 1!
Subobject of object 5246/object5248 compiled to indexed data using 24/9 vertices in 0ms!
Object 5246/object5248 compiled to 1 subobjects in 1ms!
Object 5249/object5251 precompiled!
Object 5250/object5252 precompiled!
Checking for triangle strip...
Not a triangle strip at position 1!
[x 1000 more]
...

Checking for triangle strip...
Not a triangle strip at position 1!
Subobject of object 5785/object5787 compiled to indexed data using 24/9 vertices in 0ms!
Object 5785/object5787 compiled to 1 subobjects in 1ms!
Object 5788/object5790 precompiled!
Object 5789/object5791 precompiled!
VBO created for object 'object5451'
VBO created for object 'object5409'
VBO created for object 'object5570'
VBO created for object 'object5598'
VBO created for object 'object5591'
VBO created for object 'object5731
VBO created for object 'object5444'
VBO created for object 'object5514'
VBO created for object 'object5647'
VBO created for object 'object5255'
VBO created for object 'object5696'
VBO created for object 'object5633'
VBO created for object 'object5521'
VBO created for object 'object5353'
VBO created for object 'object5773'
VBO created for object 'object5640'
VBO created for object 'object5549'
VBO created for object 'object5542'
VBO created for object 'object5710'
VBO created for object 'object5724'
VBO created for object 'object5479'
VBO created for object 'object5605'
VBO created for object 'object5689'
VBO created for object 'object5752'
VBO created for object 'object5703'
VBO created for object 'object5668'
VBO created for object 'object5654'
VBO created for object 'object5766'
VBO created for object 'object5759'
VBO created for object 'object5437'
VBO created for object 'object5528'
VBO created for object 'object5619'
VBO created for object 'object5500'
VBO created for object 'object5262'
VBO created for object 'object5311'
VBO created for object 'object5745'
VBO created for object 'object5465'
VBO created for object 'object5388'
Compiled 79 VBO!
Object 'object5301' shares compiled data with object 'object4'
Object 'object5623' shares compiled data with object 'object4'
Object 'object5595' shares compiled data with object 'object4'
Object 'object5588' shares compiled data with object 'object4'
Object 'object5448' shares compiled data with object 'object4'
Object 'object5462' shares compiled data with object 'object4'
Object 'object5315' shares compiled data with object 'object4'
Object 'object5700' shares compiled data with object 'object4'
Object 'object5567' shares compiled data with object 'object4'


during this period, a huge freeze starts and only stops after these have stop writing to the console.

The last JAR that was made to solve the preWarm issue, seems to lack the "World.compileAllObjects(FrameBuffer)" which I think could solve this loading process?

can you please add both changes to one last jar, if it's not too much trouble?

So my question is:
Could this be the cause?
If not, is there anything I can do before starting the scene to avoid this altogether?


I've even removed all the textures from my scene in order to dismiss this possibility, and it still happens, and the more objects I add onto the scene, the more this "loading period" takes. It's a bit nerve wracking because the number of objects is not that great and I'm not even in the middle of the development.

PS: I tried to use the "Config.glVerbose = false" to hide the previous log text, but it seems that some text is always being output, is it possible to reduce these info lines with an option? (any log describing the compilation process at runtime)

many thanks,

Jakes

EgonOlsen

You can configure the logger in the Logger class. Just set the log level to something higher (like http://www.jpct.net/doc/com/threed/jpct/Logger.html#LL_ERRORS_AND_WARNINGS) and the messages should disappear. The compileAllObjects-method is still there, I've just renamed it so that it reflects better what it actually does. It's now called prewarmAllObject(<FrameBuffer>)

Jakes

Quote from: EgonOlsen on January 19, 2020, 11:17:04 PM
You can configure the logger in the Logger class. Just set the log level to something higher (like http://www.jpct.net/doc/com/threed/jpct/Logger.html#LL_ERRORS_AND_WARNINGS) and the messages should disappear.

Thanks, I'll give it a go.

Quote from: EgonOlsen on January 19, 2020, 11:17:04 PMThe compileAllObjects-method is still there, I've just renamed it so that it reflects better what it actually does. It's now called prewarmAllObject(<FrameBuffer>)

Regarding this, issue, I've tried a lot of scenarios so far:

1. Creating all of the objects hidden, starting the scene with only 1 or 2 simple objects, wait like 5 or 10 seconds, and show all of the 4000 hidden objects: and this way no hiccuping happens at all, it works as if all of them were already loaded.

2. Creating all of the objects visible, starting the scene with 4000+ objects: The scene freezes and has huge frame drops for like 3 or 4 seconds.

3. Used the World.prewarmAllObjects(FrameBuffer) combined with TextureManager.preWarm(FrameBuffer) and here is where the weird behaviour starts as I'm describing below:

- If everything is processed quick enough, then nothing different happens, it loads, and there will be a slowing down of the simulation for 2 or 3 seconds before everything starts running smoothly, so nothing seems to differ when using the World.prewarmAllObjects(FrameBuffer).

But

- if I take longer, after the TextureManager.preWarm(FrameBuffer) which outputs the message "Delayed pre-warming done!" then this shows up on the log afterwards: "Compiling object object6278/com.threed.jpct.Object3D@2d12a01f!
[ Sun Jan 19 22:54:28 GMT 2020 ] - WARNING: Object object6278 hasn't been build yet. Forcing build()!" and nothing happens, as if the application just stops its cycle. and it freezes here forever:


is there anything that I could be missing? As I said previously, If I hide all the objects for a while and then show them up, everything seems to flow normally, but if they start out visible from the start, there will always be some slowness and freezing.

EgonOlsen

Seems like a dead lock between the render and the main thread. Are you getting some messages like this:

Waiting for renderer to initialize...<some number up to 50 here>

?

Jakes

No, it just freezes at that stage.

Compiling object object5811/com.threed.jpct.Object3D@63dbf1b0!
Compiling object object5813/com.threed.jpct.Object3D@7cd88d07!
Compiling object object5815/com.threed.jpct.Object3D@6d130699!
Compiling object object5816/com.threed.jpct.Object3D@7c165ec0!
Compiling object object5818/com.threed.jpct.Object3D@20a6cee5!
Compiling object object5822/com.threed.jpct.Object3D@27592d22!
Compiling object object5824/com.threed.jpct.Object3D@4fa2275c!
Compiling object object5829/com.threed.jpct.Object3D@1ec631dc!
Compiling object object5831/com.threed.jpct.Object3D@65f3724c!
Compiling object object5833/com.threed.jpct.Object3D@51d50fde!
Compiling object object5834/com.threed.jpct.Object3D@7b04e1ca!
Compiling object object5835/com.threed.jpct.Object3D@7d83d3de!
Compiling object object5836/com.threed.jpct.Object3D@59cad432!
Compiling object object5839/com.threed.jpct.Object3D@13314cac!
[ Thu Jan 23 00:18:27 GMT 2020 ] - WARNING: Object object5839 hasn't been build yet. Forcing build()!
[...Freezes Here...]


but this only happens when the loading process takes more time and this line appears:

Delayed pre-warming done!

so, what it looks like is, when this line shows up beforehand the precompilation of the objects, the whole program freezes.

I think it has something to do with that, other than that I cant really say.

Jakes

Bu regarding this issue, isn't it possible to add a method to the engine that coudl be called staticly, such as TextureManager.preWarm(FrameBuffer), like this:

FrameBuffer.prewarmCompiledObjects(FrameBuffer)

or

Object3D.prewarmCompiledObjects(FrameBuffer)

(I would assume that for this I would need to pass an array of objects, or something similar?)

The reason I'm asking this is, does this method really needs to be a part of the world, beucause I could have the need to precompile every object into the buffer and I could not be using any world at this stage. for example, these objects could be in an asset container so that they could be sent out to the world afterwards. Furthermore, the only thing needed here is the FrameBuffer right?

EgonOlsen

No, because a static method has no idea which objects are actually to compile. It can't access the actual references. In the TextureManager, this works because it's a singleton. But World or FrameBuffer aren't, so this is not possible.  It wouldn't help anything anyway, because static or not, the preloading/-warming has to happen in the render thread, which in case of the AWTGLRenderer is the AWT event dispatch thread. Hence the delayed operation. In this case, the actual build/compile/prewarm has to wait for the render thread to initialize the GL context (that would be indicated by the message that I asked for).
I'm not sure why it freezes though. It looks like a dead lock, because there are some sync operations between the threads going on, but if there's no "Waiting..."-message, I don't see why this should happen ATM. I need a test case to reproduce and debug this, I'm afraid. Can you provide me with something?

Jakes

Quote from: EgonOlsen on January 23, 2020, 03:11:56 PM
I'm not sure why it freezes though. It looks like a dead lock, because there are some sync operations between the threads going on, but if there's no "Waiting..."-message, I don't see why this should happen ATM.

There is no such message like that at all

Quote from: EgonOlsen on January 23, 2020, 03:11:56 PM
I need a test case to reproduce and debug this, I'm afraid. Can you provide me with something?

I could try to setup a stand alone project, and I will sent you afterwards