Library Override Resync Performance #94059

New Issue

Dalai Felinto · 2021-12-14T12:43:30+01:00

Dalai Felinto commented

2021-12-14 12:43:30 +01:00

Production files (that require no resync) take a long time to load when "Override Auto Resync" is enabled.
Blender: 3.0

File:

Sprite Fright: 030_0020_A.lighting.blend (255MB).

Load time:

Override Auto Resync on (default): 15min 10sec with 3.0 (latest result: 3m42s with 4b21067aea)
Override Auto Resync off: 36sec

Profiling:

{F12739213, size=full}

Findings:

Override resync seems entirely bottlenecked by poor time complexity.
BKE_collection_object_find is likely easy to optimize with a hash.
BKE_library_foreach_ID_link should be possible to optimize with a map also, but not sure how hard it is to keep this map valid if the pointers are being updated as part of this.
lib_override_linked_group_tag could run in parallel for each object ID (in the collection tag part, the second LISTBASE_FOREACH loop).

Worthy noting:

WM_main_add_notifier: likely bad time complexity with many queued notifiers, must be some way to optimize
DEG_id_tag_update: slow depsgraph tagging, likely solveable with delayed flushing instead of for every RNA edit
ED_object_constraint_tag_update: bad time complexity for object existence check, unclear why is even needed
BKE_pose_channel_find_name: bad time complexity in bone lookup, create pose bone hash earlier to solve overall feels like we should be able to make this way faster

Note: profiling by @brecht , findings by @brecht and @jbakker.

Production files (that require no resync) take a long time to load when "Override Auto Resync" is enabled. Blender: 3.0 --- File: * Sprite Fright: [030_0020_A.lighting.blend ](https://download.blender.org/demo/sprite_fright_030_0020_A.zip) (255MB). Load time: * Override Auto Resync on (default): **15min 10sec** with 3.0 (latest result: 3m42s with 4b21067aea41) * Override Auto Resync off: 36sec Profiling: {[F12739213](https://archive.blender.org/developer/F12739213/image.png), size=full} Findings: * Override resync seems entirely bottlenecked by poor time complexity. * BKE_collection_object_find is likely easy to optimize with a hash. * BKE_library_foreach_ID_link should be possible to optimize with a map also, but not sure how hard it is to keep this map valid if the pointers are being updated as part of this. * lib_override_linked_group_tag could run in parallel for each object ID (in the collection tag part, the second `LISTBASE_FOREACH` loop). Worthy noting: * WM_main_add_notifier: likely bad time complexity with many queued notifiers, must be some way to optimize * DEG_id_tag_update: slow depsgraph tagging, likely solveable with delayed flushing instead of for every RNA edit * ED_object_constraint_tag_update: bad time complexity for object existence check, unclear why is even needed * BKE_pose_channel_find_name: bad time complexity in bone lookup, create pose bone hash earlier to solve overall feels like we should be able to make this way faster Note: profiling by @brecht , findings by @brecht and @jbakker.

Dalai Felinto commented

2021-12-14 12:43:30 +01:00

Changed status from 'Needs Triage' to: 'Confirmed'

Dalai Felinto commented

2021-12-14 12:43:30 +01:00

Added subscriber: @dfelinto

Dalai Felinto commented

2021-12-14 12:58:23 +01:00

Added subscribers: @Jeroen-Bakker, @brecht

Bastien Montagne commented

2021-12-16 17:32:01 +01:00

Added subscriber: @mont29

Bastien Montagne commented

2021-12-16 17:32:01 +01:00

GHash caching of calls to BKE_collection_object_find has been implemented in 0624fad0f3

For me, opening that file goes from

Blender file read in 7m55.03s
 * Loading libraries: 0m1.87s
 * Applying overrides: 0m6.85s
 * Resyncing overrides: 7m38.19s (103 root overrides), including recursive resyncs: 5m53.94s)

to...

Blender file read in 2m31.30s
 * Loading libraries: 0m1.46s
 * Applying overrides: 0m6.97s
 * Resyncing overrides: 2m14.70s (103 root overrides), including recursive resyncs: 2m11.86s)

NOTE: This file and its dependencies remain fairly 'dirty', it exhibits several cases of multi-driver-variables-with-same-name (#94116), and also several cases of characters 'exploded' out of their root collection (for some they do not even have the root collection override anymore!), those issues cause the extra unneeded resyncs at startup.

GHash caching of calls to `BKE_collection_object_find` has been implemented in 0624fad0f3 For me, opening that file goes from ``` Blender file read in 7m55.03s * Loading libraries: 0m1.87s * Applying overrides: 0m6.85s * Resyncing overrides: 7m38.19s (103 root overrides), including recursive resyncs: 5m53.94s) ``` to... ``` Blender file read in 2m31.30s * Loading libraries: 0m1.46s * Applying overrides: 0m6.97s * Resyncing overrides: 2m14.70s (103 root overrides), including recursive resyncs: 2m11.86s) ``` NOTE: This file and its dependencies remain fairly 'dirty', it exhibits several cases of multi-driver-variables-with-same-name (#94116), and also several cases of characters 'exploded' out of their root collection (for some they do not even have the root collection override anymore!), those issues cause the extra unneeded resyncs at startup.

Bastien Montagne commented

2021-12-16 18:16:57 +01:00

Follow up: Getting completely rid of BKE_collection_object_find in 197b3502b0 allows to gain a bit more, for me values on this file are now:

Blender file read in 2m10.77s
 * Loading libraries: 0m1.45s
 * Applying overrides: 0m6.82s
 * Resyncing overrides: 1m54.40s (103 root overrides), including recursive resyncs: 1m52.94s)

Follow up: Getting completely rid of `BKE_collection_object_find` in 197b3502b0 allows to gain a bit more, for me values on this file are now: ``` Blender file read in 2m10.77s * Loading libraries: 0m1.45s * Applying overrides: 0m6.82s * Resyncing overrides: 1m54.40s (103 root overrides), including recursive resyncs: 1m52.94s) ```

Jeroen Bakker commented

2021-12-17 08:50:43 +01:00

Updated flame graph showing that performance is shifting to resync.

{F12756833,size=full}

Updated flame graph showing that performance is shifting to resync. {[F12756833](https://archive.blender.org/developer/F12756833/Screenshot_from_2021-12-17_08-46-04.png),size=full}

Brecht Van Lommel commented

2021-12-17 13:58:42 +01:00

I don't know the full context here, but would it be possible for resync to keep datablocks in the same memory location (like undo), and avoid remapping? I would expect that most of the time resync does not actually need to change most datablocks and their relations, that usually in e.g. a rig nothing changes or a few objects are added/removed.

Dalai Felinto commented

2021-12-17 14:12:41 +01:00

For the records, the file takes now 4 minutes on my computer.

Jeroen Bakker commented

2021-12-17 14:18:27 +01:00

@dfelinto 4 minutes seems to be much slower as the 110s it took when creating the flame graph. I used a RelWithDebInfo, where the files where checked out locally on primary M2 (Ryzen3800).

Garek commented

2021-12-23 05:18:29 +01:00

Added subscriber: @Garek

Bastien Montagne commented

2021-12-23 10:49:29 +01:00

In #94059#1274529, @brecht wrote:
I don't know the full context here, but would it be possible for resync to keep datablocks in the same memory location (like undo), and avoid remapping? I would expect that most of the time resync does not actually need to change most datablocks and their relations, that usually in e.g. a rig nothing changes or a few objects are added/removed.

@brecht In theory this should be possible yes... However, this would add another layer of complexity to this area. Given the current complexity of the resync code, I have refrained from implementing this so far.

Think we should first iron it out fully, and implement missing bits (like support for partial resync, for relationships between different liboverride hierarchies, etc.), before adding this extra layer of complexity (if it still makes sense to have it - performances of liboverride resync should be much less critical than those of undo system, since it only happens once on file load, in the worst case, and should not happen at all in most cases).

> In #94059#1274529, @brecht wrote: > I don't know the full context here, but would it be possible for resync to keep datablocks in the same memory location (like undo), and avoid remapping? I would expect that most of the time resync does not actually need to change most datablocks and their relations, that usually in e.g. a rig nothing changes or a few objects are added/removed. @brecht In theory this should be possible yes... However, this would add another layer of complexity to this area. Given the current complexity of the resync code, I have refrained from implementing this so far. Think we should first iron it out fully, and implement missing bits (like support for partial resync, for relationships between different liboverride hierarchies, etc.), before adding this extra layer of complexity (if it still makes sense to have it - performances of liboverride resync should be much less critical than those of undo system, since it only happens once on file load, in the worst case, and should not happen at all in most cases).

RedMser commented

2022-01-14 17:32:06 +01:00

Added subscriber: @RedMser