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

safelyExecute calls log too much #3277

Closed
niloc132 opened this issue Jan 9, 2023 · 0 comments · Fixed by #3278
Closed

safelyExecute calls log too much #3277

niloc132 opened this issue Jan 9, 2023 · 0 comments · Fixed by #3278
Labels
bug Something isn't working logging

Comments

@niloc132
Copy link
Member

niloc132 commented Jan 9, 2023

I've been running into this over the last few months, but it is a bigger issue with trees/rollups now, so i'd like to talk about either reverting this change or actually fixing callsites to log important things instead of everything: in https://github.com/deephaven/deephaven-core/pull/3101/files#r1034167610, safelyExecute and safelyExecuteLocked were turned up from debug to error.

The problem is that we use these calls to essentially say "something might go wrong here, but I don't want to hear about it, error handling is already in place elsewhere", which is probably helpful early in development, but if we ship code where this is acceptable, we've already screwed up. The specific case where this matters a lot is racing closed streams from the server, where the client doesn't have a "nice" way to say "thanks, go away now, i'm no longer interested" against the server sending results, so today the client just kills the stream, and the server then uses these error handling cases.

A few examples:

  • Browser window closes or refreshes - all streams stop, and any onNext/onError/onCompleted will now throw. There probably isn't a constructive reason to log this.
  • User changes their mind about what they want, usually during a long-running operation - without a mechanism in gRPC to terminate the call, it makes the most sense to just cancel the http call itself, avoid any client-side grpc handling, proto deserialization, etc. Likewise, there probably isnt a good reason to log this.
  • The same will apply to non-browser clients too, if they terminate, or for some reason get tired of waiting and cancel a long-running call.

Note that in order for there to be a race, the client either needs to be very spammy, or needs to be doing long enough calls that they can cancel before they are completed, which mostly means that we don't see this case when testing simple stuff, only real users hit this with heavy loads or with industrial-strength impatience.

So, I'd like to re-suppress those log messages. We probably did initially un-suppress them for good reason, as suggested before too much logic in the lambdas, so I further suggest that we replace the majority of our usage of these methods with something like this:

  • safelyOnError(observer, error)
  • safelyOnNext(observer, message) with generics to make sure the right message is passed in
  • safelyComplete(observer)
  • safelyComplete(observer, message) which will be onNext+complete, for unary calls and so on, might as well make an easy-mode for this which we do a lot

There is at least a case or two that don't follow this, but I suspect they might be errors and shouldn't be considered "safely execute" calls anyway

My inclination is to make all of these the "locked" to be more defensive, but no strong opinion there.

@niloc132 niloc132 added bug Something isn't working logging labels Jan 9, 2023
niloc132 added a commit to niloc132/deephaven-core that referenced this issue Jan 9, 2023
niloc132 added a commit that referenced this issue Jan 10, 2023
This removes safelyExecute and safelyExecuteLocked in favor of new
specific methods for sending messages to a stream or completing the
stream. All error cases should use the existing safelyError,
potentially in conjunction with securelyWrapError to ensure the message
is logged.

Fixes #3277
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working logging
Projects
None yet
Development

Successfully merging a pull request may close this issue.

1 participant