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

Fix error that caused a segfault when users registered custom Sync logger functions #4156

Merged
merged 12 commits into from
Dec 20, 2021

Conversation

fronck
Copy link

@fronck fronck commented Dec 16, 2021

What, How & Why?

This closes #4121

☑️ ToDos

  • 📝 Changelog entry
  • 📝 Compatibility label is updated or copied from previous entry
  • 🚦 Tests
  • 📱 Check the React Native/other sample apps work if necessary
  • 📝 Public documentation PR created or is not necessary
  • 💥 Breaking label has been applied or is not necessary

If this PR adds or changes public API's:

  • typescript definitions file is updated
  • jsdoc files updated
  • Chrome debug API is updated if API is available on React Native

@cla-bot cla-bot bot added the cla: yes label Dec 16, 2021
@fronck fronck requested review from kneth and tomduncalf December 16, 2021 20:06
Copy link
Member

@kraenhansen kraenhansen left a comment

Choose a reason for hiding this comment

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

Great job. Was it basically that the function provided by the user was not owned by SyncLoggerDelegator and was therefore free to be garbage collected, eventually leading to a use after free of the callback?

Copy link
Contributor

@kneth kneth left a comment

Choose a reason for hiding this comment

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

Awesome ❤️

const realm = await Realm.open(config);
realm.close();

TestCase.assertTrue(loggerInvoked, "Custom logger should have been invoked");
Copy link
Contributor

Choose a reason for hiding this comment

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

I am a bit worry for a race condition here but maybe Realm.open() takes long enough.

@tomduncalf
Copy link
Contributor

Great job. Was it basically that the function provided by the user was not owned by SyncLoggerDelegator and was therefore free to be garbage collected, eventually leading to a use after free of the callback?

My understanding is that the show_logs std::function was going out of scope at the end of the set_sync_logger method and as nothing else had taken ownership of it, it was being destructed immediately at that time... so by the time something tried to log and make_logger was called, it no longer existed. Franck may be able to correct any misunderstandings I have though :)

In the old implementation, there was a SyncLoggerDelegatorFactory class which retained ownership of the function.

Comment on lines 539 to 541
let loggerInvoked = false;
Realm.App.Sync.setLogLevel(app, "info"); // "all", "trace", "debug", "detail", "info", "warn", "error", "fatal", "off"
Realm.App.Sync.setLogger(app, (level, message) => (loggerInvoked = true));
Copy link
Contributor

Choose a reason for hiding this comment

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

I guess it might not hurt to test that level and message are passed through correctly?

Suggested change
let loggerInvoked = false;
Realm.App.Sync.setLogLevel(app, "info"); // "all", "trace", "debug", "detail", "info", "warn", "error", "fatal", "off"
Realm.App.Sync.setLogger(app, (level, message) => (loggerInvoked = true));
let loggedLevel, loggedMessage;
Realm.App.Sync.setLogLevel(app, "info"); // "all", "trace", "debug", "detail", "info", "warn", "error", "fatal", "off"
Realm.App.Sync.setLogger(app, (level, message) => {
if (!loggedLevel) loggedLevel = level;
if (!loggedMessage) loggedMessage = message;
});
// ...
TestCase.assertEqual(loggedLevel, 123);
TestCase.assertEqual(loggedMessage, "whatever the first message is");

Or is the first message not predictable?

Copy link
Author

Choose a reason for hiding this comment

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

It is as long as the sync subsystem doesn't change what it returns, or the sync config structure doesn't change. It'd be weird if the test failed because of that, but I'll see if I can parse out from the lower levels how the message is constructed.

Copy link
Contributor

Choose a reason for hiding this comment

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

I wouldn't worry too much if it's awkward :)

@fronck
Copy link
Author

fronck commented Dec 17, 2021

Great job. Was it basically that the function provided by the user was not owned by SyncLoggerDelegator and was therefore free to be garbage collected, eventually leading to a use after free of the callback?

My understanding is that the show_logs std::function was going out of scope at the end of the set_sync_logger method and as nothing else had taken ownership of it, it was being destructed immediately at that time... so by the time something tried to log and make_logger was called, it no longer existed. Franck may be able to correct any misunderstandings I have though :)

In the old implementation, there was a SyncLoggerDelegatorFactory class which retained ownership of the function.

Yes, basically we were passing log_fn around by reference, so when it went out of scope, we left a dangling pointer to a function that wasn't safe to invoke.

Copy link
Member

@kraenhansen kraenhansen left a comment

Choose a reason for hiding this comment

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

I have a minor comment here - feel free to integrate the suggestion or merge at will.

});

const realm = await Realm.open(config);
const loggerInvoked = await promisedLog;
Copy link
Member

Choose a reason for hiding this comment

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

There's no real meaning in returning and asserting true. If it doesn't happen the promise won't resolve and the test will simply time out.

Suggested change
const loggerInvoked = await promisedLog;
await promisedLog;

const realm = await Realm.open(config);
const loggerInvoked = await promisedLog;
realm.close();
TestCase.assertTrue(loggerInvoked, `Custom logger should have registered an '${logLevelStr}' message`);
Copy link
Member

Choose a reason for hiding this comment

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

Suggested change
TestCase.assertTrue(loggerInvoked, `Custom logger should have registered an '${logLevelStr}' message`);

Realm.App.Sync.setLogger(app, (level, message) => {
if (level == logLevelNum && message.includes("Connection") && message.includes("Session")) {
// we should, at some point, receive a log message that looks like
// Connection[1]: Session[1]: client_reset_config = false, Realm exists = true, client reset = false
Copy link
Member

Choose a reason for hiding this comment

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

If you want the test to rely on this message to eventually be logged, you could resolve conditionally on the message?

@fronck fronck merged commit 01e3437 into master Dec 20, 2021
@fronck fronck deleted the ff/custom-sync-logger branch December 20, 2021 13:32
@github-actions github-actions bot locked as resolved and limited conversation to collaborators Mar 16, 2024
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Segmentation fault when performing await realm.open(config)
4 participants