graphql-engine/server/src-lib/Hasura/Backends/DataConnector/Logging.hs
Antoine Leblanc cf531b05cb Rewrite Tracing to allow for only one TraceT in the entire stack.
This PR is on top of #7789.

### Description

This PR entirely rewrites the API of the Tracing library, to make `interpTraceT` a thing of the past. Before this change, we ran traces by sticking a `TraceT` on top of whatever we were doing. This had several major drawbacks:
- we were carrying a bunch of `TraceT` across the codebase, and the entire codebase had to know about it
- we needed to carry a second class constraint around (`HasReporterM`) to be able to run all of those traces
- we kept having to do stack rewriting with `interpTraceT`, which went from inconvenient to horrible
- we had to declare several behavioral instances on `TraceT m`

This PR rewrite all of `Tracing` using a more conventional model: there is ONE `TraceT` at the bottom of the stack, and there is an associated class constraint `MonadTrace`: any part of the code that happens to satisfy `MonadTrace` is able to create new traces. We NEVER have to do stack rewriting, `interpTraceT` is gone, and `TraceT` and `Reporter` become  implementation details that 99% of the code is blissfully unaware of: code that needs to do tracing only needs to declare that the monad in which it operates implements `MonadTrace`.

In doing so, this PR revealed **several bugs in the codebase**: places where we were expecting to trace something, but due to the default instance of `HasReporterM IO` we would actually not do anything. This PR also splits the code of `Tracing` in more byte-sized modules, with the goal of potentially moving to `server/lib` down the line.

### Remaining work

This PR is a draft; what's left to do is:
- [x] make Pro compile; i haven't updated `HasuraPro/Main` yet
- [x] document Tracing by writing a note that explains how to use the library, and the meaning of "reporter", "trace" and "span", as well as the pitfalls
- [x] discuss some of the trade-offs in the implementation, which is why i'm opening this PR already despite it not fully building yet
- [x] it depends on #7789 being merged first

PR-URL: https://github.com/hasura/graphql-engine-mono/pull/7791
GitOrigin-RevId: cadd32d039134c93ddbf364599a2f4dd988adea8
2023-03-13 17:38:39 +00:00

114 lines
4.8 KiB
Haskell

module Hasura.Backends.DataConnector.Logging
( logAgentRequest,
logClientError,
)
where
import Control.Lens ((^.))
import Data.Aeson (object, (.=))
import Data.Aeson.Key qualified as K
import Data.Aeson.KeyMap (KeyMap)
import Data.Aeson.KeyMap qualified as KM
import Data.ByteString qualified as BS
import Data.ByteString.Lazy qualified as BSL
import Data.CaseInsensitive qualified as CI
import Data.Text qualified as Text
import Data.Text.Encoding qualified as Text
import Data.Text.Encoding.Error (lenientDecode)
import Hasura.HTTP qualified
import Hasura.Logging (EngineLogType (..), Hasura, LogLevel (..), Logger (..), ToEngineLog (..))
import Hasura.Prelude
import Hasura.Tracing (MonadTrace)
import Hasura.Tracing qualified as Tracing
import Hasura.Tracing.TraceId (spanIdToHex, traceIdToHex)
import Network.HTTP.Client.Transformable (Header, HttpException (..), Request, Response (..), body, headers, method, path, statusCode, url)
import Servant.Client (ClientError (..), responseStatusCode, showBaseUrl)
import Servant.Client.Core (RequestF (..))
data RequestLogInfo = RequestLogInfo
{ _rliRequestMethod :: Text,
_rliRequestUri :: Text,
_rliRequestHeaders :: KeyMap Text,
_rliRequestBody :: Maybe Text
}
deriving stock (Show, Eq)
data AgentCommunicationLog = AgentCommunicationLog
{ _aclRequest :: Maybe RequestLogInfo,
_aclResponseStatusCode :: Maybe Int,
_aclError :: Maybe Text,
_aclTraceId :: Text,
_aclSpanId :: Text
}
deriving stock (Show, Eq)
instance ToEngineLog AgentCommunicationLog Hasura where
toEngineLog AgentCommunicationLog {..} =
(LevelDebug, ELTDataConnectorLog, logJson)
where
logJson =
object $
catMaybes
[ ("requestMethod" .=) . _rliRequestMethod <$> _aclRequest,
("requestUri" .=) . _rliRequestUri <$> _aclRequest,
("requestHeaders" .=) . _rliRequestHeaders <$> _aclRequest,
("requestBody" .=) <$> (_rliRequestBody =<< _aclRequest),
("responseStatusCode" .=) <$> _aclResponseStatusCode,
("error" .=) <$> _aclError,
Just $ "traceId" .= _aclTraceId,
Just $ "spanId" .= _aclSpanId
]
logAgentRequest :: (MonadIO m, MonadTrace m) => Logger Hasura -> Request -> Either HttpException (Response BSL.ByteString) -> m ()
logAgentRequest (Logger writeLog) req responseOrError = do
traceCtx <- Tracing.currentContext
let _aclRequest = Just $ extractRequestLogInfoFromClientRequest req
_aclResponseStatusCode = case responseOrError of
Right response -> Just . statusCode $ responseStatus response
Left httpExn -> Hasura.HTTP.getHTTPExceptionStatus $ Hasura.HTTP.HttpException httpExn
_aclError = either (Just . Hasura.HTTP.serializeHTTPExceptionMessageForDebugging) (const Nothing) responseOrError
_aclTraceId = maybe "" (bsToTxt . traceIdToHex . Tracing.tcCurrentTrace) traceCtx
_aclSpanId = maybe "" (bsToTxt . spanIdToHex . Tracing.tcCurrentSpan) traceCtx
writeLog AgentCommunicationLog {..}
extractRequestLogInfoFromClientRequest :: Request -> RequestLogInfo
extractRequestLogInfoFromClientRequest req =
let _rliRequestMethod = req ^. method & fromUtf8
_rliRequestUri = req ^. url
_rliRequestPath = req ^. path & fromUtf8
_rliRequestHeaders = req ^. headers & headersToKeyMap
_rliRequestBody = req ^. body <&> (BSL.toStrict >>> fromUtf8)
in RequestLogInfo {..}
logClientError :: (MonadIO m, MonadTrace m) => Logger Hasura -> ClientError -> m ()
logClientError (Logger writeLog) clientError = do
traceCtx <- Tracing.currentContext
let _aclResponseStatusCode = case clientError of
FailureResponse _ response -> Just . statusCode $ responseStatusCode response
_ -> Nothing
_aclRequest = extractRequestLogInfoFromClientInfo clientError
_aclError = Just $ Hasura.HTTP.serializeServantClientErrorMessageForDebugging clientError
_aclTraceId = maybe "" (bsToTxt . traceIdToHex . Tracing.tcCurrentTrace) traceCtx
_aclSpanId = maybe "" (bsToTxt . spanIdToHex . Tracing.tcCurrentSpan) traceCtx
writeLog AgentCommunicationLog {..}
extractRequestLogInfoFromClientInfo :: ClientError -> Maybe RequestLogInfo
extractRequestLogInfoFromClientInfo = \case
FailureResponse request _ ->
let _rliRequestMethod = requestMethod request & fromUtf8
(baseUrl, path') = requestPath request
_rliRequestUri = Text.pack (showBaseUrl baseUrl) <> fromUtf8 path'
_rliRequestHeaders = headersToKeyMap . toList $ requestHeaders request
_rliRequestBody = Nothing
in Just RequestLogInfo {..}
_ -> Nothing
headersToKeyMap :: [Header] -> KeyMap Text
headersToKeyMap headers' =
headers'
<&> (\(name, value) -> (K.fromText . fromUtf8 $ CI.original name, fromUtf8 value))
& KM.fromList
fromUtf8 :: BS.ByteString -> Text
fromUtf8 = Text.decodeUtf8With lenientDecode