Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

history() performance regression due to #4568 #5199

Closed
danieldresser-ie opened this issue Mar 9, 2023 · 5 comments
Closed

history() performance regression due to #4568 #5199

danieldresser-ie opened this issue Mar 9, 2023 · 5 comments
Assignees

Comments

@danieldresser-ie
Copy link
Contributor

In #4568, we switched from using a unique integer in the context to force a history() monitor to re-evaluate upstream nodes, to adding a feature that lets us temporarily disable caching.

This seems cleaner, and allows us to fix an issue where evaluations that snuck upstream outside the plug type we tracking could cache the upstream scene, and cause history() to miss some upstream nodes.

However ... it creates the potential for completely disastrous performance. If there are diamond shapes in the upstream network, which actually involve the plug we are interested in, then we can evaluate upstream nodes multiple times. Chaining multiple diamond shapes causes exponential increase in the number of copies of nodes evaluated.

I'll try and include a simple example script below that illustrates where this was reported in production - a scene where enabling the crop window tool takes 5 seconds ( or 10 or 20 seconds if you add another Options node or two ).

Conceptually, I suppose the correct thing would be a second cache for the plugs where forceMonitoring is true. We don't want to skip monitoring something because it has been evaluated outside of the monitored call, but once a plug has been monitored, we probably don't want to monitor it multiple times in the same context?

Post-script:

While I think we probably do need to fix this, in terms of work-arounds, it's worth mentioning that the cause of large numbers of diamond connections in the IE render pass settings was due to a kinda specific thing that can be worked around: there's a default IE render pass settings node which is commonly used. One of the things this node can do is delete a selection of IE specific render options by building a glob based on some user inputs. It does this using DeleteOptions, but DeleteOptions does not have the ability to whitelist some options for never being deleted - so to achieve a whitelist, it does a DeleteOptions followed by a CopyOptions to restore the options that should never be deleted. The CopyOptions is the source of diamond shaped connections. It would be nice if there was a cleaner way to implement a whitelist on DeleteOptions - I guess maybe instead of using a glob on DeleteOptions, we should be evaluating the options and performing the matching ourselves in Python to produce a baked list of options that match the glob but not the whitelist. For the moment, I can hack around it by just disabling the DeleteOptions and CopyOptions if the user selection is empty, which it often is.

@danieldresser-ie
Copy link
Contributor Author

A sample scene where enabling the crop takes 5 seconds ( and that's with the loop controlling the number of diamond connections on the globals set to just 17 - with it set to 30, it would for all practical purposes be hung ).

import Gaffer
import GafferArnold
import GafferImage
import GafferScene
import IECore
import imath

Gaffer.Metadata.registerValue( parent, "serialiser:milestoneVersion", 1, persistent=False )
Gaffer.Metadata.registerValue( parent, "serialiser:majorVersion", 1, persistent=False )
Gaffer.Metadata.registerValue( parent, "serialiser:minorVersion", 9, persistent=False )
Gaffer.Metadata.registerValue( parent, "serialiser:patchVersion", 2, persistent=False )

__children = {}

__children["InteractiveArnoldRender"] = GafferArnold.InteractiveArnoldRender( "InteractiveArnoldRender" )
parent.addChild( __children["InteractiveArnoldRender"] )
__children["InteractiveArnoldRender"].addChild( Gaffer.V2fPlug( "__uiPosition", defaultValue = imath.V2f( 0, 0 ), flags = Gaffer.Plug.Flags.Default | Gaffer.Plug.Flags.Dynamic, ) )
__children["Group"] = GafferScene.Group( "Group" )
parent.addChild( __children["Group"] )
__children["Group"]["in"].addChild( GafferScene.ScenePlug( "in1", flags = Gaffer.Plug.Flags.Default | Gaffer.Plug.Flags.Dynamic, ) )
__children["Group"]["in"].addChild( GafferScene.ScenePlug( "in2", flags = Gaffer.Plug.Flags.Default | Gaffer.Plug.Flags.Dynamic, ) )
__children["Group"].addChild( Gaffer.V2fPlug( "__uiPosition", defaultValue = imath.V2f( 0, 0 ), flags = Gaffer.Plug.Flags.Default | Gaffer.Plug.Flags.Dynamic, ) )
__children["Camera"] = GafferScene.Camera( "Camera" )
parent.addChild( __children["Camera"] )
__children["Camera"].addChild( Gaffer.V2fPlug( "__uiPosition", defaultValue = imath.V2f( 0, 0 ), flags = Gaffer.Plug.Flags.Default | Gaffer.Plug.Flags.Dynamic, ) )
__children["StandardOptions"] = GafferScene.StandardOptions( "StandardOptions" )
parent.addChild( __children["StandardOptions"] )
__children["StandardOptions"].addChild( Gaffer.V2fPlug( "__uiPosition", defaultValue = imath.V2f( 0, 0 ), flags = Gaffer.Plug.Flags.Default | Gaffer.Plug.Flags.Dynamic, ) )
__children["Catalogue"] = GafferImage.Catalogue( "Catalogue" )
parent.addChild( __children["Catalogue"] )
__children["Catalogue"]["images"].addChild( GafferImage.Catalogue.Image( "Image", flags = Gaffer.Plug.Flags.Default | Gaffer.Plug.Flags.Dynamic, ) )
__children["Catalogue"].addChild( Gaffer.V2fPlug( "__uiPosition", defaultValue = imath.V2f( 0, 0 ), flags = Gaffer.Plug.Flags.Default | Gaffer.Plug.Flags.Dynamic, ) )
__children["Outputs"] = GafferScene.Outputs( "Outputs" )
parent.addChild( __children["Outputs"] )
__children["Outputs"]["outputs"].addChild( Gaffer.ValuePlug( "output1", flags = Gaffer.Plug.Flags.Default | Gaffer.Plug.Flags.Dynamic, ) )
__children["Outputs"]["outputs"]["output1"].addChild( Gaffer.StringPlug( "name", defaultValue = '', flags = Gaffer.Plug.Flags.Default | Gaffer.Plug.Flags.Dynamic, ) )
__children["Outputs"]["outputs"]["output1"].addChild( Gaffer.BoolPlug( "active", defaultValue = True, flags = Gaffer.Plug.Flags.Default | Gaffer.Plug.Flags.Dynamic, ) )
__children["Outputs"]["outputs"]["output1"].addChild( Gaffer.StringPlug( "fileName", defaultValue = '', flags = Gaffer.Plug.Flags.Default | Gaffer.Plug.Flags.Dynamic, ) )
__children["Outputs"]["outputs"]["output1"].addChild( Gaffer.StringPlug( "type", defaultValue = '', flags = Gaffer.Plug.Flags.Default | Gaffer.Plug.Flags.Dynamic, ) )
__children["Outputs"]["outputs"]["output1"].addChild( Gaffer.StringPlug( "data", defaultValue = '', flags = Gaffer.Plug.Flags.Default | Gaffer.Plug.Flags.Dynamic, ) )
__children["Outputs"]["outputs"]["output1"].addChild( Gaffer.CompoundDataPlug( "parameters", flags = Gaffer.Plug.Flags.Default | Gaffer.Plug.Flags.Dynamic, ) )
__children["Outputs"]["outputs"]["output1"]["parameters"].addChild( Gaffer.NameValuePlug( "remoteDisplayType", Gaffer.StringPlug( "value", defaultValue = 'GafferImage::GafferDisplayDriver', flags = Gaffer.Plug.Flags.Default | Gaffer.Plug.Flags.Dynamic, ), "remoteDisplayType", Gaffer.Plug.Flags.Default | Gaffer.Plug.Flags.Dynamic ) )
__children["Outputs"]["outputs"]["output1"]["parameters"].addChild( Gaffer.NameValuePlug( "displayHost", Gaffer.StringPlug( "value", defaultValue = 'localhost', flags = Gaffer.Plug.Flags.Default | Gaffer.Plug.Flags.Dynamic, ), "displayHost", Gaffer.Plug.Flags.Default | Gaffer.Plug.Flags.Dynamic ) )
__children["Outputs"]["outputs"]["output1"]["parameters"].addChild( Gaffer.NameValuePlug( "driverType", Gaffer.StringPlug( "value", defaultValue = 'ClientDisplayDriver', flags = Gaffer.Plug.Flags.Default | Gaffer.Plug.Flags.Dynamic, ), "driverType", Gaffer.Plug.Flags.Default | Gaffer.Plug.Flags.Dynamic ) )
__children["Outputs"]["outputs"]["output1"]["parameters"].addChild( Gaffer.NameValuePlug( "displayPort", Gaffer.StringPlug( "value", defaultValue = '${image:catalogue:port}', flags = Gaffer.Plug.Flags.Default | Gaffer.Plug.Flags.Dynamic, ), "displayPort", Gaffer.Plug.Flags.Default | Gaffer.Plug.Flags.Dynamic ) )
__children["Outputs"]["outputs"]["output1"]["parameters"].addChild( Gaffer.NameValuePlug( "quantize", Gaffer.IntVectorDataPlug( "value", defaultValue = IECore.IntVectorData( [ 0, 0, 0, 0 ] ), flags = Gaffer.Plug.Flags.Default | Gaffer.Plug.Flags.Dynamic, ), "quantize", Gaffer.Plug.Flags.Default | Gaffer.Plug.Flags.Dynamic ) )
__children["Outputs"]["outputs"]["output1"]["parameters"].addChild( Gaffer.NameValuePlug( "catalogue:imageName", Gaffer.StringPlug( "value", defaultValue = 'Image', flags = Gaffer.Plug.Flags.Default | Gaffer.Plug.Flags.Dynamic, ), "catalogue_imageName", Gaffer.Plug.Flags.Default | Gaffer.Plug.Flags.Dynamic ) )
__children["Outputs"].addChild( Gaffer.V2fPlug( "__uiPosition", defaultValue = imath.V2f( 0, 0 ), flags = Gaffer.Plug.Flags.Default | Gaffer.Plug.Flags.Dynamic, ) )
__children["Sphere"] = GafferScene.Sphere( "Sphere" )
parent.addChild( __children["Sphere"] )
__children["Sphere"].addChild( Gaffer.V2fPlug( "__uiPosition", defaultValue = imath.V2f( 0, 0 ), flags = Gaffer.Plug.Flags.Default | Gaffer.Plug.Flags.Dynamic, ) )
__children["Loop"] = Gaffer.Loop( "Loop" )
parent.addChild( __children["Loop"] )
__children["Loop"].setup( GafferScene.ScenePlug( "in", ) )
__children["Loop"].addChild( Gaffer.V2fPlug( "__uiPosition", defaultValue = imath.V2f( 0, 0 ), flags = Gaffer.Plug.Flags.Default | Gaffer.Plug.Flags.Dynamic, ) )
__children["CopyOptions"] = GafferScene.CopyOptions( "CopyOptions" )
parent.addChild( __children["CopyOptions"] )
__children["CopyOptions"].addChild( Gaffer.V2fPlug( "__uiPosition", defaultValue = imath.V2f( 0, 0 ), flags = Gaffer.Plug.Flags.Default | Gaffer.Plug.Flags.Dynamic, ) )
__children["InteractiveArnoldRender"]["in"].setInput( __children["Outputs"]["out"] )
__children["InteractiveArnoldRender"]["__uiPosition"].setValue( imath.V2f( 47.110733, -75.0068512 ) )
__children["Group"]["in"][0].setInput( __children["Sphere"]["out"] )
__children["Group"]["in"][1].setInput( __children["Camera"]["out"] )
__children["Group"]["__uiPosition"].setValue( imath.V2f( 47.1103745, -41.2640228 ) )
__children["Camera"]["transform"]["translate"].setValue( imath.V3f( 0, 0, 3.50999999 ) )
__children["Camera"]["__uiPosition"].setValue( imath.V2f( 56.0991745, -33.0999603 ) )
__children["StandardOptions"]["in"].setInput( __children["Group"]["out"] )
__children["StandardOptions"]["options"]["renderCamera"]["value"].setValue( '/group/camera' )
__children["StandardOptions"]["options"]["renderCamera"]["enabled"].setValue( True )
__children["StandardOptions"]["__uiPosition"].setValue( imath.V2f( 47.110733, -51.867466 ) )
__children["Catalogue"]["images"]["Image"]["fileName"].setValue( '/home/danield/gaffer/projects/default/catalogues/slowCrop/f03eb392ce95c65d6ea6039bf6672496.exr' )
__children["Catalogue"]["directory"].setValue( '${project:rootDirectory}/catalogues/${script:name}' )
__children["Catalogue"]["__uiPosition"].setValue( imath.V2f( 72.3916397, -73.5052338 ) )
__children["Outputs"]["in"].setInput( __children["Loop"]["out"] )
__children["Outputs"]["outputs"]["output1"]["name"].setValue( 'Interactive/Beauty' )
__children["Outputs"]["outputs"]["output1"]["fileName"].setValue( 'beauty' )
__children["Outputs"]["outputs"]["output1"]["type"].setValue( 'ieDisplay' )
__children["Outputs"]["outputs"]["output1"]["data"].setValue( 'rgba' )
__children["Outputs"]["__uiPosition"].setValue( imath.V2f( 47.1110306, -63.4367943 ) )
__children["Sphere"]["__uiPosition"].setValue( imath.V2f( 44.1103745, -33.0999603 ) )
__children["Loop"]["in"].setInput( __children["StandardOptions"]["out"] )
Gaffer.Metadata.registerValue( __children["Loop"]["in"], 'noduleLayout:section', 'top' )
Gaffer.Metadata.registerValue( __children["Loop"]["out"], 'noduleLayout:section', 'bottom' )
__children["Loop"]["next"].setInput( __children["CopyOptions"]["out"] )
Gaffer.Metadata.registerValue( __children["Loop"]["next"], 'noduleLayout:section', 'top' )
Gaffer.Metadata.registerValue( __children["Loop"]["previous"], 'noduleLayout:section', 'bottom' )
__children["Loop"]["iterations"].setValue( 17 )
__children["Loop"]["__uiPosition"].setValue( imath.V2f( 60.8338776, -55.7017136 ) )
__children["CopyOptions"]["in"].setInput( __children["Loop"]["previous"] )
__children["CopyOptions"]["source"].setInput( __children["Loop"]["previous"] )
__children["CopyOptions"]["__uiPosition"].setValue( imath.V2f( 74.2369614, -63.8657761 ) )


del __children

@johnhaddon
Copy link
Member

Conceptually, I suppose the correct thing would be a second cache for the plugs where forceMonitoring is true.

That's an interesting idea. We already kindof have a cache-within-a-cache with GAFFER_HASHCACHE_MODE=Checked, so could use the same mechanism? Alternatively, having two actual caches might not be too bad either.

I suppose the other way of doing it is to store a set of already-monitored-things in the monitor, and use that to turn caching back on after something has been monitored once?

@danieldresser-ie
Copy link
Contributor Author

The GAFFER_HASHCACHE_MODE approach doesn't make it easy to clear just the monitored caches when started a new monitored process - we don't want to share caches with other monitors, only ourselves.

After thinking about it a bit more, I was starting to lean towards the "set of already-monitored-things". Should this set be held by CapturingMonitor or by ValuePlug::ComputeProcess? Do we want to allow the possibility that someone might want some kind of monitor that can visit a node more than once? I think this would always be a bad idea in a production graph.

@johnhaddon
Copy link
Member

Should this set be held by CapturingMonitor or by ValuePlug::ComputeProcess?

CapturingMonitor I think - it's the only monitor with this requirement, and it it will involve some overhead we wouldn't want to pay at any other time.

@johnhaddon
Copy link
Member

I've just found a very similar pattern in another production setup. I think we're going to have to do this "set of already-monitored-things".

johnhaddon added a commit to johnhaddon/gaffer that referenced this issue Aug 8, 2024
johnhaddon added a commit to johnhaddon/gaffer that referenced this issue Aug 8, 2024
johnhaddon added a commit to johnhaddon/gaffer that referenced this issue Aug 9, 2024
This gives us the following pleasing performance improvement :

```
testHistoryDiamondPerformance (GafferSceneTest.SceneAlgoTest.SceneAlgoTest) : was 9.11s now 0.00s (100% reduction)
```

As noted in the comment, this does mean that we're now returning a reduced history, but we don't anticipate this being a problem in practice. Clients such as `attributeHistory()` aim to whittle the graph down to a single path relevant to a particular attribute, and our HistoryWindow only shows a single linear history anyway. The histories we're returning now are a closer match for the ones we returned prior to GafferHQ#4568, while retaining the main benefit of that PR - the evaluations of thing we're not trying to track are still pulled from the cache if possible.

Fixes GafferHQ#5199
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants