mirror of
https://github.com/hasura/graphql-engine.git
synced 2024-12-15 01:12:56 +03:00
server: pass http and websocket request to logging context (#5470)
* pass request body to logging context in all cases * add message size logging on the websocket API this is required by graphql-engine-pro/#416 * message size logging on websocket API As we need to log all messages recieved/sent by the websocket server, it makes sense to log them as part of the websocket server event logs. Previously message recieved were logged inside the onMessage handler, and messages sent were logged only for "data" messages (as a server event log) * fix review comments Co-authored-by: Phil Freeman <phil@hasura.io>
This commit is contained in:
Anon Ray
GitHub
parent
6c7e63791f
commit
046a783a14
@ -604,13 +604,13 @@ execQuery env queryBs = do
|
||||
instance Tracing.HasReporter AppM
|
||||
|
||||
instance HttpLog AppM where
|
||||
logHttpError logger userInfoM reqId httpReq req qErr headers =
|
||||
logHttpError logger userInfoM reqId waiReq req qErr headers =
|
||||
unLogger logger $ mkHttpLog $
|
||||
mkHttpErrorLogContext userInfoM reqId httpReq qErr req Nothing Nothing headers
|
||||
mkHttpErrorLogContext userInfoM reqId waiReq req qErr Nothing Nothing headers
|
||||
|
||||
logHttpSuccess logger userInfoM reqId httpReq _ _ compressedResponse qTime cType headers =
|
||||
logHttpSuccess logger userInfoM reqId waiReq _reqBody _response compressedResponse qTime cType headers =
|
||||
unLogger logger $ mkHttpLog $
|
||||
mkHttpAccessLogContext userInfoM reqId httpReq compressedResponse qTime cType headers
|
||||
mkHttpAccessLogContext userInfoM reqId waiReq compressedResponse qTime cType headers
|
||||
|
||||
instance MonadExecuteQuery AppM where
|
||||
executeQuery _ _ _ pgCtx _txAccess tx =
|
||||
|
||||
@ -5,6 +5,7 @@ module Hasura.GraphQL.Transport.WebSocket.Server
|
||||
( WSId(..)
|
||||
, WSLog(..)
|
||||
, WSEvent(..)
|
||||
, MessageDetails(..)
|
||||
, WSConn
|
||||
, getData
|
||||
, getWSId
|
||||
@ -64,12 +65,20 @@ instance J.ToJSON WSId where
|
||||
toJSON (WSId uuid) =
|
||||
J.toJSON $ UUID.toText uuid
|
||||
|
||||
-- | Websocket message and other details
|
||||
data MessageDetails
|
||||
= MessageDetails
|
||||
{ _mdMessage :: !TBS.TByteString
|
||||
, _mdMessageSize :: !Int64
|
||||
} deriving (Show, Eq)
|
||||
$(J.deriveToJSON (J.aesonDrop 3 J.snakeCase) ''MessageDetails)
|
||||
|
||||
data WSEvent
|
||||
= EConnectionRequest
|
||||
| EAccepted
|
||||
| ERejected
|
||||
| EMessageReceived !TBS.TByteString
|
||||
| EMessageSent !TBS.TByteString
|
||||
| EMessageReceived !MessageDetails
|
||||
| EMessageSent !MessageDetails
|
||||
| EJwtExpired
|
||||
| ECloseReceived
|
||||
| ECloseSent !TBS.TByteString
|
||||
@ -315,13 +324,15 @@ createServerApp (WSServer logger@(L.Logger writeLog) serverStatus) wsHandlers !i
|
||||
-- Regardless this should be safe:
|
||||
handleJust (guard . E.isResourceVanishedError) (\()-> throw WS.ConnectionClosed) $
|
||||
WS.receiveData conn
|
||||
logWSLog logger $ WSLog wsId (EMessageReceived $ TBS.fromLBS msg) Nothing
|
||||
let message = MessageDetails (TBS.fromLBS msg) (BL.length msg)
|
||||
logWSLog logger $ WSLog wsId (EMessageReceived message) Nothing
|
||||
_hOnMessage wsHandlers wsConn msg
|
||||
|
||||
let send = forever $ do
|
||||
WSQueueResponse msg wsInfo <- liftIO $ STM.atomically $ STM.readTQueue sendQ
|
||||
let message = MessageDetails (TBS.fromLBS msg) (BL.length msg)
|
||||
liftIO $ WS.sendTextData conn msg
|
||||
logWSLog logger $ WSLog wsId (EMessageSent $ TBS.fromLBS msg) wsInfo
|
||||
logWSLog logger $ WSLog wsId (EMessageSent message) wsInfo
|
||||
|
||||
-- withAsync lets us be very sure that if e.g. an async exception is raised while we're
|
||||
-- forking that the threads we launched will be cleaned up. See also below.
|
||||
|
||||
@ -283,8 +283,8 @@ mkSpockAction serverCtx qErrEncoder qErrModifier apiHandler = do
|
||||
lift $ Tracing.attachMetadata [("request_id", unRequestId requestId)]
|
||||
|
||||
userInfoE <- fmap fst <$> lift (resolveUserInfo logger manager headers authMode)
|
||||
userInfo <- either (logErrorAndResp Nothing requestId req (Left reqBody) False headers . qErrModifier)
|
||||
return userInfoE
|
||||
userInfo <- either (logErrorAndResp Nothing requestId req (reqBody, Nothing) False headers . qErrModifier)
|
||||
return userInfoE
|
||||
|
||||
let handlerState = HandlerCtx serverCtx userInfo headers requestId ipAddress
|
||||
includeInternal = shouldIncludeInternal (_uiRole userInfo) $
|
||||
@ -296,7 +296,7 @@ mkSpockAction serverCtx qErrEncoder qErrModifier apiHandler = do
|
||||
return (res, Nothing)
|
||||
AHPost handler -> do
|
||||
parsedReqE <- runExceptT $ parseBody reqBody
|
||||
parsedReq <- either (logErrorAndResp (Just userInfo) requestId req (Left reqBody) includeInternal headers . qErrModifier)
|
||||
parsedReq <- either (logErrorAndResp (Just userInfo) requestId req (reqBody, Nothing) includeInternal headers . qErrModifier)
|
||||
return parsedReqE
|
||||
res <- lift $ runReaderT (runExceptT $ handler parsedReq) handlerState
|
||||
return (res, Just parsedReq)
|
||||
@ -306,9 +306,8 @@ mkSpockAction serverCtx qErrEncoder qErrModifier apiHandler = do
|
||||
|
||||
-- log and return result
|
||||
case modResult of
|
||||
Left err -> let jErr = maybe (Left reqBody) (Right . toJSON) q
|
||||
in logErrorAndResp (Just userInfo) requestId req jErr includeInternal headers err
|
||||
Right res -> logSuccessAndResp (Just userInfo) requestId req (fmap toJSON q) res (Just (ioWaitTime, serviceTime)) headers
|
||||
Left err -> logErrorAndResp (Just userInfo) requestId req (reqBody, toJSON <$> q) includeInternal headers err
|
||||
Right res -> logSuccessAndResp (Just userInfo) requestId req (reqBody, toJSON <$> q) res (Just (ioWaitTime, serviceTime)) headers
|
||||
|
||||
where
|
||||
logger = scLogger serverCtx
|
||||
@ -318,31 +317,31 @@ mkSpockAction serverCtx qErrEncoder qErrModifier apiHandler = do
|
||||
=> Maybe UserInfo
|
||||
-> RequestId
|
||||
-> Wai.Request
|
||||
-> Either BL.ByteString Value
|
||||
-> (BL.ByteString, Maybe Value)
|
||||
-> Bool
|
||||
-> [HTTP.Header]
|
||||
-> QErr
|
||||
-> Spock.ActionCtxT ctx m a
|
||||
logErrorAndResp userInfo reqId req reqBody includeInternal headers qErr = do
|
||||
lift $ logHttpError logger userInfo reqId req reqBody qErr headers
|
||||
logErrorAndResp userInfo reqId waiReq req includeInternal headers qErr = do
|
||||
lift $ logHttpError logger userInfo reqId waiReq req qErr headers
|
||||
Spock.setStatus $ qeStatus qErr
|
||||
Spock.json $ qErrEncoder includeInternal qErr
|
||||
|
||||
logSuccessAndResp userInfo reqId req reqBody result qTime reqHeaders =
|
||||
logSuccessAndResp userInfo reqId waiReq reqBody result qTime reqHeaders =
|
||||
case result of
|
||||
JSONResp (HttpResponse encJson h) ->
|
||||
possiblyCompressedLazyBytes userInfo reqId req reqBody qTime (encJToLBS encJson)
|
||||
possiblyCompressedLazyBytes userInfo reqId waiReq reqBody qTime (encJToLBS encJson)
|
||||
(pure jsonHeader <> h) reqHeaders
|
||||
RawResp (HttpResponse rawBytes h) ->
|
||||
possiblyCompressedLazyBytes userInfo reqId req reqBody qTime rawBytes h reqHeaders
|
||||
possiblyCompressedLazyBytes userInfo reqId waiReq reqBody qTime rawBytes h reqHeaders
|
||||
|
||||
possiblyCompressedLazyBytes userInfo reqId req reqBody qTime respBytes respHeaders reqHeaders = do
|
||||
possiblyCompressedLazyBytes userInfo reqId waiReq req qTime respBytes respHeaders reqHeaders = do
|
||||
let (compressedResp, mEncodingHeader, mCompressionType) =
|
||||
compressResponse (Wai.requestHeaders req) respBytes
|
||||
compressResponse (Wai.requestHeaders waiReq) respBytes
|
||||
encodingHeader = maybe [] pure mEncodingHeader
|
||||
reqIdHeader = (requestIdHeader, txtToBs $ unRequestId reqId)
|
||||
allRespHeaders = pure reqIdHeader <> encodingHeader <> respHeaders
|
||||
lift $ logHttpSuccess logger userInfo reqId req reqBody respBytes compressedResp qTime mCompressionType reqHeaders
|
||||
lift $ logHttpSuccess logger userInfo reqId waiReq req respBytes compressedResp qTime mCompressionType reqHeaders
|
||||
mapM_ setHeader allRespHeaders
|
||||
Spock.lazyBytes compressedResp
|
||||
|
||||
@ -814,7 +813,7 @@ raiseGenericApiError logger headers qErr = do
|
||||
req <- Spock.request
|
||||
reqBody <- liftIO $ Wai.strictRequestBody req
|
||||
reqId <- getRequestId $ Wai.requestHeaders req
|
||||
lift $ logHttpError logger Nothing reqId req (Left reqBody) qErr headers
|
||||
lift $ logHttpError logger Nothing reqId req (reqBody, Nothing) qErr headers
|
||||
setHeader jsonHeader
|
||||
Spock.setStatus $ qeStatus qErr
|
||||
Spock.lazyBytes $ encode qErr
|
||||
|
||||
@ -122,8 +122,8 @@ class (Monad m) => HttpLog m where
|
||||
-- ^ request id of the request
|
||||
-> Wai.Request
|
||||
-- ^ the Wai.Request object
|
||||
-> Either BL.ByteString Value
|
||||
-- ^ the actual request body (bytestring if unparsed, Aeson value if parsed)
|
||||
-> (BL.ByteString, Maybe Value)
|
||||
-- ^ the request body and parsed request
|
||||
-> QErr
|
||||
-- ^ the error
|
||||
-> [HTTP.Header]
|
||||
@ -139,8 +139,8 @@ class (Monad m) => HttpLog m where
|
||||
-- ^ request id of the request
|
||||
-> Wai.Request
|
||||
-- ^ the Wai.Request object
|
||||
-> Maybe Value
|
||||
-- ^ the actual request body, if present
|
||||
-> (BL.ByteString, Maybe Value)
|
||||
-- ^ the request body and parsed request
|
||||
-> BL.ByteString
|
||||
-- ^ the response bytes
|
||||
-> BL.ByteString
|
||||
@ -196,9 +196,7 @@ data OperationLog
|
||||
, olError :: !(Maybe QErr)
|
||||
} deriving (Show, Eq)
|
||||
|
||||
$(deriveToJSON (aesonDrop 2 snakeCase)
|
||||
{ omitNothingFields = True
|
||||
} ''OperationLog)
|
||||
$(deriveToJSON (aesonDrop 2 snakeCase){omitNothingFields = True} ''OperationLog)
|
||||
|
||||
data HttpLogContext
|
||||
= HttpLogContext
|
||||
@ -247,20 +245,20 @@ mkHttpErrorLogContext
|
||||
-- ^ Maybe because it may not have been resolved
|
||||
-> RequestId
|
||||
-> Wai.Request
|
||||
-> (BL.ByteString, Maybe Value)
|
||||
-> QErr
|
||||
-> Either BL.ByteString Value
|
||||
-> Maybe (DiffTime, DiffTime)
|
||||
-> Maybe CompressionType
|
||||
-> [HTTP.Header]
|
||||
-> HttpLogContext
|
||||
mkHttpErrorLogContext userInfoM reqId req err query mTiming compressTypeM headers =
|
||||
mkHttpErrorLogContext userInfoM reqId waiReq (reqBody, parsedReq) err mTiming compressTypeM headers =
|
||||
let http = HttpInfoLog
|
||||
{ hlStatus = qeStatus err
|
||||
, hlMethod = bsToTxt $ Wai.requestMethod req
|
||||
, hlSource = Wai.getSourceFromFallback req
|
||||
, hlPath = bsToTxt $ Wai.rawPathInfo req
|
||||
, hlHttpVersion = Wai.httpVersion req
|
||||
, hlCompression = compressTypeM
|
||||
, hlMethod = bsToTxt $ Wai.requestMethod waiReq
|
||||
, hlSource = Wai.getSourceFromFallback waiReq
|
||||
, hlPath = bsToTxt $ Wai.rawPathInfo waiReq
|
||||
, hlHttpVersion = Wai.httpVersion waiReq
|
||||
, hlCompression = compressTypeM
|
||||
, hlHeaders = headers
|
||||
}
|
||||
op = OperationLog
|
||||
@ -269,8 +267,8 @@ mkHttpErrorLogContext userInfoM reqId req err query mTiming compressTypeM header
|
||||
, olResponseSize = Just $ BL.length $ encode err
|
||||
, olRequestReadTime = Seconds . fst <$> mTiming
|
||||
, olQueryExecutionTime = Seconds . snd <$> mTiming
|
||||
, olQuery = either (const Nothing) Just query
|
||||
, olRawQuery = either (Just . bsToTxt . BL.toStrict) (const Nothing) query
|
||||
, olQuery = parsedReq
|
||||
, olRawQuery = maybe (Just $ bsToTxt $ BL.toStrict reqBody) (const Nothing) parsedReq
|
||||
, olError = Just err
|
||||
}
|
||||
in HttpLogContext http op
|
||||
|
||||
Loading…
Reference in New Issue
Block a user