google-ar / sceneform-android-sdk

Sceneform SDK for Android
https://developers.google.com/sceneform/develop/
Apache License 2.0
1.23k stars 604 forks source link

Sceneform v1.16.0 assigning to (glb) renderable very slow, ~1 sec per model #1046

Open tellypresence opened 4 years ago

tellypresence commented 4 years ago

Sceneform v1.16.0

Extended the new gltf sample app (https://github.com/google-ar/sceneform-android-sdk/tree/master/samples/gltf), loading models and then assigning renderables on plane tap.

Benchmarking the single line https://github.com/google-ar/sceneform-android-sdk/blob/4d7b6602f24cab1b46a739e80d1b288818a58555/samples/gltf/app/src/main/java/com/google/ar/sceneform/samples/gltf/GltfActivity.java#L141

indicates that this single assignment line takes anywhere from 0.5 to over 1 second for our own custom .glb models.

Anyone else seeing this?

The bad part is that this assignment has to be on the main thread, so the camera view freezes for several seconds depending on how many models are being loaded.

Would be great if the sample could be updated to reflect best practices in real world situation where several models are being loaded instead of just one.

romainguy commented 4 years ago

Do you have more information about your model? Is there any chance you can share it?

tellypresence commented 4 years ago

Issue can easily be demonstrated using "tiger" model from v1.16.0 "gltf" sample, sample project attached (in folder samples/gltf): sceneform_issue_1046.zip

In this case the tiger is instanced 5 times; each renderable assignment takes 250 - 300 ms on test device (as always YMMV) but should see noticeable AR camera view freeze while the renderables are assigned

E/GltfActivity:     node.setRenderable() [0] took 0.25834954 secs
E/GltfActivity:     node.setRenderable() [1] took 0.25169277 secs
E/GltfActivity:     node.setRenderable() [2] took 0.2926885 secs
E/GltfActivity:     node.setRenderable() [3] took 0.30250108 secs
E/GltfActivity:     node.setRenderable() [4] took 0.26427245 secs
E/GltfActivity: setupNodes(): took 1.6280144 secs
tellypresence commented 4 years ago

Also, the attached sample project is a good check for general stability; found that by increasing the instances from 5 to 12, good chance of crashing on flagship phone (Samsung Galaxy S9) (which wouldn't be expected to happen given that it's only loading a single renderable being instanced several times)

tellypresence commented 4 years ago

Checked profiler memory usages using sample project

Does sceneform leverage GL instancing at all? Looks like single model is O(N) on RAM consumption

NUM_MODELS = 3 uses ~600MB sceneform_issue_1046_03_tigers_memory

NUM_MODELS = 12 uses ~1.5GB sceneform_issue_1046_12_tigers_memory

NUM_MODELS = 20 uses ~1.9GB (but crashes after 19th tiger) sceneform_issue_1046_20_tigers_memory_crash

(loaded 19 of 'em but then crashed)

E/GltfActivity:     node.setRenderable() [0] took 0.3290517 secs
E/GltfActivity:     node.setRenderable() [1] took 0.2977509 secs
E/GltfActivity:     node.setRenderable() [2] took 0.27852172 secs
E/GltfActivity:     node.setRenderable() [3] took 0.283355 secs
E/GltfActivity:     node.setRenderable() [4] took 0.27688906 secs
E/GltfActivity:     node.setRenderable() [5] took 0.299327 secs
E/GltfActivity:     node.setRenderable() [6] took 0.31435588 secs
E/GltfActivity:     node.setRenderable() [7] took 0.29318497 secs
E/GltfActivity:     node.setRenderable() [8] took 0.22272807 secs
E/GltfActivity:     node.setRenderable() [9] took 0.29228407 secs
E/GltfActivity:     node.setRenderable() [10] took 0.26803324 secs
E/GltfActivity:     node.setRenderable() [11] took 0.30059725 secs
E/GltfActivity:     node.setRenderable() [12] took 0.32690912 secs
E/GltfActivity:     node.setRenderable() [13] took 0.3774478 secs
E/GltfActivity:     node.setRenderable() [14] took 0.3748167 secs
E/GltfActivity:     node.setRenderable() [15] took 0.4512907 secs
E/GltfActivity:     node.setRenderable() [16] took 0.29349643 secs
E/GltfActivity:     node.setRenderable() [17] took 0.33146808 secs
E/GltfActivity:     node.setRenderable() [18] took 0.3858366 secs
E/GltfActivity:     node.setRenderable() [19] took 0.35472056 secs