Proof of Concept Insights - (Apparent) Race condition on disconnecting animated nodes

# Context 

The following exception is being thrown _at random_ during E2E tests:

```
Exception thrown while executing UI block: 'parentNode' is a required parameter
```

```
__44-[RCTUIManager flushUIBlocksWithCompletion:]_block_invoke
    RCTUIManager.m:1201
__44-[RCTUIManager flushUIBlocksWithCompletion:]_block_invoke.498
__RCTExecuteOnMainQueue_block_invoke
____detox_sync_dispatch_wrapper_block_invoke
_dispatch_call_block_and_release
_dispatch_client_callout
_dispatch_main_queue_drain
_dispatch_main_queue_callback_4CF
__CFRUNLOOP_IS_SERVICING_THE_MAIN_DISPATCH_QUEUE__
__CFRunLoopRun
CFRunLoopRunSpecific
GSEventRunModal
-[UIApplication _run]
__detox_sync_UIApplication_run
UIApplicationMain
main
start_sim
0x0
0x0
````

# Investigation

## Building and running the E2E tests

```bash
detox build -c ios.sim.debug
detox test -c ios.sim.debug -l trace
```

## Logging of the application

* Command

```bash
/usr/bin/xcrun simctl spawn 7BC04173-BF0C-43FD-B02A-0D7DCF1B4893 log stream --level debug --style compact --predicate 'process == "MetaMask"'
````

* We find the cause of the exception to be at `RCTNativeAnimatedNodesManager.m:140`.

```
2022-08-02 23:02:31.998 Df MetaMask[84277:10fd37] (Foundation) *** Assertion failure in -[RCTNativeAnimatedNodesManager disconnectAnimatedNodes:childTag:](), /Users/bentobox/Documents/dev/mm/mobile/node_modules/react-native/Libraries/NativeAnimation/RCTNativeAnimatedNodesManager.m:140

2022-08-02 23:02:31.998 E  MetaMask[84277:10fd37] [com.facebook.react.log:native] Exception thrown while executing UI block: 'parentNode' is a required parameter
```

* The code at that function is

```objective-c

- (void)disconnectAnimatedNodes:(nonnull NSNumber *)parentTag
                       childTag:(nonnull NSNumber *)childTag
{
  RCTAssertParam(parentTag);
  RCTAssertParam(childTag);

  RCTAnimatedNode *parentNode = _animationNodes[parentTag];
  RCTAnimatedNode *childNode = _animationNodes[childTag];

  RCTAssertParam(parentNode);
  RCTAssertParam(childNode);

  [parentNode removeChild:childNode];
  [childNode setNeedsUpdate];
}
```

* The line `RCTAssertParam(parentNode);` is a failing assertion. We further explore by adding logs, and rebuilding the RN app.

```objective-c
#import <React/RCTLog.h>
- (void)disconnectAnimatedNodes:(nonnull NSNumber *)parentTag
                       childTag:(nonnull NSNumber *)childTag
{
  
  RCTLogInfo(@"disconnectAnimatedNodes (Tag) - %@ - %@ +", parentTag, childTag);

  RCTAssertParam(parentTag);
  RCTAssertParam(childTag);

  RCTAnimatedNode *parentNode = _animationNodes[parentTag];
  RCTAnimatedNode *childNode = _animationNodes[childTag];

  RCTLogInfo(@"disconnectAnimatedNodes (parentNode) - %@ - %@ +", parentNode, childNode);

  RCTAssertParam(parentNode);
  RCTAssertParam(childNode);

  [parentNode removeChild:childNode];
  [childNode setNeedsUpdate];
}
```

* However there is not a lot of evidence for a race condition.
* After some investigation, we find the caller of this function to be at `./node_modules/react-native/Libraries/NativeAnimation/Nodes/RCTStyleAnimatedNode.m:disconnectAnimatedNodes`.

```js
  __removeChild(child: AnimatedNode): void {
    const index = this._children.indexOf(child);
    if (index === -1) {
      console.warn("Trying to remove a child that doesn't exist");
      return;
    }
    if (this.__isNative && child.__isNative) {
      NativeAnimatedHelper.API.disconnectAnimatedNodes(
        this.__getNativeTag(),
        child.__getNativeTag(),
      );
    }
    this._children.splice(index, 1);
    if (this._children.length === 0) {
      this.__detach();
    }
  }
```

* After adding a log (`yarn watch` will just rebuild the bundle) and restart the test we find the start of a proof:
* Notice the one that produces the exception

```bash
2022-08-03 03:06:04.656 I  MetaMask[63634:158457] [com.facebook.react.log:native] b. disconnectAnimatedNodes - (null) - (null) +
```

* Let's see the error

```bash
2022-08-03 04:06:17.676 I  MetaMask[66774:1610a2] [com.facebook.react.log:native] disconnectAnimatedNodes (Tag) - 11502 - 11503 +
2022-08-03 04:06:17.677 I  MetaMask[66774:1610a2] [com.facebook.react.log:native] disconnectAnimatedNodes (Node) - (null) - (null) +
```

* We want to find out when the parent was deleted

```bash
2022-08-03 04:06:17.666 I  MetaMask[66774:1610db] [com.facebook.react.log:javascript] '__removeChild', 10446, 11502
```

# Early Conclusions

* This call was issued before the call within RN. We believe, in parallel there is another call to get rid of the object, which produces the result to `RCTAnimatedNode *parentNode = _animationNodes[parentTag];` to be null. More investigation is needed to find the real root cause. For now this is the issued fix

```objective-c
- (void)disconnectAnimatedNodes:(nonnull NSNumber *)parentTag
                       childTag:(nonnull NSNumber *)childTag
{
  RCTAssertParam(parentTag);
  RCTAssertParam(childTag);

  RCTAnimatedNode *parentNode = _animationNodes[parentTag];
  RCTAnimatedNode *childNode = _animationNodes[childTag];

  // Temporary patch!
  // There is a race condition after removing
  // the promise polifill and transform-regenerator.
  //
  // We'll set the investigation of the root cause
  // as technical debt.
  //
  // The caller is at node_modules/react-native/Libraries/
  //   /Animated/nodes/AnimatedWithChildren.js:__removeChild
  if (parentNode) {
    [parentNode removeChild:childNode];
  }

  if (childNode) {
    [childNode setNeedsUpdate];
  }
}
```

# Further Facts

* Different experiments were performed to determine the root cause of the exception.

## Testing different patches over `main`

* We took the `main` branch, and by only applying this patch into it we were able to obtain the error

```diff
diff --git a/node_modules/metro-react-native-babel-preset/src/configs/main.js b/node_modules/metro-react-native-babel-preset/src/configs/main.js
index caa45fe..8eeb742 100644
--- a/node_modules/metro-react-native-babel-preset/src/configs/main.js
+++ b/node_modules/metro-react-native-babel-preset/src/configs/main.js
@@ -174,16 +174,6 @@ const getPreset = (src, options) => {
     extraPlugins.push([require("@babel/plugin-transform-react-jsx-self")]);
   }

-  if (!options || options.enableBabelRuntime !== false) {
-    extraPlugins.push([
-      require("@babel/plugin-transform-runtime"),
-      {
-        helpers: true,
-        regenerator: !isHermes
-      }
-    ]);
-  }
-
   return {
     comments: false,
     compact: true,
@@ -196,7 +186,6 @@ const getPreset = (src, options) => {
       {
         plugins: [
           ...defaultPluginsBeforeRegenerator,
-          isHermes ? null : require("@babel/plugin-transform-regenerator"),
           ...defaultPluginsAfterRegenerator
         ].filter(Boolean)
       },
```

* Further investigation including the patch `react-native+0.66.3.patch`, which ,among other things, comments the promise polifill gave the following results.
  * Commenting _only_ the promise polifill makes the exception appear.
  * Removal _only_ of `@babel/plugin-transform-runtime` won't make the exception appear.
  * Removal _only_ of `@babel/plugin-transform-regenerator` makes the exception appear.

* It is important to stress the fact that these are tests over a patched `main` branch. These three patches are fundamental to the working of ses in the react native contect.

## Stack trace of `__removeChild`

* Obtainable with `console.log(new Error().stack);`

* Needs further study.

```bash
Error@http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=io.metamask.MetaMask:7802:32
__removeChild@http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=io.metamask.MetaMask:75008:32
__detach@http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=io.metamask.MetaMask:78559:32
__removeChild@http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=io.metamask.MetaMask:75017:24
__detach@http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=io.metamask.MetaMask:78342:32
_attachProps@http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=io.metamask.MetaMask:78062:38
UNSAFE_componentWillReceiveProps@http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=io.metamask.MetaMask:78127:28
callComponentWillReceiveProps@http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=io.metamask.MetaMask:20553:52
updateClassInstance@http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=io.metamask.MetaMask:20725:42
updateClassComponent@http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=io.metamask.MetaMask:24627:45
beginWork$1@http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=io.metamask.MetaMask:29655:29
performUnitOfWork@http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=io.metamask.MetaMask:29066:29
workLoopSync@http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=io.metamask.MetaMask:29005:28
renderRootSync@http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=io.metamask.MetaMask:28981:25
performSyncWorkOnRoot@http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=io.metamask.MetaMask:28742:40
performSyncWorkOnRoot@[native code]
flushSyncCallbacks@http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=io.metamask.MetaMask:19068:36
flushSyncCallbacksOnlyInLegacyMode@http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=io.metamask.MetaMask:19049:29
batchedUpdates$1@http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=io.metamask.MetaMask:28790:47
batchedUpdates@http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=io.metamask.MetaMask:16630:36
notify@http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=io.metamask.MetaMask:603478:14
notifyNestedSubs@http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=io.metamask.MetaMask:603549:28
handleChangeWrapper@http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=io.metamask.MetaMask:603554:27
handleChangeWrapper@[native code]
dispatch@http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=io.metamask.MetaMask:550882:17
update_bg_state_cb@http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=io.metamask.MetaMask:553331:32
@http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=io.metamask.MetaMask:376859:19
forEach@[native code]
notify@http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=io.metamask.MetaMask:376858:39
update@http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=io.metamask.MetaMask:376881:20
@http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=io.metamask.MetaMask:432894:22
generatorResume@[native code]
fulfilled@http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=io.metamask.MetaMask:432776:30
promiseReactionJob@[native code]
```


Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Proof of Concept Insights - (Apparent) Race condition on disconnecting animated nodes #9

Context

Investigation

Building and running the E2E tests

Logging of the application

Early Conclusions

Further Facts

Testing different patches over `main`

Stack trace of `__removeChild`

Metadata

Assignees

Labels

Type

Fields

Projects

Milestone

Relationships

Development

Proof of Concept Insights - (Apparent) Race condition on disconnecting animated nodes #9

Description

Context

Investigation

Building and running the E2E tests

Logging of the application

Early Conclusions

Further Facts

Testing different patches over main

Stack trace of __removeChild

Metadata

Metadata

Assignees

Labels

Type

Fields

Projects

Milestone

Relationships

Development

Issue actions

Testing different patches over `main`

Stack trace of `__removeChild`