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

event: assert the case of both read and closed event registered #18265

Merged
merged 10 commits into from
Oct 27, 2021

Conversation

soulxu
Copy link
Member

@soulxu soulxu commented Sep 26, 2021

Signed-off-by: He Jie Xu hejie.xu@intel.com

Commit Message: event: assert the case of both read and closed event registered
Additional Description:
On Windows, the Read event may be removed when both the read and closed event are registered. That will lead the thread is waiting for next read event forever. So change to assertion to prevent someone registered both read and closed events.
Risk Level: low
Testing: n/a
Docs Changes: n/a
Release Notes: n/a

@repokitteh-read-only
Copy link

As a reminder, PRs marked as draft will not be automatically assigned reviewers,
or be handled by maintainer-oncall triage.

Please mark your PR as ready when you want it to be reviewed!

🐱

Caused by: #18265 was opened by soulxu.

see: more, trace.

@soulxu
Copy link
Member Author

soulxu commented Sep 26, 2021

Waiting for the comment from @davinci26 at #17395 (comment)

cc @davinci26 @wrowe

@soulxu soulxu changed the title Assert the case of both read and closed event registered event: assert the case of both read and closed event registered Sep 26, 2021
@davinci26
Copy link
Member

/retest

@repokitteh-read-only
Copy link

Retrying Azure Pipelines:
Retried failed jobs in: envoy-presubmit

🐱

Caused by: a #18265 (comment) was created by @davinci26.

see: more, trace.

@soulxu soulxu marked this pull request as ready for review October 11, 2021 05:56
Copy link
Member

@davinci26 davinci26 left a comment

Choose a reason for hiding this comment

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

Overall, this looks reasonable to me. There are still some tests that are not passing on windows, I can help with debugging those tomorrow.

Adding also @antoniovicente to take a look as he is really well versed on the subject.

(edit: I have a PR to fix coverage flakes so you might want to pick up main when #18571 is merged)

Copy link
Contributor

@antoniovicente antoniovicente left a comment

Choose a reason for hiding this comment

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

Seems reasonable. I would recommend looping in code owners for the HTTP and TLS inspectors.

@@ -28,6 +28,9 @@ FileEventImpl::FileEventImpl(DispatcherImpl& dispatcher, os_fd_t fd, FileReadyCb
"Cannot use EmulatedEdge events if they are not the default platform type");
}

// We never ask for both early close and read at the same time.
ASSERT(!(events & FileReadyType::Read && (events & FileReadyType::Closed)));
Copy link
Contributor

Choose a reason for hiding this comment

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

You're not asserting this condition in FileEventImpl::updateEvents

Can I suggest you move this assert to assignEvents so both cases are covered?

Copy link
Member Author

Choose a reason for hiding this comment

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

sure, that is better, let me try

new_event_mask = new_event_mask & ~FileReadyType::Read;
}
// We never ask for both early close and read at the same time.
ASSERT(!(event & FileReadyType::Read && (enabled_events_ & FileReadyType::Closed)));
Copy link
Contributor

Choose a reason for hiding this comment

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

You may want to ASSERT against new_event_mask instead.

// inspector is always peeking and can never determine EOF.
// Use this event type to avoid listener timeout on the OS supporting
// FileReadyType::Closed.
bool end_stream = events & Event::FileReadyType::Closed;
Copy link
Contributor

Choose a reason for hiding this comment

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

These comments imply that including Closed in the event mask is important. IIRC Closed events are not supported on Mac, so relying on Closed events seems broken. At some point in the future I may try to reduce our reliance on them but that is unlikely to happen anytime soon.

Copy link
Member Author

Choose a reason for hiding this comment

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

Do you mean reduce the reliance on Closed event? I may can help after finishing the current task.

Copy link
Contributor

Choose a reason for hiding this comment

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

Yes, stop using Closed events in the envoy implementation. It's not an easy task as it interacts in intrusive ways with the way Connection readDisable is implemented.

@soulxu
Copy link
Member Author

soulxu commented Oct 12, 2021

Seems reasonable. I would recommend looping in code owners for the HTTP and TLS inspectors.

Yea, I guess they are @ggreenway and @alyssawilk :)

@soulxu
Copy link
Member Author

soulxu commented Oct 12, 2021

Overall, this looks reasonable to me. There are still some tests that are not passing on windows, I can help with debugging those tomorrow.

Adding also @antoniovicente to take a look as he is really well versed on the subject.

(edit: I have a PR to fix coverage flakes so you might want to pick up main when #18571 is merged)

thanks! I will give it a try today, hope my windows dev env works.

@soulxu
Copy link
Member Author

soulxu commented Oct 12, 2021

Overall, this looks reasonable to me. There are still some tests that are not passing on windows, I can help with debugging those tomorrow.
Adding also @antoniovicente to take a look as he is really well versed on the subject.
(edit: I have a PR to fix coverage flakes so you might want to pick up main when #18571 is merged)

thanks! I will give it a try today, hope my windows dev env works.

@davinci26 I probably need your help, I don't know why there is no forth loop, not sure whether it is a different between linux and windows. But the previous test works, so it is strange.

@davinci26
Copy link
Member

probably need your help, I don't know why there is no forth loop, not sure whether it is a different between linux and windows. But the previous test works, so it is strange.

I think this is a difference in to libevent, because at the end no events are registered on windows (all of them are unregistered) libevent closes the event loop and thus the watcher event is not emitted. I think we should guard the failing expectation based on the underlying event type

Signed-off-by: He Jie Xu <hejie.xu@intel.com>
Signed-off-by: He Jie Xu <hejie.xu@intel.com>
Signed-off-by: He Jie Xu <hejie.xu@intel.com>
Signed-off-by: He Jie Xu <hejie.xu@intel.com>
Signed-off-by: He Jie Xu <hejie.xu@intel.com>
Signed-off-by: He Jie Xu <hejie.xu@intel.com>
Signed-off-by: He Jie Xu <hejie.xu@intel.com>
Signed-off-by: He Jie Xu <hejie.xu@intel.com>
Copy link
Contributor

@ggreenway ggreenway left a comment

Choose a reason for hiding this comment

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

Makes sense to me

source/common/event/file_event_impl.cc Outdated Show resolved Hide resolved
Signed-off-by: He Jie Xu <hejie.xu@intel.com>
@soulxu
Copy link
Member Author

soulxu commented Oct 14, 2021

/retest

@snowp
Copy link
Contributor

snowp commented Oct 26, 2021

@antoniovicente are you able to finish off the review of this one? Or is there someone else that can take that over?

@antoniovicente antoniovicente self-assigned this Oct 26, 2021
Copy link
Contributor

@antoniovicente antoniovicente left a comment

Choose a reason for hiding this comment

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

@davinci26 could review and approve this change? It relates to Windows emulated edge behavior.

@@ -120,7 +123,6 @@ void FileEventImpl::unregisterEventIfEmulatedEdge(uint32_t event) {
ASSERT(dispatcher_.isThreadSafe());
// This constexpr if allows the compiler to optimize away the function on POSIX
if constexpr (PlatformDefaultTriggerType == FileTriggerType::EmulatedEdge) {
ASSERT((event & (FileReadyType::Read | FileReadyType::Write)) == event);
Copy link
Contributor

Choose a reason for hiding this comment

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

Can you shed some light as to why this ASSERT was removed?

Copy link
Member Author

Choose a reason for hiding this comment

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

Since we assert the same at assignEvents, it will be invoked by updateEvents at line 128 also. So I remove this since it is duplicated

if (event & FileReadyType::Read && (enabled_events_ & FileReadyType::Closed)) {
// We never ask for both early close and read at the same time.
new_event_mask = new_event_mask & ~FileReadyType::Read;
}
Copy link
Contributor

Choose a reason for hiding this comment

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

It doesn't seem safe to me to remove this code. This is a change in behavior in cases where the ASSERT above about not allowing read and closed at the same time fails.

Copy link
Member Author

Choose a reason for hiding this comment

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

got it, let me add it back.

if (events & FileReadyType::Closed && injected_activation_events_ & FileReadyType::Read) {
// We never ask for both early close and read at the same time. If close is requested
// keep that instead.
injected_activation_events_ = injected_activation_events_ & ~FileReadyType::Read;
Copy link
Contributor

Choose a reason for hiding this comment

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

See above, this is a change in behavior. Adding an ASSERT is not a guarantee that these cases won't come up while running a real proxy.

Also note that injected_activation_events_ may contain events that the connection is not registered for. I don't think it happens often but it is technically allowed.

// We never ask for both early close and read at the same time.
new_event_mask = new_event_mask & ~FileReadyType::Read;
}
// We never ask for both early close and read at the same time.
Copy link
Contributor

Choose a reason for hiding this comment

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

@davinci26 Can you confirm that libevent on Windows supports EV_CLOSE?

Copy link
Member

Choose a reason for hiding this comment

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

Does EV_CLOSE correspond to EPOLLRDHUP? if yes then it is supported on wepoll

Copy link
Contributor

Choose a reason for hiding this comment

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

Seems like it. I guess Windows and Linux support this, but not Mac which uses the kqueue for event handling in libevent.

Signed-off-by: He Jie Xu <hejie.xu@intel.com>
@ggreenway ggreenway enabled auto-merge (squash) October 27, 2021 21:23
@ggreenway
Copy link
Contributor

@davinci26 any further comments?

Copy link
Member

@davinci26 davinci26 left a comment

Choose a reason for hiding this comment

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

LGTM

@ggreenway ggreenway merged commit 5d320af into envoyproxy:main Oct 27, 2021
mpuncel added a commit to mpuncel/envoy that referenced this pull request Oct 29, 2021
* main: (221 commits)
  deps: Bump `protobuf` -> 3.19.0 (envoyproxy#18471)
  tooling: auto-assign dependency shephards (envoyproxy#18794)
  clang-tidy: Return from diff fun if empty diff (envoyproxy#18815)
  repokitteh: Block PRs pending deps approval (envoyproxy#18814)
  deps: Bump `org_llvm_llvm` -> 12.0.1, `com_github_wavm_wavm` -> 9ffd3e2 (envoyproxy#18747)
  dns resolvers: add All lookup mode (envoyproxy#18464)
  doc: fix link formatting for TLS session_timeout (envoyproxy#18790)
  ext_authz: Set response flag and code details to UAEX when denied (envoyproxy#18740)
  socket options: add support for directly creating ipv4/ipv6 pairs (envoyproxy#18769)
  ecds: make onConfigUpdate generic over filter type (envoyproxy#18061)
  bazel: update CMake instructions in EXTERNAL_DEPS.md (envoyproxy#18799)
  upstream: fix typo in comment (envoyproxy#18798)
  runtime: removing envoy.reloadable_features.grpc_json_transcoder_adhere_to_buffer_limits (envoyproxy#18696)
  bazel: Add CC=clang to clang configuration (envoyproxy#18732)
  fix error request id in the dubbbo local reply (envoyproxy#18741)
  event: assert the case of both read and closed event registered (envoyproxy#18265)
  tcp proxy connect tunneling: improved testing (envoyproxy#18784)
  deps: Bump `protoc-gen-validate` -> 0.6.2 (envoyproxy#18742)
  deps: Bump `rules_pkg` -> ad57589 (envoyproxy#18746)
  bazel: copy .bazelversion for envoy filter examples (envoyproxy#18730)
  ...

Signed-off-by: Michael Puncel <mpuncel@squareup.com>
@ggreenway
Copy link
Contributor

@soulxu I just found an obscure corner-case bug introduced by this change. For the listener filters that MSG_PEEK (http_inspector, tls_inspector), if the client sends some data with a FIN, the filter can't detect that the connection is closed. It has logic to check the return value for zero, but this won't happen since the data is never removed from the socket due to the MSG_PEEK. However, I don't know that it matters much; the listener_filters_timeout will eventually catch it and close the connection.

@soulxu
Copy link
Member Author

soulxu commented Feb 9, 2022

@soulxu I just found an obscure corner-case bug introduced by this change. For the listener filters that MSG_PEEK (http_inspector, tls_inspector), if the client sends some data with a FIN, the filter can't detect that the connection is closed. It has logic to check the return value for zero, but this won't happen since the data is never removed from the socket due to the MSG_PEEK. However, I don't know that it matters much; the listener_filters_timeout will eventually catch it and close the connection.

I will do some tests. It sounds like we will have different behavior between linux and windows. Maybe it should be ok for windows after we have emulated MSG_PEEK. But let me do some tests and think about it.

@soulxu
Copy link
Member Author

soulxu commented Feb 9, 2022

@soulxu I just found an obscure corner-case bug introduced by this change. For the listener filters that MSG_PEEK (http_inspector, tls_inspector), if the client sends some data with a FIN, the filter can't detect that the connection is closed. It has logic to check the return value for zero, but this won't happen since the data is never removed from the socket due to the MSG_PEEK. However, I don't know that it matters much; the listener_filters_timeout will eventually catch it and close the connection.

I wrote a test https://github.com/envoyproxy/envoy/pull/19883/files, the test won't execute successful, but I can get the log. it seems the recv with MSG_PEEK will return 0 when the connection closed. But let me know if didn't test it with right way.

[2022-02-09 06:33:13.996][270][debug][filter] [source/extensions/filters/listener/proxy_protocol/proxy_protocol.cc:67] proxy_protocol: new connection accepted
[2022-02-09 06:33:13.997][12][debug][connection] [source/common/network/connection_impl.cc:938] [C84] connected on local interface 'lo'
[2022-02-09 06:33:13.997][12][trace][connection] [source/common/network/connection_impl.cc:418] [C84] raising connection event 2
[2022-02-09 06:33:13.997][12][trace][connection] [source/common/network/connection_impl.cc:672] [C84] write ready
[2022-02-09 06:33:13.997][12][trace][connection] [source/common/network/raw_buffer_socket.cc:67] [C84] write returns: 45
[2022-02-09 06:33:13.997][270][debug][filter] [source/extensions/filters/listener/proxy_protocol/proxy_protocol.cc:435] failed to read proxy protocol (no bytes read)

I also lookup the discussion history, davinci26 mentioned that the remote close will trigger event #17395 (comment)

also found this case was spotted out in the review https://github.com/envoyproxy/envoy/pull/18265/files#r726677895

But from the test seems davinci26 was right.

@ggreenway
Copy link
Contributor

The proxy protocol listener filter doesn't PEEK, it consumes the data, so it won't hit this case. Try a similar test with http_inspector or tls_inspector.

@soulxu
Copy link
Member Author

soulxu commented Feb 9, 2022

The proxy protocol listener filter doesn't PEEK, it consumes the data, so it won't hit this case. Try a similar test with http_inspector or tls_inspector.

oops, right, thanks. let me test again.

@soulxu
Copy link
Member Author

soulxu commented Feb 10, 2022

The proxy protocol listener filter doesn't PEEK, it consumes the data, so it won't hit this case. Try a similar test with http_inspector or tls_inspector.

@ggreenway I test those out.

The MSG_PEEK won't return 0 when remote closed. It only triggered an event, but the MSG_PEEK still returns the data in the buffer. Seems there is no way to figure out it is a connection close or not.

The background is the read event will be removed silently after recv return EAGAIN when both read and closed are registered. This leads to further data won't be able to trigger the read event again, the envoy will be stuck there or waiting for a timeout. That can be triggered by the client sending the data in multiple pieces, only the first piece can be received.

For the current code, all test works fine with both read and closed registered, since there is no EAGAIN returned by MSG_PEEK, so the Windows code won't remove the read event silently. A remaining question is is there any chance MSG_PEEK return EAGAIN?

For removing data peek #17395, #17395 (comment) reference to recv without MSG_PEEK. And at that time, we are going to drain out all the data and put them into the ListenerFilterBuffer. Then when both read and closed registered, the read event will be removed silently when recv returns EAGAIN. Although we changed the solution, back to use the MSG_PEEK for ListenerFilterBuffer, but unfortunately, Windows still doesn't work due to the level-triggered event. So we are implementing the Emulated Peek on Windows #19777, it is using the recv without MSG_PEEK to emulate MSG_PEEK. So it still makes the Windows code remove the read event silently. (https://github.com/envoyproxy/envoy/pull/19777/files#diff-9a58b923da541e9bbe65ae41bf9d5a42cd1f5a123603fedd08fdade3fd658ac6R106)

So thinking about the solution here.

  1. If we revert this change, the current code will work. But removing data peek still face this problem on Windows. Also need to ensure there is no chance of MSG_PEEK return EAGAIN.
  2. do nothing, even with removing data peek, we still have the same issue. If the request closed after a few data, then envoy only can wait for a listener filter timeout.
  3. register both read and closed event for removing data peek, but for the Windows code, making it won't remove the read event when emulated the peek. (probably a flag not_remove_read_event for FileEventImpl::registerEventIfEmulatedEdge, and pass true at https://github.com/envoyproxy/envoy/pull/19777/files#diff-9a58b923da541e9bbe65ae41bf9d5a42cd1f5a123603fedd08fdade3fd658ac6R106)
  4. Step back a little bit more. To think about why we remove read event. As listener: remove the peek from the listener filters #17395 (comment) said, the reason is ConnectionImpl doesn't support both read and close event. But that means there is nobody registering both read and close event, so I'm not sure why we take care of that on Windows, and only for Windows. I'm not clear about the original reason. Maybe @antoniovicente can help with that. If everything works fine without removing read event, then it will be a good solution also. Actually option#4 need to think about why removing read event also.
  5. or just keep Windows as is, fix other platfrom with both read and closed event. A little annoying platform specific code.

@soulxu
Copy link
Member Author

soulxu commented Feb 10, 2022

  1. register both read and closed event for removing data peek, but for the Windows code, making it won't remove the read event when emulated the peek. (probably a flag not_remove_read_event for FileEventImpl::registerEventIfEmulatedEdge, and pass true at https://github.com/envoyproxy/envoy/pull/19777/files#diff-9a58b923da541e9bbe65ae41bf9d5a42cd1f5a123603fedd08fdade3fd658ac6R106)
  2. Step back a little bit more. To think about why we remove read event. As listener: remove the peek from the listener filters #17395 (comment) said, the reason is ConnectionImpl doesn't support both read and close event. But that means there is nobody registering both read and close event, so I'm not sure why we take care of that on Windows, and only for Windows. I'm not clear about the original reason. Maybe @antoniovicente can help with that. If everything works fine without removing read event, then it will be a good solution also. Actually option#4 need to think about why removing read event also.

Try to understand why we remove read event here. Since the ConnectionImpl::onFileEvent doesn't handle the read and closed event at same time. (like when both happened, we want to consume the data before close everything. So just avoid to register both events happened. Just using recv/read return 0 to detemine the connection is closed)

Both below two parts handle the case of a read event injected, and closed event was registered.

This is for the case read event was injected, and a closed event happened on the real socket.

if constexpr (PlatformDefaultTriggerType == FileTriggerType::EmulatedEdge) {
if (events & FileReadyType::Closed && injected_activation_events_ & FileReadyType::Read) {
// We never ask for both early close and read at the same time. If close is requested
// keep that instead.
injected_activation_events_ = injected_activation_events_ & ~FileReadyType::Read;
}
}

This is for the case a read event injected, then ensure we won't register the read event back after consume data.

if (trigger_ == FileTriggerType::EmulatedEdge) {
auto new_event_mask = enabled_events_ | event;
if (event & FileReadyType::Read && (enabled_events_ & FileReadyType::Closed)) {
// We never ask for both early close and read at the same time.
new_event_mask = new_event_mask & ~FileReadyType::Read;
}

So can I understand it like, those change are only for ConnectionImpl to avoid process both read and close event?

But for listener filter, we are ok for both read and close event happened (we should be ok for drop the data when close happened). If those understand right, then we can just not removing the read event for listener filter.

@davinci26
Copy link
Member

cc @rectified95 who is the working on Msft/Windows

@soulxu
Copy link
Member Author

soulxu commented Feb 10, 2022

cc @rectified95 who is the working on Msft/Windows

@davinci26 thanks :)

@ggreenway
Copy link
Contributor

@soulxu if this change fixes a case that is supposed to work on windows and previously didn't, and we accidentally broke a case that should never happen and is supposed to fail and now fails a bit slower, I'd say we can leave it; overall behavior is improved.

@soulxu
Copy link
Member Author

soulxu commented Feb 11, 2022

@soulxu if this change fixes a case that is supposed to work on windows and previously didn't, and we accidentally broke a case that should never happen and is supposed to fail and now fails a bit slower, I'd say we can leave it; overall behavior is improved.

I would like to explore this again after remove data peek merged. Then after we figure out why both read and closed event can't be registered on Windows, then we can have a fix on it. It feels like it just a workaround for ConnectionImpl, but in the listener filter, we don't use it. But I'm still not very sure yet, need to dig the code more.

ggreenway pushed a commit that referenced this pull request Jun 29, 2022
Previously the PR #18265 removed the `Closed` event for listener filter, since the Windows doesn't work well.

There is still have a corner case that can't be handled without the `Closed` event #18265 (comment)

This PR tries to introduce the `Closed` event back to the listener filter. As the comments on Windows code said, both `Read` and `Closed` can't be registered at same time due to the `Connection` doesn't support that yet. That means it shouldn't be a problem for the listener filter. Also currently, there is no Envoy code using both `Read` and `Closed` event, so it should be ok to remove those workaround code to make the both `Read` and `Closed` events registered to work with listener filter.

The full analysis is here #18265 (comment)

Signed-off-by: He Jie Xu <hejie.xu@intel.com>
oschaaf pushed a commit to maistra/envoy that referenced this pull request Oct 26, 2022
Previously the PR envoyproxy/envoy#18265 removed the `Closed` event for listener filter, since the Windows doesn't work well.

There is still have a corner case that can't be handled without the `Closed` event envoyproxy/envoy#18265 (comment)

This PR tries to introduce the `Closed` event back to the listener filter. As the comments on Windows code said, both `Read` and `Closed` can't be registered at same time due to the `Connection` doesn't support that yet. That means it shouldn't be a problem for the listener filter. Also currently, there is no Envoy code using both `Read` and `Closed` event, so it should be ok to remove those workaround code to make the both `Read` and `Closed` events registered to work with listener filter.

The full analysis is here envoyproxy/envoy#18265 (comment)

Signed-off-by: He Jie Xu <hejie.xu@intel.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

5 participants