fix: setupControllerConnection outstream end event listener #26141

danjm · 2024-07-25T18:52:01Z

Description

This PR addresses a problem which had the following surface level symptoms: when the UI is closed, the extension continues to send network requests to the provider.

Upon some investigation, we discovered that these requests were the result of polling initiated from the account tracker. And then upon further investigation, we discovered that the callback in the outstream 'end' listener in setupControllerConnection of metamask-controller.js was not being called when the UI was closed.

This problem was introduced with #24533. That PR updates the object-multiplex dependency to v2.0.0. The major change in that update is the update of the readable-stream dependency from a v2 version to a v3 version. With that update, we see new premature-close errors in the background. It seems that these errors are still present in v2, but they are handled differently, resulting in an 'error' event instead of an 'end' event. We still have not established a definitive understanding of why this is happening, and follow up investigation will be needed.

However, this PR still puts forward a fix that safely resolves the issue. The solution added here is to make use of the readableStream.finished function. The callback passed to this function will be called when the stream is ended. This function has the same behaviour as the outstream.on('end' listener had prior to the aforementioned PR.

Instead of fully replacing the existing listener, we have added the readableStream.finished call in addition to the existing listener. The reason for this is explained in a code comment:

The presence of both of the below handlers may be redundant. After upgrading metamask/object-multiples to v2.0.0, which included an upgrade of readable-streams from v2 to v3, we saw that the outStream.on('end' handler was almost never being called. This seems to related to how v3 handles errors vs how v2 handles errors; there are "premature close" errors in both cases, although in the case of v2 they don't prevent outStream.on('end' from being called. At the time that this comment was committed, it was known that we need to investigate and resolve the underlying error, however, for expediency, we are not addressing them at this time. Instead, we can observe that readableStream.finished preserves the same functionality as we had when we relied on readable-stream v2. Meanwhile, the outStream.on('end' handler was observed to have been called at least once. As we do not yet fully understand the conditions under which both of these are being called, we include both handlers at the risk of redundancy. Logic has been added to the handler to ensure that calling it more than once does not have any affect.

To achieve "Logic has been added to the handler to ensure that calling it more than once does not have any affect.", the PR adds a unique id to each stream passed to setupControllerConnection, and uses a Set to ensure the handler code only runs once per stream.

This PR then adds automated tests. The added unit tests are focused on validating both pre-existing and new behaviour of setupControllerChanged. The added e2e tests focus on the inititially mentioned surface level symptoms: it confirms that eth_call and eth_getBalance calls, the calls coming from the account-tracker initiated polling, are not continued after the UI is closed. This e2e test fails on current develop but passes on this branch.

MetaMask team members can see more details in this thread: https://consensys.slack.com/archives/CTQAGKY5V/p1721653870583869

Related issues

Fixes: #26002

Manual testing steps

To observe the bug on develop:

Install and onboard
Open the service worker dev console and go to the network tab
Observe eth_call and eth_getBalance requests to infura
Close the UI, observe that the requests from step 3 continue

On this branch, in step 4, after closing the UI, those requests will not continue.

Screenshots/Recordings

Before

After

Pre-merge author checklist

I've followed MetaMask Contributor Docs and MetaMask Extension Coding Standards.
I've completed the PR template to the best of my ability
I’ve included tests if applicable
I’ve documented my code using JSDoc format if applicable
I’ve applied the right labels on the PR (see labeling guidelines). Not required for external contributors.

Pre-merge reviewer checklist

I've manually tested the PR (e.g. pull and build branch, run the app, test code being changed).
I confirm that this PR addresses all acceptance criteria described in the ticket it closes and includes the necessary testing evidence such as recordings and or screenshots.

…ection in metamask-controller.js is called when it should be

…requests to infura after the UI has closed

github-actions · 2024-07-25T18:52:12Z

CLA Signature Action: All authors have signed the CLA. You may need to manually re-run the blocking PR check if it doesn't pass in a few minutes.

Gudahtt · 2024-07-25T19:58:41Z

privacy-snapshot.json

For a later PR: We should consider sorting this with prettier (prettier-plugin-sort-json can do it)

privacy-snapshot.json

test/e2e/webdriver/chrome.js

legobeat · 2024-07-25T21:41:54Z

test/e2e/tests/api-usage/account-tracker-api-usage.spec.ts

+  ];
+}
+
+async function getAllInfuraJsonRpcRequests(


This looks nice and like it could be useful elsewhere!

privacy-snapshot.json

…r needed privacy snapshot addition

seaona · 2024-07-26T09:47:50Z

test/e2e/tests/api-usage/account-tracker-api-usage.spec.ts

+          mockedEndpoint,
+        );
+
+        await driver.openNewURL('chrome://extensions');


It looks like this makes the firefox test fail. Could we selectively go to:

Suggested change

await driver.openNewURL('chrome://extensions');

if (process.env.SELENIUM_BROWSER === 'chrome') {

await driver.openNewURL('chrome://extensions');

} else if (process.env.SELENIUM_BROWSER === 'firefox') {

await driver.openNewURL('about:debugging#/runtime/this-firefox');

}

or something similar? This solves the issue in my end

I fixed it by replacing the url with about:blank a315444

oh nice 😍 ty!!

seaona · 2024-07-26T10:08:21Z

test/e2e/tests/api-usage/account-tracker-api-usage.spec.ts

+}
+
+describe('Account Tracker API Usage', function () {
+  it('should not make eth_call or eth_getBalance requests before the UI is opened and should make those requests after the UI is opened', async function () {


I see that the account tracker is also responsible from initiating eth_getBlockByNumber calls. Should we also include them here?

account-tracker-getblockbynumber.mp4

good suggestion, added here ac50f66

thank you Dan, great refactor! Could it be that we are missing it here and in the test description (not a blocker though)?

No, in that case there is an eth_getBlockbyNumber call before the UI opens, for other reasons. That should be addressed separately.

I will create a ticket for that and add a code comment and update the test description

oh gotcha, thank you Dan!

…c page

metamaskbot · 2024-07-26T10:57:50Z

Builds ready [a315444]

builds: chrome, firefox
builds (beta): chrome
builds (flask): chrome, firefox
builds (MMI): chrome, firefox
builds (test): chrome, firefox
builds (test-flask): chrome, firefox
build viz: Build System
mv3: Background Module Init Stats
mv3: UI Init Stats
mv3: Module Load Stats
mv3: Bundle Size Stats
mv2: E2e Actions Stats
code coverage: Report
storybook: Storybook
typescript migration: Dashboard
all artifacts
bundle viz:
- background: 0, 1, 2, 3, 4, 5
- common: 0, 1, 10, 2, 3, 4, 5, 6, 7, 8, 9
- content-script: 0
- offscreen: 0
- ui: 0, 1, 10, 11, 2, 3, 4, 5, 6, 7, 8, 9

Page Load Metrics (412 ± 325 ms)

Platform	Page	Metric	Min (ms)	Max (ms)	Average (ms)	StandardDeviation (ms)	MarginOfError (ms)
Chrome	Home	firstPaint	77	228	117	34	16
		domContentLoaded	11	80	33	19	9
		load	43	1894	412	677	325
		domInteractive	11	80	33	19	9

Bundle size diffs [🚨 Warning! Bundle size has increased!]

background: 96 Bytes (0.00%)
ui: 0 Bytes (0.00%)
common: 0 Bytes (0.00%)

codecov · 2024-07-26T11:14:56Z

Codecov Report

Attention: Patch coverage is 80.00000% with 3 lines in your changes missing coverage. Please review.

Project coverage is 69.95%. Comparing base (b27dd2b) to head (27df50c).
Report is 16 commits behind head on develop.

Files	Patch %	Lines
app/scripts/metamask-controller.js	80.00%	3 Missing ⚠️

Additional details and impacted files

@@             Coverage Diff             @@
##           develop   #26141      +/-   ##
===========================================
+ Coverage    69.94%   69.95%   +0.01%     
===========================================
  Files         1409     1409              
  Lines        49794    49799       +5     
  Branches     13773    13771       -2     
===========================================
+ Hits         34826    34832       +6     
+ Misses       14968    14967       -1

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

…osed

metamaskbot · 2024-07-26T13:15:41Z

Builds ready [98a10a1]

builds: chrome, firefox
builds (beta): chrome
builds (flask): chrome, firefox
builds (MMI): chrome, firefox
builds (test): chrome, firefox
builds (test-flask): chrome, firefox
build viz: Build System
mv3: Background Module Init Stats
mv3: UI Init Stats
mv3: Module Load Stats
mv3: Bundle Size Stats
mv2: E2e Actions Stats
code coverage: Report
storybook: Storybook
typescript migration: Dashboard
all artifacts
bundle viz:
- background: 0, 1, 2, 3, 4, 5
- common: 0, 1, 10, 2, 3, 4, 5, 6, 7, 8, 9
- content-script: 0
- offscreen: 0
- ui: 0, 1, 10, 11, 2, 3, 4, 5, 6, 7, 8, 9

Page Load Metrics (63 ± 8 ms)

Platform	Page	Metric	Min (ms)	Max (ms)	Average (ms)	StandardDeviation (ms)	MarginOfError (ms)
Chrome	Home	firstPaint	64	130	90	15	7
		domContentLoaded	8	61	25	12	6
		load	39	114	63	17	8
		domInteractive	8	61	25	12	6

Bundle size diffs [🚨 Warning! Bundle size has increased!]

background: 96 Bytes (0.00%)
ui: 0 Bytes (0.00%)
common: 0 Bytes (0.00%)

chloeYue · 2024-07-29T13:02:59Z

QA test OK !

test/e2e/tests/api-usage/account-tracker-api-usage.spec.ts

DDDDDanica · 2024-07-29T13:57:40Z

test/e2e/tests/api-usage/account-tracker-api-usage.spec.ts

+        );
+
+        await driver.openNewURL('about:blank');
+        await driver.delay(20000);


same as https://github.com/MetaMask/metamask-extension/pull/26141/files#r1695290161

we need this to be 20000 ms long. I have added a code comment to explain 27df50c

Co-authored-by: Danica Shen <[email protected]>

sonarqubecloud · 2024-07-29T14:58:43Z

Quality Gate passed

Issues
0 New issues
0 Accepted issues

Measures
0 Security Hotspots
0.0% Coverage on New Code
0.0% Duplication on New Code

See analysis details on SonarCloud

seaona

tests look good, though might be good to have a dev approval too, for the controllers change

metamaskbot · 2024-07-29T15:30:30Z

Builds ready [27df50c]

builds: chrome, firefox
builds (beta): chrome
builds (flask): chrome, firefox
builds (MMI): chrome, firefox
builds (test): chrome, firefox
builds (test-flask): chrome, firefox
build viz: Build System
mv3: Background Module Init Stats
mv3: UI Init Stats
mv3: Module Load Stats
mv3: Bundle Size Stats
mv2: E2e Actions Stats
code coverage: Report
storybook: Storybook
typescript migration: Dashboard
all artifacts
bundle viz:
- background: 0, 1, 2, 3, 4, 5
- common: 0, 1, 10, 2, 3, 4, 5, 6, 7, 8, 9
- content-script: 0
- offscreen: 0
- ui: 0, 1, 10, 11, 2, 3, 4, 5, 6, 7, 8, 9

Page Load Metrics (218 ± 212 ms)

Platform	Page	Metric	Min (ms)	Max (ms)	Average (ms)	StandardDeviation (ms)	MarginOfError (ms)
Chrome	Home	firstPaint	73	164	98	22	10
		domContentLoaded	9	68	25	16	7
		load	42	1570	218	441	212
		domInteractive	9	68	25	16	7

Bundle size diffs [🚨 Warning! Bundle size has increased!]

background: 96 Bytes (0.00%)
ui: 0 Bytes (0.00%)
common: 0 Bytes (0.00%)

metamaskbot · 2024-07-30T11:10:28Z

Missing release label release-12.0.0 on PR. Adding release label release-12.0.0 on PR and removing other release labels(release-12.4.0), as PR was cherry-picked in branch 12.0.0.

danjm added 2 commits July 25, 2024 10:13

Ensure that the outstream end/finished handler in setupControllerConn…

d5ee4fb

…ection in metamask-controller.js is called when it should be

Add e2e test to verify that there are no eth_call and eth_getBalance …

32ea2ff

…requests to infura after the UI has closed

danjm requested review from a team as code owners July 25, 2024 18:52

metamaskbot added the team-extension-platform label Jul 25, 2024

lint fix

236fcbe

danjm changed the title ~~Fix setup controller connection outstream end~~ Fix setupControllerConnection outstream end event listener Jul 25, 2024

danjm changed the title ~~Fix setupControllerConnection outstream end event listener~~ fix: setupControllerConnection outstream end event listener Jul 25, 2024

legobeat mentioned this pull request Jul 25, 2024

fix: refactor outStream end-handling #26142

Merged

Gudahtt reviewed Jul 25, 2024

View reviewed changes

privacy-snapshot.json Outdated

Copy link

Member

Gudahtt Jul 25, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

For a later PR: We should consider sorting this with prettier (prettier-plugin-sort-json can do it)

Gudahtt reviewed Jul 25, 2024

View reviewed changes

privacy-snapshot.json Outdated Show resolved Hide resolved

danjm and others added 5 commits July 25, 2024 18:08

Merge branch 'develop' into fix-setupControllerConnection-outstream-end

3a0f193

Fix typescript in test file

646c022

chore: readable-stream import cleanup

582f4c0

chore: track outStream state directly on stream object

dc7032a

chore: test update

fe44d80

This comment was marked as resolved.

Sign in to view

legobeat reviewed Jul 25, 2024

View reviewed changes

test/e2e/webdriver/chrome.js Outdated Show resolved Hide resolved

legobeat reviewed Jul 25, 2024

View reviewed changes

legobeat requested a review from a team July 25, 2024 22:11

legobeat reviewed Jul 25, 2024

View reviewed changes

privacy-snapshot.json Outdated Show resolved Hide resolved

Remove no longer needed proxy-bypass-list chrome option, and no longe…

aac4e57

…r needed privacy snapshot addition

legobeat previously approved these changes Jul 25, 2024

View reviewed changes

legobeat requested a review from a team July 25, 2024 23:42

Merge branch 'develop' into fix-setupControllerConnection-outstream-end

a1dea62

seaona reviewed Jul 26, 2024

View reviewed changes

Fix e2e on firefox by using a empty page instead of a browser specifi…

a315444

…c page

danjm dismissed legobeat’s stale review via a315444 July 26, 2024 10:25

danjm added 3 commits July 26, 2024 10:12

Add code comment explaining increasing block number in api mock

74226e0

Add eth_getBlockByNumber to requests to check for after the ui has cl…

ac50f66

…osed

Code cleanup

98a10a1

chloeYue added the QA Passed label Jul 29, 2024

DDDDDanica reviewed Jul 29, 2024

View reviewed changes

test/e2e/tests/api-usage/account-tracker-api-usage.spec.ts Outdated Show resolved Hide resolved

DDDDDanica reviewed Jul 29, 2024

View reviewed changes

danjm and others added 3 commits July 29, 2024 12:17

Clarify testing of eth_getBlockByNumber

ca67fc4

Update test/e2e/tests/api-usage/account-tracker-api-usage.spec.ts

fda57b3

Co-authored-by: Danica Shen <[email protected]>

Add code comment explaining the 20000 ms delay

27df50c

danjm force-pushed the fix-setupControllerConnection-outstream-end branch from 7a00c1f to 27df50c Compare July 29, 2024 14:56

seaona approved these changes Jul 29, 2024

View reviewed changes

DDDDDanica approved these changes Jul 29, 2024

View reviewed changes

DDDDDanica merged commit 8f6c83e into develop Jul 29, 2024
76 checks passed

DDDDDanica deleted the fix-setupControllerConnection-outstream-end branch July 29, 2024 15:35

github-actions bot locked and limited conversation to collaborators Jul 29, 2024

metamaskbot added release-12.4.0 Issue or pull request that will be included in release 12.4.0 release-12.0.0 Issue or pull request that will be included in release 12.0.0 and removed release-12.4.0 Issue or pull request that will be included in release 12.4.0 labels Jul 29, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

fix: setupControllerConnection outstream end event listener #26141

fix: setupControllerConnection outstream end event listener #26141

danjm commented Jul 25, 2024 •

edited

Loading

github-actions bot commented Jul 25, 2024

Gudahtt Jul 25, 2024

This comment was marked as resolved.

legobeat Jul 25, 2024

seaona Jul 26, 2024

seaona Jul 26, 2024 •

edited

Loading

danjm Jul 26, 2024

seaona Jul 26, 2024

seaona Jul 26, 2024

danjm Jul 26, 2024

seaona Jul 29, 2024

danjm Jul 29, 2024

seaona Jul 29, 2024

metamaskbot commented Jul 26, 2024

codecov bot commented Jul 26, 2024 •

edited

Loading

metamaskbot commented Jul 26, 2024

chloeYue commented Jul 29, 2024

DDDDDanica Jul 29, 2024

danjm Jul 29, 2024

sonarqubecloud bot commented Jul 29, 2024

seaona left a comment

metamaskbot commented Jul 29, 2024

metamaskbot commented Jul 30, 2024

-        await driver.openNewURL('chrome://extensions');
+        if (process.env.SELENIUM_BROWSER === 'chrome') {
+          await driver.openNewURL('chrome://extensions');
+        } else if (process.env.SELENIUM_BROWSER === 'firefox') {
+          await driver.openNewURL('about:debugging#/runtime/this-firefox');
+        }

fix: setupControllerConnection outstream end event listener #26141

fix: setupControllerConnection outstream end event listener #26141

Conversation

danjm commented Jul 25, 2024 • edited Loading

Description

Related issues

Manual testing steps

Screenshots/Recordings

Before

After

Pre-merge author checklist

Pre-merge reviewer checklist

github-actions bot commented Jul 25, 2024

Choose a reason for hiding this comment

This comment was marked as resolved.

Choose a reason for hiding this comment

Choose a reason for hiding this comment

seaona Jul 26, 2024 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

metamaskbot commented Jul 26, 2024

codecov bot commented Jul 26, 2024 • edited Loading

Codecov Report

metamaskbot commented Jul 26, 2024

chloeYue commented Jul 29, 2024

Choose a reason for hiding this comment

Choose a reason for hiding this comment

sonarqubecloud bot commented Jul 29, 2024

Quality Gate passed

seaona left a comment

Choose a reason for hiding this comment

metamaskbot commented Jul 29, 2024

metamaskbot commented Jul 30, 2024

danjm commented Jul 25, 2024 •

edited

Loading

seaona Jul 26, 2024 •

edited

Loading

codecov bot commented Jul 26, 2024 •

edited

Loading