Skip to content

Commit

Permalink
feat: add timing for the api request parse
Browse files Browse the repository at this point in the history
  • Loading branch information
laurenceisla authored and steve-chavez committed Nov 24, 2023
1 parent 850b15f commit b538ab9
Show file tree
Hide file tree
Showing 3 changed files with 40 additions and 30 deletions.
56 changes: 32 additions & 24 deletions src/PostgREST/App.hs
Original file line number Diff line number Diff line change
Expand Up @@ -145,12 +145,17 @@ postgrestResponse appState conf@AppConfig{..} maybeSchemaCache pgVer authResult@

body <- lift $ Wai.strictRequestBody req

apiRequest <-
liftEither . mapLeft Error.ApiRequestError $
ApiRequest.userApiRequest conf req body sCache
(parseTime, apiRequest) <-
calcTiming configServerTimingEnabled $
liftEither . mapLeft Error.ApiRequestError $
ApiRequest.userApiRequest conf req body sCache

let jwtTiming = (SMJwt, if configServerTimingEnabled then Auth.getJwtDur req else Nothing)
handleRequest authResult conf appState (Just authRole /= configDbAnonRole) configDbPreparedStatements pgVer apiRequest sCache jwtTiming
let
jwtAndParseTiming =
[(SMJwt, if configServerTimingEnabled then Auth.getJwtDur req else Nothing)
,(SMParse, parseTime)]

handleRequest authResult conf appState (Just authRole /= configDbAnonRole) configDbPreparedStatements pgVer apiRequest sCache jwtAndParseTiming

runDbHandler :: AppState.AppState -> SQL.IsolationLevel -> SQL.Mode -> Bool -> Bool -> DbHandler b -> Handler IO b
runDbHandler appState isoLvl mode authenticated prepared handler = do
Expand All @@ -164,72 +169,72 @@ runDbHandler appState isoLvl mode authenticated prepared handler = do

liftEither resp

handleRequest :: AuthResult -> AppConfig -> AppState.AppState -> Bool -> Bool -> PgVersion -> ApiRequest -> SchemaCache -> (ServerMetric, Maybe Double) -> Handler IO Wai.Response
handleRequest AuthResult{..} conf appState authenticated prepared pgVer apiReq@ApiRequest{..} sCache jwtTime =
handleRequest :: AuthResult -> AppConfig -> AppState.AppState -> Bool -> Bool -> PgVersion -> ApiRequest -> SchemaCache -> [(ServerMetric, Maybe Double)] -> Handler IO Wai.Response
handleRequest AuthResult{..} conf appState authenticated prepared pgVer apiReq@ApiRequest{..} sCache jwtAndParseTime =
case (iAction, iTarget) of
(ActionRead headersOnly, TargetIdent identifier) -> do
(planTime', wrPlan) <- withTiming $ liftEither $ Plan.wrappedReadPlan identifier conf sCache apiReq
(txTime', resultSet) <- withTiming $ runQuery roleIsoLvl Nothing (Plan.wrTxMode wrPlan) $ Query.readQuery wrPlan conf apiReq
(renderTime', pgrst) <- withTiming $ liftEither $ Response.readResponse wrPlan headersOnly identifier apiReq resultSet
let metrics = Map.fromList [(SMPlan, planTime'), (SMTransaction, txTime'), (SMRender, renderTime'), jwtTime]
let metrics = Map.fromList $ [(SMPlan, planTime'), (SMTransaction, txTime'), (SMRender, renderTime')] ++ jwtAndParseTime
return $ pgrstResponse metrics pgrst

(ActionMutate MutationCreate, TargetIdent identifier) -> do
(planTime', mrPlan) <- withTiming $ liftEither $ Plan.mutateReadPlan MutationCreate apiReq identifier conf sCache
(txTime', resultSet) <- withTiming $ runQuery roleIsoLvl Nothing (Plan.mrTxMode mrPlan) $ Query.createQuery mrPlan apiReq conf
(renderTime', pgrst) <- withTiming $ liftEither $ Response.createResponse identifier mrPlan apiReq resultSet
let metrics = Map.fromList [(SMPlan, planTime'), (SMTransaction, txTime'), (SMRender, renderTime'), jwtTime]
let metrics = Map.fromList $ [(SMPlan, planTime'), (SMTransaction, txTime'), (SMRender, renderTime')] ++ jwtAndParseTime
return $ pgrstResponse metrics pgrst

(ActionMutate MutationUpdate, TargetIdent identifier) -> do
(planTime', mrPlan) <- withTiming $ liftEither $ Plan.mutateReadPlan MutationUpdate apiReq identifier conf sCache
(txTime', resultSet) <- withTiming $ runQuery roleIsoLvl Nothing (Plan.mrTxMode mrPlan) $ Query.updateQuery mrPlan apiReq conf
(renderTime', pgrst) <- withTiming $ liftEither $ Response.updateResponse mrPlan apiReq resultSet
let metrics = Map.fromList [(SMPlan, planTime'), (SMTransaction, txTime'), (SMRender, renderTime'), jwtTime]
let metrics = Map.fromList $ [(SMPlan, planTime'), (SMTransaction, txTime'), (SMRender, renderTime')] ++ jwtAndParseTime
return $ pgrstResponse metrics pgrst

(ActionMutate MutationSingleUpsert, TargetIdent identifier) -> do
(planTime', mrPlan) <- withTiming $ liftEither $ Plan.mutateReadPlan MutationSingleUpsert apiReq identifier conf sCache
(txTime', resultSet) <- withTiming $ runQuery roleIsoLvl Nothing (Plan.mrTxMode mrPlan) $ Query.singleUpsertQuery mrPlan apiReq conf
(renderTime', pgrst) <- withTiming $ liftEither $ Response.singleUpsertResponse mrPlan apiReq resultSet
let metrics = Map.fromList [(SMPlan, planTime'), (SMTransaction, txTime'), (SMRender, renderTime'), jwtTime]
let metrics = Map.fromList $ [(SMPlan, planTime'), (SMTransaction, txTime'), (SMRender, renderTime')] ++ jwtAndParseTime
return $ pgrstResponse metrics pgrst

(ActionMutate MutationDelete, TargetIdent identifier) -> do
(planTime', mrPlan) <- withTiming $ liftEither $ Plan.mutateReadPlan MutationDelete apiReq identifier conf sCache
(txTime', resultSet) <- withTiming $ runQuery roleIsoLvl Nothing (Plan.mrTxMode mrPlan) $ Query.deleteQuery mrPlan apiReq conf
(renderTime', pgrst) <- withTiming $ liftEither $ Response.deleteResponse mrPlan apiReq resultSet
let metrics = Map.fromList [(SMPlan, planTime'), (SMTransaction, txTime'), (SMRender, renderTime'), jwtTime]
let metrics = Map.fromList $ [(SMPlan, planTime'), (SMTransaction, txTime'), (SMRender, renderTime')] ++ jwtAndParseTime
return $ pgrstResponse metrics pgrst

(ActionInvoke invMethod, TargetProc identifier _) -> do
(planTime', cPlan) <- withTiming $ liftEither $ Plan.callReadPlan identifier conf sCache apiReq invMethod
(txTime', resultSet) <- withTiming $ runQuery (fromMaybe roleIsoLvl $ pdIsoLvl (Plan.crProc cPlan)) (pdTimeout $ Plan.crProc cPlan) (Plan.crTxMode cPlan) $ Query.invokeQuery (Plan.crProc cPlan) cPlan apiReq conf pgVer
(renderTime', pgrst) <- withTiming $ liftEither $ Response.invokeResponse cPlan invMethod (Plan.crProc cPlan) apiReq resultSet
let metrics = Map.fromList [(SMPlan, planTime'), (SMTransaction, txTime'), (SMRender, renderTime'), jwtTime]
let metrics = Map.fromList $ [(SMPlan, planTime'), (SMTransaction, txTime'), (SMRender, renderTime')] ++ jwtAndParseTime
return $ pgrstResponse metrics pgrst

(ActionInspect headersOnly, TargetDefaultSpec tSchema) -> do
(planTime', iPlan) <- withTiming $ liftEither $ Plan.inspectPlan apiReq
(txTime', oaiResult) <- withTiming $ runQuery roleIsoLvl Nothing (Plan.ipTxmode iPlan) $ Query.openApiQuery sCache pgVer conf tSchema
(renderTime', pgrst) <- withTiming $ liftEither $ Response.openApiResponse (T.decodeUtf8 prettyVersion, docsVersion) headersOnly oaiResult conf sCache iSchema iNegotiatedByProfile
let metrics = Map.fromList [(SMPlan, planTime'), (SMTransaction, txTime'), (SMRender, renderTime'), jwtTime]
let metrics = Map.fromList $ [(SMPlan, planTime'), (SMTransaction, txTime'), (SMRender, renderTime')] ++ jwtAndParseTime
return $ pgrstResponse metrics pgrst

(ActionInfo, TargetIdent identifier) -> do
(renderTime', pgrst) <- withTiming $ liftEither $ Response.infoIdentResponse identifier sCache
let metrics = Map.fromList [(SMRender, renderTime'), jwtTime]
let metrics = Map.fromList $ (SMRender, renderTime'):jwtAndParseTime
return $ pgrstResponse metrics pgrst

(ActionInfo, TargetProc identifier _) -> do
(planTime', cPlan) <- withTiming $ liftEither $ Plan.callReadPlan identifier conf sCache apiReq ApiRequest.InvHead
(renderTime', pgrst) <- withTiming $ liftEither $ Response.infoProcResponse (Plan.crProc cPlan)
let metrics = Map.fromList [(SMPlan, planTime'), (SMRender, renderTime'), jwtTime]
let metrics = Map.fromList $ [(SMPlan, planTime'), (SMRender, renderTime')] ++ jwtAndParseTime
return $ pgrstResponse metrics pgrst

(ActionInfo, TargetDefaultSpec _) -> do
(renderTime', pgrst) <- withTiming $ liftEither Response.infoRootResponse
let metrics = Map.fromList [(SMRender, renderTime'), jwtTime]
let metrics = Map.fromList $ (SMRender, renderTime'):jwtAndParseTime
return $ pgrstResponse metrics pgrst

_ ->
Expand All @@ -248,13 +253,16 @@ handleRequest AuthResult{..} conf appState authenticated prepared pgVer apiReq@A
pgrstResponse :: ServerTimingData -> Response.PgrstResponse -> Wai.Response
pgrstResponse timings (Response.PgrstResponse st hdrs bod) = Wai.responseLBS st (hdrs ++ ([renderServerTimingHeader timings | configServerTimingEnabled conf])) bod

withTiming f = if configServerTimingEnabled conf
then do
(t, r) <- timeItT f
pure (Just t, r)
else do
r <- f
pure (Nothing, r)
withTiming = calcTiming $ configServerTimingEnabled conf

calcTiming :: Bool -> Handler IO a -> Handler IO (Maybe Double, a)
calcTiming timingEnabled f = if timingEnabled
then do
(t, r) <- timeItT f
pure (Just t, r)
else do
r <- f
pure (Nothing, r)

traceHeaderMiddleware :: AppConfig -> Wai.Middleware
traceHeaderMiddleware AppConfig{configServerTraceHeader} app req respond =
Expand Down
2 changes: 2 additions & 0 deletions src/PostgREST/Response/Performance.hs
Original file line number Diff line number Diff line change
Expand Up @@ -12,6 +12,7 @@ import Protolude

data ServerMetric =
SMJwt
| SMParse
| SMRender
| SMPlan
| SMTransaction
Expand All @@ -32,3 +33,4 @@ renderTiming (metric, time) = maybe "" (\x -> BS.concat [renderMetric metric, BS
renderMetric SMTransaction = "transaction"
renderMetric SMRender = "render"
renderMetric SMJwt = "jwt"
renderMetric SMParse = "parse"
12 changes: 6 additions & 6 deletions test/spec/Feature/Query/ServerTimingSpec.hs
Original file line number Diff line number Diff line change
Expand Up @@ -22,7 +22,7 @@ spec =
`shouldRespondWith`
[json|[{"id":6,"name":"Oscorp","referee":3,"auditor":4,"manager_id":6}]|]
{ matchStatus = 200
, matchHeaders = matchContentTypeJson : map matchServerTimingHasTiming ["jwt", "plan", "transaction", "render"]
, matchHeaders = matchContentTypeJson : map matchServerTimingHasTiming ["jwt", "parse", "plan", "transaction", "render"]
}

it "works with post request" $
Expand All @@ -32,7 +32,7 @@ spec =
`shouldRespondWith`
[json|[{"id":7,"name":"John","referee":null,"auditor":null,"manager_id":6}]|]
{ matchStatus = 201
, matchHeaders = matchContentTypeJson : map matchServerTimingHasTiming ["jwt", "plan", "transaction", "render"]
, matchHeaders = matchContentTypeJson : map matchServerTimingHasTiming ["jwt", "parse", "plan", "transaction", "render"]
}

it "works with patch request" $
Expand All @@ -41,7 +41,7 @@ spec =
`shouldRespondWith`
""
{ matchStatus = 204
, matchHeaders = matchHeaderAbsent hContentType : map matchServerTimingHasTiming ["jwt", "plan", "transaction", "render"]
, matchHeaders = matchHeaderAbsent hContentType : map matchServerTimingHasTiming ["jwt", "parse", "plan", "transaction", "render"]
}

it "works with put request" $
Expand All @@ -51,7 +51,7 @@ spec =
`shouldRespondWith`
[json| [ { "name": "Python", "rank": 19 } ]|]
{ matchStatus = 200
, matchHeaders = map matchServerTimingHasTiming ["jwt", "plan", "transaction", "render"]
, matchHeaders = map matchServerTimingHasTiming ["jwt", "parse", "plan", "transaction", "render"]
}

it "works with delete request" $
Expand All @@ -61,7 +61,7 @@ spec =
`shouldRespondWith`
""
{ matchStatus = 204
, matchHeaders = matchHeaderAbsent hContentType : map matchServerTimingHasTiming ["jwt", "plan", "transaction", "render"]
, matchHeaders = matchHeaderAbsent hContentType : map matchServerTimingHasTiming ["jwt", "parse", "plan", "transaction", "render"]
}

it "works with rpc call" $
Expand All @@ -71,5 +71,5 @@ spec =
`shouldRespondWith`
[json|{"x": 1, "y": 2}|]
{ matchStatus = 200
, matchHeaders = map matchServerTimingHasTiming ["jwt", "plan", "transaction", "render"]
, matchHeaders = map matchServerTimingHasTiming ["jwt", "parse", "plan", "transaction", "render"]
}

0 comments on commit b538ab9

Please sign in to comment.