CustomNodes that replicate do not access trace correctly. #11244

mjkkirschner · 2020-11-12T21:53:36Z

Purpose

https://jira.autodesk.com/browse/DYN-1726

I found while investigating this issue that during execution of a nested node which accesses trace and creates elements (lets call this nodeT) - that the callsite which is created for nodeT contains an invokeCount field - this field is incremented each time the callsite is accessed "within a single run".

Unfortunately, when nodeT is nested inside a customNode or any DSFunction which is represented by a JILFunctionEndpoint - the invokeCount field is reset to 0 when the function is called.

This means that when a JILFunctionEndPoint is replicated, each replicated call, results in nested function calls reseting their callsites's invokeCount to 0.

When this occur the resulting execution results and trace data are both replaced with the last function call result.

Update:

I've fallen back to adding a new internal field to RuntimeCore - LastDispatchedCallSite which is set to the this inside of DispatchNew- before resetting the invokeCount we check if the last callsite was the same as the current callsite - if this is the case we're very likely in some type of replicated or nested replicated call - so don't reset the invoke count.

When the callsites are out of sync we've moved on to a new callsite, and we should reset the invoke count - this takes care of the cases where we execute the graph more than once, or execute a function using associative update (without the execution actually ending, and yet still returning to a previous callsite).

I tried to use the existing property RuntimeCore.DSExecutable.ExecutinGraphNode - but by the time we can check this, it's already been set to the same graphnode that represents the current callsite, so it's not useful for this check.

I'd like to return to this in the future to investigate why the entire contents of InterperterProperties is always null, because it contains a stack of executingGraphNodes which should be able to tell us what graphNodes executed in what order - but it seems to be reset to null for a reason in multiple places, and appears to hold up lots of other things, like callsite ids... I think refactoring that is out of scope for now, and I will file a task to investigate it. Unfortunately, it looks like it is unchanged from when Luke first merged it into Dynamo in 2014, so no helpful git history.

Declarations

Check these if you believe they are true

The codebase is in a better state after this PR
Is documented according to the standards
The level of testing this PR includes is appropriate
User facing strings, if any, are extracted into *.resx files
All tests pass using the self-service CI.
Snapshot of UI changes, if any.
Changes to the API follow Semantic Versioning and are documented in the API Changes document.
This PR modifies some build requirements and the readme is updated

more tests

mjkkirschner · 2020-11-12T22:02:41Z

I'm moving this PR to open - because it looks like the API used to check for all pullrequests does not treat draft prs as "open"

src/Engine/ProtoCore/Lang/CallSite.cs

src/Engine/ProtoScript/Runners/LiveRunner.cs

mjkkirschner · 2020-11-13T18:55:33Z

There are some failing test cases here - that seem to use associative update to trigger executions of those same FEPs - the test has a comment that seems to conflict with what I understand about callsites - it needs more thought if this solution will work.

I'm not sure supporting associative update matters any longer as you can no longer redefine variables in associative codeblocks - obviously the test still runs though when run through the protoscript runner just fine... 😕

src/Engine/ProtoScript/Runners/LiveRunner.cs

use new field - cant find a better way currently add comments

update test

mjkkirschner · 2020-11-19T02:15:45Z

much easier to review this with whitespace changes off:
https://github.com/DynamoDS/Dynamo/pull/11244/files?diff=unified&w=1

aparajit-pratap · 2020-11-19T02:24:48Z

src/Engine/ProtoCore/Lang/CallSite.cs

+            // if the last dispatched callsite is this callsite then we are repeatedly making calls
+            // to this same callsite (for example replicating over an outer function that contains this callsite)
+            // and should not reset the invoke count.
+            if (runtimeCore.LastDispatchedCallSite != this)


Did this not work:

if(this.id != runtimeCore.DSExecutable.ExecutingGraphnode.CallsiteIdentifier) {...}

yes, as stated above, I found this did not work - the ExecutingGraphNode on the executable has already been set to the current callsite - so it's too late, we really need the LastGraphNode - not the current one.

mjkkirschner · 2020-11-19T15:52:51Z

I'm looking into the test failure - it seems unrelated to these changes as it deals with serialization of inputs... but will track it down.

mjkkirschner · 2020-11-19T21:20:41Z

@aparajit-pratap @pinzart - test failure should be resolved latest commit - I believe what was happening was as follows:

The serialization tests grab the first 300 dyn files in the repo - I added new .dyn files, so this changed which tests ran.
Some of the tests don't fully run, for example if they have dummy nodes.
There is a map that contains guids and ids that some tests may update to fully test parts of id deserialization.
This map was not being cleared so previous test runs were affecting other tests -
This could happen for a few different reasons - like if a test did not fully run, or if the last test run populated the map - but did not clear it before the next test methods, changing the order of tests etc.

In any case, to avoid this in the future, all serialization tests now clear this map before the run.

pinzart90 · 2020-11-20T14:02:14Z

@mjkkirschner @aparajit-pratap I may have this wrong, but here's my 2 cents:

Each function call (represented by a unique callsite), from running a graph, will generate trace data (persisted in callsite). This trace data is used to enable binding to elements.
So if a function call - callsite X - (with replication or without) generates n number of traces, then it could bind to n number of elements. - I think....
If you have a subsequent call to callsite X that generates n + 1 traces, then we should reuse the first n preexisting traces, and generate 1 additional one.
I think this is where the invokeCount mechanism steps in.

Regarding the invokeCount mechanism:
From what I can tell, invokeCount is supposed to represent the number of times a callsite has been called into during one execution of the graph.
This is a bit weird because invokeCount is persisited in callSites, but it seems to be more suited as transitory data (execution context). Anyway...

I think the design was to set invokeCount to 0 when first calling into a function or callsite. Then keep incrementing invokeCount for however many times we replicate that call.
I guess no one accounted for the fact that recursion can reset the invokeCount.

Regarding your change:
If you take the simple case of a non replicating function call foo().
Because invokeCount is persited data (callsites are persisted too) then each Graph run will keep incrementing invokeCount with no reset (because this === LastDispatchedCallSite).
This in turn will cause the callsite to keep adding trace data after each execution.
Execute the same function 5 times will result in invokeCount=5 and 5 traceData.
Before your change, invokeCount was always reset to 0.

sm6srw

@pinzart90 summed it up quite good. To me, it looks like this scenario has never worked as intended and was never considered when invokeCount was implemented. I think the proposed fix is OK for now and we can decide to do a bigger refactoring later if and when we run into any new regressions because of it. LGTM!

pinzart90 · 2020-11-20T14:57:15Z

What I would highlight is that if you have a graph with a single node (with single callsite) that is supposed to do element binding, the your PR will change the behavior (with your changes, each execution of the graph will also create a new trace data - which in turn would mean that a new element will be created). Can you test this case out @mjkkirschner ?

aparajit-pratap

Regarding your change:
If you take the simple case of a non replicating function call foo().
Because invokeCount is persited data (callsites are persisted too) then each Graph run will keep incrementing invokeCount with no reset (because this === LastDispatchedCallSite).

@pinzart ~~in this case, each graph run, even if it's to the same function will result in a new callsite so it will not match with LastDispatchedCallSite~~ I was wrong about this. Sorry.

aparajit-pratap · 2020-11-19T23:23:06Z

src/Engine/ProtoScript/Runners/LiveRunner.cs

@@ -1354,6 +1354,7 @@ private void PostExecution()
            HandleWarnings();
        }

+


I think we should just revert this file.

mjkkirschner · 2020-11-20T16:17:53Z

@pinzart I can test that case - that could be a problem yes, I will add a test - one solution I guess is to reset LastDispatchedCallsite to null after the execution or at the start of an execution.

pinzart90 · 2020-11-20T16:18:44Z

Regarding your change:
If you take the simple case of a non replicating function call foo().
Because invokeCount is persited data (callsites are persisted too) then each Graph run will keep incrementing invokeCount with no reset (because this === LastDispatchedCallSite).

@pinzart in this case, each graph run, even if it's to the same function will result in a new callsite so it will not match with LastDispatchedCallSite

From what I've seen, callsites are cached and stored in a map. If a subsequent run is made to the same function, it should re use an existing callsite. So a single function foo called multiple times with different input params should go to the same callsite. Is this not correct ?

mjkkirschner · 2020-11-20T16:21:44Z

@aparajit-pratap - isn't it?
The callsites are not recreated - the callsiteCache is used from inside the GetCallSite function and those existing callsites are retrieved, isn't that how trace works?

mjkkirschner · 2020-11-20T16:53:57Z

@pinzart your suggested example case fails - I will look into solutions, only thing that comes to mind is resetting the LastCallSite between executions. Any other ideas?

I guess as you suggested above moving the invoke count out of the callsite altogether might be a refactor worth doing in the future?

pinzart90

LGTM

* Fix sorting for number keys in List.SortByKey (DynamoDS#11241) * fix sorting for number keys in List.SortByKey * add unit test * Crash when accessing static hidden methods from zero touch nodes (DynamoDS#11238) * handle hidden static methods from zero touch nodes * add images (DynamoDS#11243) * Revert "Adding copy of missing file from LibG nuget package (DynamoDS#11218)" (DynamoDS#11254) This reverts commit a71b5c8. * Revert "Revert "Adding copy of missing file from LibG nuget package (DynamoDS#11218)" (DynamoDS#11254)" (DynamoDS#11255) This reverts commit 257ac14. * Undock/redock extension tabs to windows (DynamoDS#11246) * Somewhat working version * Pretty much working version * Finishing touches and test * Cleanup * Prevent both window and tab * Improve method name and comment * Forgot to include this in last commit * add analytics to extensions load event (DynamoDS#11258) * Revert Project Reference Changes (DynamoDS#11256) * Initial Commit * fix mono build * Update to latest libG nuget version * Cleanup entries VS Studio failed to update * Fix Mono build * Add the private flag back (modified by VS Studio) * Regressions * Add back missing resource * Change DefaultValue setter to public (DynamoDS#11251) * update load asm binaries from registry logic (DynamoDS#11261) * update load asm binaries from registry * Add coverage for docking (DynamoDS#11262) * Adding a public API on the View extension that gets triggered when the view extension is closed. (DynamoDS#11260) * Adding a public API on the View extension that gets triggered when the view extension is closed. * Update variable name * changing the name to ViewExtensionBaseClass * Addressing some comments. * Adding unit test. * Changing the name to Closed() * Some more comments. * Adding an additional test * Adding checks for the Menu items before setting its value. * Update Style (DynamoDS#11263) * CustomNodes that replicate do not access trace correctly. (DynamoDS#11244) * add failing test * this works, but seems like cheating. more tests * new tests, one failing, needs discussion * fix test - still fails but as expected * tests all pass with this change - but looking for better alternatives * add test use new field - cant find a better way currently add comments * revert internal update test * reset guid map before each test * failing test * reset * whitespace * Localize buttons (DynamoDS#11265) * update version num and tt file (DynamoDS#11269) * Fix merge error * Fix merge error * Revert "Fix merge error" This reverts commit 0a21ca4. Co-authored-by: aparajit-pratap <aparajit.pratap@autodesk.com> Co-authored-by: pinzart90 <46732933+pinzart90@users.noreply.github.com> Co-authored-by: Sylvester Knudsen <sylvesterknudsen@gmail.com> Co-authored-by: Aaron (Qilong) <173288704@qq.com> Co-authored-by: Michael Kirschner <mjk.kirschner@gmail.com> Co-authored-by: Martin Misol Monzo <mmisol@users.noreply.github.com> Co-authored-by: Ashish Aggarwal <aggarwal.ash@husky.neu.edu> Co-authored-by: reddyashish <43763136+reddyashish@users.noreply.github.com>

* add packageDocManager to handle package documentation links * new viewModelEventArgs to send node annotation data to doc browser * Handle node annotation in doc browser * support custom NodeModels + fix watcher event bug * Update NodeAnnotationNotFound.md * Update NodeAnnotationNotFound.md * Comment updates * Update AssemblySharedInfo.cs * Update src/DynamoCoreWpf/ViewModels/Core/DynamoViewModelEventArgs.cs * addtional comment updates + clean up * clean up packageDocManager * Update DocumentationBrowserViewModel.cs * handle overloads + fix hot reload bug * use HtmlSanitizer to clean potential dangerous content from markdown files * move PackageDocumentationManager to DocumentationBrowser * update syntax highlighting + markdownStyling updates * comment updates * add Markdig to License files * Change GetPackageName to GetMainCategory * update markdig + htmlsanitizer version * fix failing tests + add new node documentaion tests * fix broken test * update link to wiki * Update DocumentationBrowserViewExtension.cs * Add MD2HTML Tool * First pass - singleton version * Revert "Add MD2HTML Tool" This reverts commit 71509da. * Revert "First pass - singleton version" This reverts commit bbefc36. * fix test * add doc folder to PackageDirectoryBuilder (#10) * add doc folder to PackageDirectoryBuilder * update tests * comment update * Use a CLI tool for converting MD to HTML and for Sanitizing HTML as a way to not add any new 3rd party dependencies to Dynamo (#11) * Revert "Revert "Add MD2HTML Tool"" This reverts commit 99b42f2. * Revert "Revert "First pass - singleton version"" This reverts commit f655c39. * Implement HTML Sanitizer * Remove unneeded dependecies from the doc extension * Cleanup naming * More naming cleanups * Rename files * Rename folder * Add comments * Use literal strings * Hardening wrapper class * Simplify API * Make wrapper API internal * Add Tools project to Mono solution * Fix directory name (case) * Add missing internal * Use IDispose pattern * Fix literal string * Fix cross platform issues * Use CS.props file * Undo change to AssemblySharedInfo.cs * Use shared assembly info * Add more docs * Add ndesk support and implement help option * Rename class * Add missing change * Remove the use of ref * Fix typo * Fix toolpath and use nameof() * Improve error handling * Move strings to resources * Enhance error messages * Merge master (#12) * Fix sorting for number keys in List.SortByKey (#11241) * fix sorting for number keys in List.SortByKey * add unit test * Crash when accessing static hidden methods from zero touch nodes (#11238) * handle hidden static methods from zero touch nodes * add images (#11243) * Revert "Adding copy of missing file from LibG nuget package (#11218)" (#11254) This reverts commit a71b5c8. * Revert "Revert "Adding copy of missing file from LibG nuget package (#11218)" (#11254)" (#11255) This reverts commit 257ac14. * Undock/redock extension tabs to windows (#11246) * Somewhat working version * Pretty much working version * Finishing touches and test * Cleanup * Prevent both window and tab * Improve method name and comment * Forgot to include this in last commit * add analytics to extensions load event (#11258) * Revert Project Reference Changes (#11256) * Initial Commit * fix mono build * Update to latest libG nuget version * Cleanup entries VS Studio failed to update * Fix Mono build * Add the private flag back (modified by VS Studio) * Regressions * Add back missing resource * Change DefaultValue setter to public (#11251) * update load asm binaries from registry logic (#11261) * update load asm binaries from registry * Add coverage for docking (#11262) * Adding a public API on the View extension that gets triggered when the view extension is closed. (#11260) * Adding a public API on the View extension that gets triggered when the view extension is closed. * Update variable name * changing the name to ViewExtensionBaseClass * Addressing some comments. * Adding unit test. * Changing the name to Closed() * Some more comments. * Adding an additional test * Adding checks for the Menu items before setting its value. * Update Style (#11263) * CustomNodes that replicate do not access trace correctly. (#11244) * add failing test * this works, but seems like cheating. more tests * new tests, one failing, needs discussion * fix test - still fails but as expected * tests all pass with this change - but looking for better alternatives * add test use new field - cant find a better way currently add comments * revert internal update test * reset guid map before each test * failing test * reset * whitespace * Localize buttons (#11265) * update version num and tt file (#11269) * Fix merge error * Fix merge error * Revert "Fix merge error" This reverts commit 0a21ca4. Co-authored-by: aparajit-pratap <aparajit.pratap@autodesk.com> Co-authored-by: pinzart90 <46732933+pinzart90@users.noreply.github.com> Co-authored-by: Sylvester Knudsen <sylvesterknudsen@gmail.com> Co-authored-by: Aaron (Qilong) <173288704@qq.com> Co-authored-by: Michael Kirschner <mjk.kirschner@gmail.com> Co-authored-by: Martin Misol Monzo <mmisol@users.noreply.github.com> Co-authored-by: Ashish Aggarwal <aggarwal.ash@husky.neu.edu> Co-authored-by: reddyashish <43763136+reddyashish@users.noreply.github.com> * Extract more strings (#13) * Fix failing tests (#14) * Fix failing tests * Revert "Fix failing tests" This reverts commit 824f785. * Fix failing tests * Properly dispose all string writers * More failing test fixes (#15) * Fix for regression in multi-output node preview (#11266) * fix for multi-output node preview regression * update tests * add test * revert unwanted changes * update test * Life cycle refactoring: Get rid of singleton. Let the model create and own the MarkdownHandler on first use. * Fix crash in some document browser tests * Properly dispose all DocumentBrowserViewExtension objects * Revert "Fix crash in some document browser tests" This reverts commit ab146f9. * Display input port type specific default suggestions only (#11268) * input port type specific default suggestions * test fix * Test fixes * Use InTestMode flag * Delete empty lines * turn off hit testing visibility for DM related render packages (#11282) * Apply syntax highlighting to multi-line strings (#11289) * Also sanitize node documentation html * Save/Load view extension size and location (#11278) Information of where an extension control was last shown is saved and retrieved as preference settings. These are actually not directly visible for the user and are updating automatically, just like the main Dynamo window size. These settings are used when showing the extension control, to restore it to how it used to be before closing it. The available information for each view extension is: 1. How it is shown. For now this can be either as a floating window or docked to the right-side panel. 2. In case it is shown as a floating window, the following information about the window is saved: - Location by Top/Left coordinates - Size by Width/Height - Whether the window is maximized * add revit dlls to assembly conflict checker ignore list (#11285) * Update StartupUtils.cs Co-authored-by: pinzart <tiberiu.pinzariu@autodesk.com> * Fix sanitizing log warnings * Node AutoComplete suggestions sorted alphabetically within the same group (#11280) * add/update tests * Address review comments * Add ILMerge * Fix typo * Fix mono build * Revert "Fix mono build" This reverts commit 9904525. * Refine mono solution * Remove task condition * Mono build fix * Add Readme Co-authored-by: aparajit-pratap <aparajit.pratap@autodesk.com> Co-authored-by: Ashish Aggarwal <aggarwal.ash@husky.neu.edu> Co-authored-by: Laurence Elsdon <github@elsdon.me> Co-authored-by: Martin Misol Monzo <mmisol@users.noreply.github.com> Co-authored-by: pinzart90 <46732933+pinzart90@users.noreply.github.com> Co-authored-by: pinzart <tiberiu.pinzariu@autodesk.com> Co-authored-by: Radu Gidei <radumg@users.noreply.github.com> Co-authored-by: Jorgen Dahl <jorgen.dahl@autodesk.com> Co-authored-by: Jorgen Dahl <sm6srw@users.noreply.github.com> Co-authored-by: aparajit-pratap <aparajit.pratap@autodesk.com> Co-authored-by: pinzart90 <46732933+pinzart90@users.noreply.github.com> Co-authored-by: Aaron (Qilong) <173288704@qq.com> Co-authored-by: Michael Kirschner <mjk.kirschner@gmail.com> Co-authored-by: Martin Misol Monzo <mmisol@users.noreply.github.com> Co-authored-by: Ashish Aggarwal <aggarwal.ash@husky.neu.edu> Co-authored-by: reddyashish <43763136+reddyashish@users.noreply.github.com> Co-authored-by: Laurence Elsdon <github@elsdon.me> Co-authored-by: pinzart <tiberiu.pinzariu@autodesk.com>

mjkkirschner added 2 commits November 10, 2020 19:20

add failing test

66a66c1

this works, but seems like cheating.

c1d8ee8

more tests

mjkkirschner marked this pull request as ready for review November 12, 2020 22:02

mjkkirschner added the WIP label Nov 12, 2020

mjkkirschner commented Nov 12, 2020

View reviewed changes

src/Engine/ProtoCore/Lang/CallSite.cs Show resolved Hide resolved

mjkkirschner commented Nov 12, 2020

View reviewed changes

src/Engine/ProtoScript/Runners/LiveRunner.cs Outdated Show resolved Hide resolved

mjkkirschner added 3 commits November 17, 2020 21:08

new tests, one failing, needs discussion

01a9ec9

fix test - still fails but as expected

d2b5923

tests all pass with this change - but looking for better alternatives

3190975

aparajit-pratap reviewed Nov 18, 2020

View reviewed changes

src/Engine/ProtoScript/Runners/LiveRunner.cs Outdated Show resolved Hide resolved

mjkkirschner added 2 commits November 18, 2020 20:40

add test

73be9a8

use new field - cant find a better way currently add comments

revert internal

617e87f

update test

mjkkirschner added PTAL Please Take A Look 👀 and removed WIP labels Nov 19, 2020

mjkkirschner requested a review from pinzart November 19, 2020 02:12

aparajit-pratap reviewed Nov 19, 2020

View reviewed changes

mjkkirschner changed the title ~~WIP CustomNodes that replicate do not access trace correctly.~~ CustomNodes that replicate do not access trace correctly. Nov 19, 2020

reset guid map before each test

992db6d

sm6srw approved these changes Nov 20, 2020

View reviewed changes

aparajit-pratap reviewed Nov 20, 2020

View reviewed changes

mjkkirschner added 2 commits November 20, 2020 11:54

failing test

e53da0e

reset

8e9e068

pinzart90 approved these changes Nov 20, 2020

View reviewed changes

aparajit-pratap approved these changes Nov 20, 2020

View reviewed changes

whitespace

3fe5f9c

mjkkirschner merged commit 8667008 into DynamoDS:master Nov 20, 2020

		@@ -1354,6 +1354,7 @@ private void PostExecution()
		HandleWarnings();
		}

CustomNodes that replicate do not access trace correctly. #11244

CustomNodes that replicate do not access trace correctly. #11244

Uh oh!

Conversation

mjkkirschner commented Nov 12, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Purpose

Declarations

Uh oh!

mjkkirschner commented Nov 12, 2020

Uh oh!

Uh oh!

Uh oh!

mjkkirschner commented Nov 13, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

Uh oh!

mjkkirschner commented Nov 19, 2020

Uh oh!

aparajit-pratap Nov 19, 2020

Choose a reason for hiding this comment

Uh oh!

mjkkirschner Nov 19, 2020

Choose a reason for hiding this comment

Uh oh!

mjkkirschner commented Nov 19, 2020

Uh oh!

mjkkirschner commented Nov 19, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

pinzart90 commented Nov 20, 2020

Uh oh!

sm6srw left a comment • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

pinzart90 commented Nov 20, 2020

Uh oh!

aparajit-pratap left a comment • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

aparajit-pratap Nov 19, 2020

Choose a reason for hiding this comment

Uh oh!

mjkkirschner Nov 20, 2020

Choose a reason for hiding this comment

Uh oh!

mjkkirschner commented Nov 20, 2020

Uh oh!

pinzart90 commented Nov 20, 2020

Uh oh!

mjkkirschner commented Nov 20, 2020

Uh oh!

mjkkirschner commented Nov 20, 2020 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

pinzart90 left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

mjkkirschner commented Nov 12, 2020 •

edited

Loading

mjkkirschner commented Nov 13, 2020 •

edited

Loading

mjkkirschner commented Nov 19, 2020 •

edited

Loading

sm6srw left a comment •

edited

Loading

aparajit-pratap left a comment •

edited

Loading

mjkkirschner commented Nov 20, 2020 •

edited

Loading