Report handler panics as panics, not client disconnects - #1677
Conversation
da88253 to
43b9b56
Compare
| error!(request_log, "request handling panicked"; | ||
| "latency_us" => latency_us, | ||
| ); | ||
| return; |
There was a problem hiding this comment.
I think we'd still want to fire a DTrace probe for this case.
There was a problem hiding this comment.
When I finally get the test condition ironed out I will make sure to add that.
My follow up code that makes the instrumentation more abstract will have a clear spot for that to happen (the current draft I think doesn't fire the dtrace probe, but that is easily fixed.)
| let on_disconnect = guard((), |_| { | ||
| let latency_us = start_time.elapsed().as_micros(); | ||
|
|
||
| if std::thread::panicking() { |
There was a problem hiding this comment.
I don't think this condition is right. The thread currently panicking doesn't mean the handler panicked. One concrete example: suppose somebody else (outside of Dropshot) has a test that creates a Dropshot server, then does some work, the test fails (panics), resulting in everything being dropped. We'll wind up here because the thread is panicking, but it's not that the handler panicked.
(I've almost always found std::thread::panicking() to be the wrong check.)
I think the way to tell if the handler panicked is:
- for the
CancelOnDisconnectcase: we'd have to catch_unwind - for the
Detachedcase: check the result of awaiting on the tokio handle. I see we already do that and log a message about it below.
which makes me wonder how you ran into this? Are you in the CancelOnDisconnect case or does the Detached case not work right despite checking for that?
There was a problem hiding this comment.
Update: clicked through to #1359 and see that it's the Detached case you're seeing. If I'm understanding right, you should be getting an error log message saying the handler panicked, then we propagate the panic and then you get a message and DTrace probe about it being a 499?
There was a problem hiding this comment.
I will beef up the test cases and make sure I have all the reproducers as clear as possible at which point I should be able to figure out what the right check(s) should be. Thank you for your feedback!!
|
a19b6f9 adds a more thorough set of test cases and confirms your analysis that 48f7c1a makes the tests pass. I need to reread it a few more times to wrap my head around it and trim down the comments to a more appropriate quantity. I might be able to make the code a little more readable to my own eye as well. The main question that this surfaces is what kind of dtrace probe you would want to fire. Reuse request_done (as sketched out in 7609e8f) or create something else for it... I also imagine that for your programs in release builds where that the abort would prevent the dtrace probe from actually firing? Is my mental model accurate on that? |
A handler panic, a panic elsewhere in request handling (a version policy), a mid-handler client disconnect, and server teardown caused by a panic elsewhere in the process -- in both handler task modes where the mode matters. Also a dtrace(8)-verified test of the USDT probe payloads, runnable where dtrace and the privileges to use it exist (DROPSHOT_DTRACE_TEST=require turns its skip into a failure). The panic tests fail until the next commit: a panic escaping request handling is currently misreported as a client disconnection, in the log and in the request-done probe. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Poll http_request_handle inside catch_unwind: a caught panic defuses
the disconnect scopeguard, is logged with the panic message, fires the
request-done probe with status code 0 ("no response"), and propagates
as before. The scopeguard now runs only on cancellation, however
caused.
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
7609e8f to
58acfb7
Compare
2 participants
Supersedes #1359
We can keep or drop the tests at your discretion.