Add id in logs in order to identify all the logs related to an error, to a request

[bnjjj]

Here is a sub task from #1840

The original idea was to provide a way to identify logs related to an error received in a GraphQL response with for example an error_id. I think we can do better by introduce a request_id in logs instead of just an error_id. In that way people who wants to debug a behavior without an error would be able to easily debug just by grepping the request_id in the logs.

My proposal is to introduce request_id in fields for JSON formatter and directly in the text with of the TextFormatter (including nice formatting).

An addition to this experience we could introduce a way to directly ask to the router to return the request_id in the response thanks to GraphQL extensions to not limit it only for error cases. The way I imagine it is a configuration to indicate if we want to enable this debug mode and what kind of header should we pass to enable the ability to return the request_id.

An addition to this experience we could introduce a way to directly ask to the router to return the request_id in the response headers.

Something like

expose_request_id:
    enabled: true # Disabled by default
    header_name: "ROUTER_DEBUG_MODE" # Send ROUTER_DEBUG_MODE = true in headers to return the request_id in extensions

and have an answer like this:

{
  "data": {
    "topProducts": [
      {
        "name": "Table"
      },
      {
        "name": "Couch"
      },
      {
        "name": "Chair"
      }
    ]
  }
}

headers:

apollo_request_id: b060011c6c016070fc21a6c543dda554

And the formatted text log for example:

2022-10-21T14:49:11.557950Z ERROR [request_id=b060011c6c016070fc21a6c543dda554] apollo_router::query_planner::execution: Fetch error: HTTP fetch failed from 'accounts': HTTP fetch failed from 'accounts': error trying to connect: tcp connect error: Connection refused (os error 111)

TODO:

• Rename to trace_id
• Send it in apollo studio in response headers

[garypen]

I like it. I wonder why have header control though? If it's good to have a request_id, why not just always return it as an extension? Security? Performance?

I still think we want error codes as well so we can easily classify errors and simplify downstream processing.

[bnjjj]

I don't know why not enabling it by default, it could just be a noise I think. But I don't have strong opinions.

For error codes we will still be able to classify errors thanks to the type field in extension which specifies the kind of error it is.

For example:

{
  "data": {},
  "errors": [
    {
      "message": "HTTP fetch failed from 'accounts': HTTP fetch failed from 'accounts': error trying to connect: tcp connect error: Connection refused (os error 111)",
      "path": [],
      "extensions": {
        "type": "SubrequestHttpError",
        "service": "accounts",
        "reason": "HTTP fetch failed from 'accounts': error trying to connect: tcp connect error: Connection refused (os error 111)",
        "request_id": "5e6a6bda8d0dca26e5aec14dafa6d96f"
      }
    }
  ]
}

[bnjjj]

However it could be also way more easy to always enable the return of request_id because I won't have to manually add it on every errors in the errors array...

[garypen]

Regarding error classification. I'm thinking about the use case where an admin is looking at server logs, not the use case where a client is looking at a response.

[bnjjj]

@garypen To make sure there isn't any misunderstandings could you provide a real world example of what you would like to have as an admin. Maybe it's already done, but I want to be sure I understand correctly.

BTW I made a changes in the way we will expose request_id. At the end I think it's definitely better to expose it in response headers instead of graphql extensions.