'user_vars' is missing in http-log even when there are errors #7532
Description
Version Information
Server Version:
<= 2.0.8
Environment
Cloud, OSS and EE
What is the expected behaviour?
http-log should have user_vars when the user can be determined.
What is the current behaviour?
http-log does not have user_vars when an invalid json body is sent to /v1/graphql.
How to reproduce the issue?
The following query (valid) produces this log:
curl 'http://127.0.0.1:8080/v1/graphql' -H 'content-type: application/json' -H 'x-hasura-role: user' -H 'x-hasura-user-id: 1' --data-raw '{"query":"query { __typename }","variables":null}'{
"type": "http-log",
"timestamp": "2021-09-09T15:42:14.035+0530",
"level": "info",
"detail": {
"operation": {
"query_execution_time": 0.00120527,
"user_vars": {
"x-hasura-role": "user",
"x-hasura-user-id": "1"
},
"request_id": "3cbd033c-1049-4ae7-ac17-ea5adf77b249",
"response_size": 36,
"query": {
"variables": null,
"query": "query { __typename }"
},
"request_mode": "single",
"request_read_time": 2.253e-05
},
"request_id": "3cbd033c-1049-4ae7-ac17-ea5adf77b249",
"http_info": {
"status": 200,
"http_version": "HTTP/1.1",
"url": "/v1/graphql",
"ip": "127.0.0.1",
"method": "POST",
"content_encoding": null
}
}
}Note the presence of user_vars at $.detail.operation.user_vars. However, if we send an invalid json body as follows:
curl 'http://127.0.0.1:8080/v1/graphql' -H 'content-type: application/json' -H 'x-hasura-role: user' -H 'x-hasura-user-id: 1' --data-raw 'not-a-valid-json-query'the log line is as follows:
{
"type": "http-log",
"timestamp": "2021-09-09T15:45:11.362+0530",
"level": "error",
"detail": {
"operation": {
"error": {
"path": "$",
"error": "Error in $: string at 'not-a-valid-json-query'",
"code": "invalid-json"
},
"request_id": "f3186318-4896-4b30-ad95-da0b01903601",
"response_size": 91,
"request_mode": "error",
"raw_query": "not-a-valid-json-query"
},
"request_id": "f3186318-4896-4b30-ad95-da0b01903601",
"http_info": {
"status": 200,
"http_version": "HTTP/1.1",
"url": "/v1/graphql",
"ip": "127.0.0.1",
"method": "POST",
"content_encoding": null
}
}
}The user_vars section isn't present even when the information is part of the query.
Any possible solutions?
Is this even possible? We can't delay parsing the request body till we resolve the user information because we send the request body to the auth webhook. Should we instead log raw headers along with the raw query when the body cannot be parsed? It isn't exactly user information but the headers should help get the user information if need be.