Skip to content
New issue

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

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

Already on GitHub? # to your account

Fix race condition in RCTLoggingTests integration tests #34858

Closed
wants to merge 1 commit into from

Conversation

rshest
Copy link
Contributor

@rshest rshest commented Oct 4, 2022

Summary:
Changelog:

[iOS][Fixed] - Fix race condition in RCTLoggingTests integration tests

RCTLoggingTests work in the following way:

  • Put a custom hook on logging (logging function) to intercept log messages
  • Send several log messages via JS and see whether they hit the hook as expected

The problem with this approach was that there may be unexpected log messages, which squeeze inbetween the points of time when the hook was set and when the first message was sent.

There was a (now 6 years old!!!) fix to mitigate this problem, which was adding a lead pause of 2s to "make sure" that all the other possible log messages had been sent: #10568

That didn't actually guarantee fixing the problem in general, just partially mitigating it, as the race condition conceptually still remained there.

Here I take a different approach, which should guarantee that we skip all the rogue JS messages before we start sending and reading them on our own:

  • Install the hook
  • Log a "marker" message
  • Pump the log until the marker appears - at this point we know that the hook has been definitely installed

Differential Revision: D40043442

Summary:
Changelog:

[iOS][Fixed] - Fix race condition in RCTLoggingTests integration tests

RCTLoggingTests work in the following way:
* Put a custom hook on logging (logging function) to intercept log messages
* Send several log messages via JS and see whether they hit the hook as expected

The problem with this approach was that there may be unexpected log messages, which squeeze inbetween the points of time when the hook was set and when the first message was sent.

There was a (now 6 years old!!!) fix to mitigate this problem, which was adding a lead pause of 2s to "make sure" that all the other possible log messages had been sent: facebook#10568

That didn't actually guarantee fixing the problem in general, just partially mitigating it, as the race condition conceptually still remained there.

Here I take a different approach, which should guarantee that we skip all the rogue JS messages before we start sending and reading them on our own:
* Install the hook
* Log a "marker" message
* Pump the log until the marker appears - at this point we know that the hook has been definitely installed

Differential Revision: D40043442

fbshipit-source-id: 396501cc48eafc9a41f4c5eb4b7d2a5019b0b212
@facebook-github-bot facebook-github-bot added CLA Signed This label is managed by the Facebook bot. Authors need to sign the CLA before a PR can be reviewed. p: Facebook Partner: Facebook Partner fb-exported labels Oct 4, 2022
@facebook-github-bot
Copy link
Contributor

This pull request was exported from Phabricator. Differential Revision: D40043442

@react-native-bot react-native-bot added Bug Platform: iOS iOS applications. labels Oct 4, 2022
@analysis-bot
Copy link

Platform Engine Arch Size (bytes) Diff
android hermes arm64-v8a 7,739,368 +0
android hermes armeabi-v7a 7,142,017 +0
android hermes x86 8,050,463 +0
android hermes x86_64 8,022,289 +0
android jsc arm64-v8a 9,607,560 +0
android jsc armeabi-v7a 8,373,048 +0
android jsc x86 9,555,221 +0
android jsc x86_64 10,147,815 +0

Base commit: 793ebf6
Branch: main

@analysis-bot
Copy link

Platform Engine Arch Size (bytes) Diff
ios - universal n/a --

Base commit: 793ebf6
Branch: main

@react-native-bot
Copy link
Collaborator

This pull request was successfully merged by Ruslan Shestopalyuk in 540ae39.

When will my fix make it into a release? | Upcoming Releases

@react-native-bot react-native-bot added the Merged This PR has been merged. label Oct 4, 2022
@rshest
Copy link
Contributor Author

rshest commented Oct 4, 2022

The failed TestDocker test looks to be due to infra issues, not related to the change:

Unable to download: mvn:org.robolectric:utils:jar:4.4

OlimpiaZurek pushed a commit to OlimpiaZurek/react-native that referenced this pull request May 22, 2023
Summary:
Pull Request resolved: facebook#34858

Changelog:

[iOS][Fixed] - Fix race condition in RCTLoggingTests integration tests

RCTLoggingTests work in the following way:
* Put a custom hook on logging (logging function) to intercept log messages
* Send several log messages via JS and see whether they hit the hook as expected

The problem with this approach was that there may be unexpected log messages, which squeeze inbetween the points of time when the hook was set and when the first message was sent.

There was a (now 6 years old!!!) fix to mitigate this problem, which was adding a lead pause of 2s to "make sure" that all the other possible log messages had been sent: facebook#10568

That didn't actually guarantee fixing the problem in general, just partially mitigating it, as the race condition conceptually still remained there.

Here I take a different approach, which should guarantee that we skip all the rogue JS messages before we start sending and reading them on our own:
* Install the hook
* Log a "marker" message
* Pump the log until the marker appears - at this point we know that the hook has been definitely installed

Reviewed By: cipolleschi

Differential Revision: D40043442

fbshipit-source-id: b4aa617d27c2dcff26682dd72e47ec19cb0d11ca
# for free to join this conversation on GitHub. Already have an account? # to comment
Labels
Bug CLA Signed This label is managed by the Facebook bot. Authors need to sign the CLA before a PR can be reviewed. fb-exported Merged This PR has been merged. p: Facebook Partner: Facebook Partner Platform: iOS iOS applications.
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants