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 race condition where log.whenComplete may not complete #5986

Merged
merged 4 commits into from
Nov 21, 2024

Conversation

jrhee17
Copy link
Contributor

@jrhee17 jrhee17 commented Nov 18, 2024

Motivation:

It has been reported that log.whenComplete is not completing in some cases in #5981.
The cause seems to be a race condition between DefaultRequestLog#endRequest and DefaultRequestLog#requestContent. Completion of log.whenComplete is important because

  1. it is semantically bound to an HTTP request 2) users (including us) have clean up logic using log.whenComplete.

I propose that simply endRequest only sets name if content is not deferred, and requestContent sets name if content is deferred. The logic is easier to reason about, and there are minimal performance implications since a lock is held anyways.

Modifications:

  • #endRequest sets name if requestContent isn't deferred
  • #requestContent sets name if requestContent is deferred

Result:

@jrhee17 jrhee17 added the defect label Nov 18, 2024
@jrhee17 jrhee17 added this to the 1.31.1 milestone Nov 18, 2024
@jrhee17 jrhee17 marked this pull request as ready for review November 18, 2024 08:37
if (!hasInterestedFlags(deferredFlags, RequestLogProperty.REQUEST_CONTENT) ||
isAvailable(RequestLogProperty.REQUEST_CONTENT)) {
// Set names if request content is not deferred
if (!hasInterestedFlags(deferredFlags, RequestLogProperty.REQUEST_CONTENT)) {
Copy link
Contributor

@ikhoon ikhoon Nov 19, 2024

Choose a reason for hiding this comment

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

Previously, the default name was filled in if there was no custom value before a request ended. With this change, if a deferred request content is called before endRequest(), RequestLogBuilder.name() could be ignored, which may be a breaking change. Would it be worth specifying this change in Javadoc?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Sure, done

Copy link
Member

@minwoox minwoox left a comment

Choose a reason for hiding this comment

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

The change makes sense. 👍

Copy link
Contributor

@ikhoon ikhoon left a comment

Choose a reason for hiding this comment

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

Thanks!

@ikhoon ikhoon merged commit 79112f5 into line:main Nov 21, 2024
12 of 14 checks passed
minwoox pushed a commit that referenced this pull request Nov 22, 2024
Motivation:

It has been reported that `log.whenComplete` is not completing in some
cases in #5981.
The cause seems to be a race condition between
`DefaultRequestLog#endRequest` and `DefaultRequestLog#requestContent`.
Completion of `log.whenComplete` is important because
1) it is semantically bound to an HTTP request 2) users (including us)
have clean up logic using `log.whenComplete`.

I propose that simply `endRequest` only sets `name` if content is not
deferred, and `requestContent` sets `name` if content is deferred. The
logic is easier to reason about, and there are minimal performance
implications since a lock is held anyways.

Modifications:

- `#endRequest` sets `name` if `requestContent` isn't deferred
- `#requestContent` sets name if `requestContent` is deferred

Result:

- Closes #5981 

<!--
Visit this URL to learn more about how to write a pull request
description:

https://armeria.dev/community/developer-guide#how-to-write-pull-request-description
-->
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Potential Race Condition in FramedGrpcService with ctx.log.whenComplete Not Completing in v1.30.1
3 participants