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

DocumentMigrator: add logging for errors outside of migration functions #76477

Conversation

pgayvallet
Copy link
Contributor

@pgayvallet pgayvallet commented Sep 2, 2020

Summary

Fix #75055

Add logging of errors occurring from outside of the wrapped migration function to DocumentMigrator.migrate

Checklist

@pgayvallet pgayvallet added release_note:skip Skip the PR/issue when compiling release notes Team:Core Core services & architecture: plugins, logging, config, saved objects, http, ES client, i18n, etc v7.10.0 labels Sep 2, 2020
Comment on lines +647 to +648
expect(mockLogger.warn).toHaveBeenCalledTimes(1);
expect(mockLogger.error).not.toHaveBeenCalled();
Copy link
Contributor Author

Choose a reason for hiding this comment

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

Error from within the wrapped transform functions are currently logged as warnings

log.warn(
`Failed to transform document ${doc}. Transform: ${failedTransform}\nDoc: ${failedDoc}`
);

As the error is actually causing the migration to fail and the server to not start, I wonder if we shouldn't upgrade that to the error level, wdyt?

Copy link
Contributor

Choose a reason for hiding this comment

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

Upgrade to error makes sense 👍

Comment on lines +277 to +279
if (!e.alreadyLogged) {
log.error(`Error applying migrations to doc ${doc.type}:${doc.id}: ${e}`);
}
Copy link
Contributor Author

Choose a reason for hiding this comment

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

The errors were already logged when thrown from within the migration function, via the wrapWithTry wrapper. Only non-logged errors are the one from the actual DocumentMigrator code.

As the migration function errors got some specific infos, I did not remove them when adding this try/catch block. Instead, I use this alreadyLogged flag trick to avoid logging the error twice, while preserving the thrown error.

@pgayvallet pgayvallet marked this pull request as ready for review September 2, 2020 10:02
@pgayvallet pgayvallet requested a review from a team as a code owner September 2, 2020 10:02
@elasticmachine
Copy link
Contributor

Pinging @elastic/kibana-platform (Team:Platform)

@kibanamachine
Copy link
Contributor

💚 Build Succeeded

Build metrics

✅ unchanged

History

To update your PR or re-run it, just comment with:
@elasticmachine merge upstream

Copy link
Contributor

@joshdover joshdover left a comment

Choose a reason for hiding this comment

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

Code looks good. Only remaining question I have is where were these exceptions being swallowed before? Is it possible that any other exceptions are being swallowed in the same place?

@pgayvallet
Copy link
Contributor Author

Only remaining question I have is where were these exceptions being swallowed before? Is it possible that any other exceptions are being swallowed in the same place?

Don't even know why I did not look a little deeper, as every uncatched exceptions are supposed to be catched by root

public async start() {
this.log.debug('starting root');
try {
return await this.server.start();
} catch (e) {
await this.shutdown(e);
throw e;
}
}

After a little more investigation, I found the actual culprit:

function transformNonBlocking(
transform: TransformFn
): (doc: SavedObjectUnsanitizedDoc) => Promise<SavedObjectUnsanitizedDoc> {
// promises aren't enough to unblock the event loop
return (doc: SavedObjectUnsanitizedDoc) =>
new Promise((resolve) => {
// set immediate is though
setImmediate(() => {
resolve(transform(doc));
});
});
}

This recent addition to avoid blocking the event loop during migration does not handle error during the failure call, resulting in an unhandled promise rejection.

@pgayvallet
Copy link
Contributor Author

Closing in favor of #77018

@pgayvallet pgayvallet closed this Sep 9, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
release_note:skip Skip the PR/issue when compiling release notes Team:Core Core services & architecture: plugins, logging, config, saved objects, http, ES client, i18n, etc v7.10.0
Projects
None yet
Development

Successfully merging this pull request may close these issues.

DocumentMigrator exception not handled by logger
4 participants