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(qe): fix error logging #16287
fix(qe): fix error logging #16287
Conversation
50932be
to
84f0538
Compare
b59ed44
to
46a1d44
Compare
e96216d
to
cbb2d72
Compare
packages/client/tests/functional/query-error-logging/_matrix.ts
Outdated
Show resolved
Hide resolved
6a58e15
to
e660458
Compare
This comment was marked as outdated.
This comment was marked as outdated.
98c615b
to
a13c40c
Compare
1348600
to
00a497e
Compare
Did the following:
diff --git a/query-engine/request-handlers/src/graphql/handler.rs b/query-engine/request-handlers/src/graphql/handler.rs
index 39cb2e08e1..15690c5b47 100644
--- a/query-engine/request-handlers/src/graphql/handler.rs
+++ b/query-engine/request-handlers/src/graphql/handler.rs
@@ -26,7 +26,6 @@ impl<'a> GraphQlHandler<'a> {
pub async fn handle(&self, body: GraphQlBody, tx_id: Option<TxId>, trace_id: Option<String>) -> PrismaResponse {
tracing::debug!("Incoming GraphQL query: {:?}", &body);
-
match body.into_doc() {
Ok(QueryDocument::Single(query)) => self.handle_single(query, tx_id, trace_id).await,
Ok(QueryDocument::Multi(batch)) => match batch.compact(self.query_schema) {
@@ -44,7 +43,7 @@ impl<'a> GraphQlHandler<'a> {
async fn handle_single(&self, query: Operation, tx_id: Option<TxId>, trace_id: Option<String>) -> PrismaResponse {
use user_facing_errors::Error;
-
+ dbg!("Running single {}", query.clone());
let gql_response = match AssertUnwindSafe(self.handle_graphql(query, tx_id, trace_id))
.catch_unwind()
.await
@@ -201,6 +200,9 @@ impl<'a> GraphQlHandler<'a> {
tx_id: Option<TxId>,
trace_id: Option<String>,
) -> query_core::Result<ResponseData> {
+ if 2 > 1 {
+ panic!("Forced")
+ }
self.executor
.execute(tx_id, query_doc, self.query_schema.clone(), trace_id)
.await
I think this is ready for another pass. |
In case error logging is enabled in the client, a middleware captures errors and uses the event emitter to notify about them. This way, errors are captured in the same way accross the different engines, by capturing errors one level above in the call stack (at the client level) After this approach is validated, next commits will: - Filter the kind of errors that should be logged - Create the appropriate structure for the logging event being emitted - Add unit tests to check the behavior with the binary engine.
Our middleware is FIFO (a queue rather than an actual stack) so the first middleware would call on other middlewares defined by the user before hitting the actual request. As we don't want to observe on users's middleware errors, I moved the logic from a middleware to the point where the request is being made. Also notice we don't want to block on user handling code upon request resolving, so the error handling code runs asynchronously. This has a side effect. If the execution of the program halts, before the promise is resolved in the next event loop tick, then the error won't be logged. This might not be an acceptable trade-off, and I might change it in a follow-up commit.
Error will flow up the stack and be captured by the RequestHandler
Co-authored-by: Daniel Starns <danielstarns@hotmail.com>
This change is about: 1. getting rid of lastErrorLog, lastRustError, lastPanic state and instead build all the error information when we parse a log line if that's pertinent 2. Let request errors flow up the stack instead to be emitted in the RequestHandler. 3. Only emit events explicitly during lifecycle management of the binary engine
00a497e
to
ef408ae
Compare
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
One comment/question, but other than that, looks very good to me! Thank you for the fix and for the nice refactoring!
Fixes #16226
This patch ensures that errors resulting in a failed query generate an event if the error logger is enabled.
This aligns with the principle of least astonishment: The user expects errors to be logged, and due to the lack of a formal definition of what constitutes an error, the most sensible approach in my opinion (backed by bug reports like #14933) is to log any condition leading to an error in the processing of the query, which is, in turn, any of the four well-known classes of errors.
This is done now in the RequestHandler thus capturing any possible error condition happening during query processing. Before, every different engine was doing this differently, and errors were not properly captured.
A smoke test suite proves that
NotFoundError
errors infindXOrThrow
are now properly emitted. I consider this enough, given that the code that handles the error is the same for every exception thrown during query execution.