diff --git a/postgrest.cabal b/postgrest.cabal index 0b3715ae7f9..10db076e352 100644 --- a/postgrest.cabal +++ b/postgrest.cabal @@ -58,6 +58,7 @@ library PostgREST.Query.QueryBuilder PostgREST.Query.SqlFragment PostgREST.Query.Statements + PostgREST.OpenTelemetry PostgREST.Plan PostgREST.Plan.CallPlan PostgREST.Plan.MutatePlan @@ -103,6 +104,7 @@ library , heredoc >= 0.2 && < 0.3 , http-types >= 0.12.2 && < 0.13 , hs-opentelemetry-sdk >= 0.0.3.6 && < 0.0.4 + , hs-opentelemetry-instrumentation-wai , insert-ordered-containers >= 0.2.2 && < 0.3 , interpolatedstring-perl6 >= 1 && < 1.1 , jose >= 0.8.5.1 && < 0.12 diff --git a/src/PostgREST/App.hs b/src/PostgREST/App.hs index a7e560734f4..22f7b853b2a 100644 --- a/src/PostgREST/App.hs +++ b/src/PostgREST/App.hs @@ -45,7 +45,7 @@ import qualified PostgREST.Unix as Unix (installSignalHandlers) import PostgREST.ApiRequest (Action (..), ApiRequest (..), Mutation (..), Target (..)) -import PostgREST.AppState (AppState) +import PostgREST.AppState (AppState, getOTelTracer) import PostgREST.Auth (AuthResult (..)) import PostgREST.Config (AppConfig (..)) import PostgREST.Config.PgVersion (PgVersion (..)) @@ -57,13 +57,14 @@ import PostgREST.SchemaCache (SchemaCache (..)) import PostgREST.SchemaCache.Routine (Routine (..)) import PostgREST.Version (docsVersion, prettyVersion) -import qualified Data.ByteString.Char8 as BS -import qualified Data.List as L -import qualified Network.HTTP.Types as HTTP -import qualified Network.Socket as NS -import Protolude hiding (Handler) -import System.TimeIt (timeItT) -import OpenTelemetry.Trace (getGlobalTracerProvider, defaultSpanArguments, makeTracer, InstrumentationLibrary (..), TracerOptions (..), Tracer, SpanKind (..), SpanArguments(..), inSpan', addEvent, NewEvent (NewEvent, newEventAttributes, newEventTimestamp, newEventName), setStatus, SpanStatus(..), Span, ToAttribute (toAttribute)) +import qualified Data.ByteString.Char8 as BS +import qualified Data.List as L +import qualified Network.HTTP.Types as HTTP +import qualified Network.Socket as NS +import OpenTelemetry.Instrumentation.Wai (newOpenTelemetryWaiMiddleware) +import Protolude hiding (Handler) +import System.TimeIt (timeItT) +import OpenTelemetry.Trace (inSpan, defaultSpanArguments) type Handler = ExceptT Error @@ -88,7 +89,9 @@ run appState = do pure $ "port " <> show port AppState.logWithZTime appState $ "Listening on " <> what - Warp.runSettingsSocket (serverSettings conf) (AppState.getSocketREST appState) app + oTelMWare <- newOpenTelemetryWaiMiddleware + + Warp.runSettingsSocket (serverSettings conf) (AppState.getSocketREST appState) (oTelMWare app) serverSettings :: AppConfig -> Warp.Settings serverSettings AppConfig{..} = @@ -106,27 +109,28 @@ postgrest conf appState connWorker = Logger.middleware (configLogLevel conf) $ -- fromJust can be used, because the auth middleware will **always** add -- some AuthResult to the vault. - \req respond -> case fromJust $ Auth.getResult req of - Left err -> respond $ Error.errorResponseFor err - Right authResult -> do - appConf <- AppState.getConfig appState -- the config must be read again because it can reload - maybeSchemaCache <- AppState.getSchemaCache appState - pgVer <- AppState.getPgVersion appState - - let - eitherResponse :: IO (Either Error Wai.Response) - eitherResponse = - runExceptT $ postgrestResponse appState appConf maybeSchemaCache pgVer authResult req - - response <- either Error.errorResponseFor identity <$> eitherResponse - -- Launch the connWorker when the connection is down. The postgrest - -- function can respond successfully (with a stale schema cache) before - -- the connWorker is done. - when (isServiceUnavailable response) connWorker - resp <- do - delay <- AppState.getRetryNextIn appState - return $ addRetryHint delay response - respond resp + \req respond -> inSpan (getOTelTracer appState) "PostgREST.postgrest" defaultSpanArguments $ + case fromJust $ Auth.getResult req of + Left err -> respond $ Error.errorResponseFor err + Right authResult -> do + appConf <- AppState.getConfig appState -- the config must be read again because it can reload + maybeSchemaCache <- AppState.getSchemaCache appState + pgVer <- AppState.getPgVersion appState + + let + eitherResponse :: IO (Either Error Wai.Response) + eitherResponse = + runExceptT $ postgrestResponse appState appConf maybeSchemaCache pgVer authResult req + + response <- either Error.errorResponseFor identity <$> eitherResponse + -- Launch the connWorker when the connection is down. The postgrest + -- function can respond successfully (with a stale schema cache) before + -- the connWorker is done. + when (isServiceUnavailable response) connWorker + resp <- do + delay <- AppState.getRetryNextIn appState + return $ addRetryHint delay response + respond resp postgrestResponse :: AppState.AppState @@ -137,7 +141,6 @@ postgrestResponse -> Wai.Request -> Handler IO Wai.Response postgrestResponse appState conf@AppConfig{..} maybeSchemaCache pgVer authResult@AuthResult{..} req = do - t <- liftIO getTracer sCache <- case maybeSchemaCache of Just sCache -> @@ -148,20 +151,12 @@ postgrestResponse appState conf@AppConfig{..} maybeSchemaCache pgVer authResult@ body <- lift $ Wai.strictRequestBody req (parseTime, apiRequest) <- - calcTiming' configServerTimingEnabled $ + calcTiming configServerTimingEnabled $ liftEither . mapLeft Error.ApiRequestError $ ApiRequest.userApiRequest conf req body sCache let jwtTime = if configServerTimingEnabled then Auth.getJwtDur req else Nothing - liftIO $ inSpan' t "handleRequest" defaultSpanArguments {kind = Server} $ \span -> do - result <- runExceptT $ handleRequest span authResult conf appState (Just authRole /= configDbAnonRole) configDbPreparedStatements pgVer apiRequest sCache jwtTime parseTime - case result of - Left err -> do - setStatus span (Error "Boo!") - inSpan' t "errorResponseFor" defaultSpanArguments {kind = Server} $ \span' -> do - _ <- addEvent span' $ NewEvent { newEventName = "error", newEventAttributes = HM.fromList [], newEventTimestamp = Nothing } - return $ Error.errorResponseFor err - Right resp -> return resp + handleRequest authResult conf appState (Just authRole /= configDbAnonRole) configDbPreparedStatements pgVer apiRequest sCache jwtTime parseTime runDbHandler :: AppState.AppState -> AppConfig -> SQL.IsolationLevel -> SQL.Mode -> Bool -> Bool -> DbHandler b -> Handler IO b runDbHandler appState config isoLvl mode authenticated prepared handler = do @@ -175,62 +170,62 @@ runDbHandler appState config isoLvl mode authenticated prepared handler = do liftEither resp -handleRequest :: Span -> AuthResult -> AppConfig -> AppState.AppState -> Bool -> Bool -> PgVersion -> ApiRequest -> SchemaCache -> Maybe Double -> Maybe Double -> Handler IO Wai.Response -handleRequest span AuthResult{..} conf appState authenticated prepared pgVer apiReq@ApiRequest{..} sCache jwtTime parseTime = +handleRequest :: AuthResult -> AppConfig -> AppState.AppState -> Bool -> Bool -> PgVersion -> ApiRequest -> SchemaCache -> Maybe Double -> Maybe Double -> Handler IO Wai.Response +handleRequest AuthResult{..} conf appState authenticated prepared pgVer apiReq@ApiRequest{..} sCache jwtTime parseTime = case (iAction, iTarget) of (ActionRead headersOnly, TargetIdent identifier) -> do - (planTime', wrPlan) <- withTiming "queryTime" $ liftEither $ Plan.wrappedReadPlan identifier conf sCache apiReq - (txTime', resultSet) <- withTiming "planTime" $ runQuery roleIsoLvl Nothing (Plan.wrTxMode wrPlan) $ Query.readQuery wrPlan conf apiReq - (respTime', pgrst) <- withTiming "responseTime" $ liftEither $ Response.readResponse wrPlan headersOnly identifier apiReq resultSet + (planTime', wrPlan) <- withOTel "" $ withTiming $ liftEither $ Plan.wrappedReadPlan identifier conf sCache apiReq + (txTime', resultSet) <- withTiming $ runQuery roleIsoLvl Nothing (Plan.wrTxMode wrPlan) $ Query.readQuery wrPlan conf apiReq + (respTime', pgrst) <- withTiming $ liftEither $ Response.readResponse wrPlan headersOnly identifier apiReq resultSet return $ pgrstResponse (ServerTiming jwtTime parseTime planTime' txTime' respTime') pgrst (ActionMutate MutationCreate, TargetIdent identifier) -> do - (planTime', mrPlan) <- withTiming "queryTime" $ liftEither $ Plan.mutateReadPlan MutationCreate apiReq identifier conf sCache - (txTime', resultSet) <- withTiming "planTime" $ runQuery roleIsoLvl Nothing (Plan.mrTxMode mrPlan) $ Query.createQuery mrPlan apiReq conf - (respTime', pgrst) <- withTiming "responseTime" $ liftEither $ Response.createResponse identifier mrPlan apiReq resultSet + (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 + (respTime', pgrst) <- withTiming $ liftEither $ Response.createResponse identifier mrPlan apiReq resultSet return $ pgrstResponse (ServerTiming jwtTime parseTime planTime' txTime' respTime') pgrst (ActionMutate MutationUpdate, TargetIdent identifier) -> do - (planTime', mrPlan) <- withTiming "queryTime" $ liftEither $ Plan.mutateReadPlan MutationUpdate apiReq identifier conf sCache - (txTime', resultSet) <- withTiming "planTime" $ runQuery roleIsoLvl Nothing (Plan.mrTxMode mrPlan) $ Query.updateQuery mrPlan apiReq conf - (respTime', pgrst) <- withTiming "responseTime" $ liftEither $ Response.updateResponse mrPlan apiReq resultSet + (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 + (respTime', pgrst) <- withTiming $ liftEither $ Response.updateResponse mrPlan apiReq resultSet return $ pgrstResponse (ServerTiming jwtTime parseTime planTime' txTime' respTime') pgrst (ActionMutate MutationSingleUpsert, TargetIdent identifier) -> do - (planTime', mrPlan) <- withTiming "queryTime" $ liftEither $ Plan.mutateReadPlan MutationSingleUpsert apiReq identifier conf sCache - (txTime', resultSet) <- withTiming "planTime" $ runQuery roleIsoLvl Nothing (Plan.mrTxMode mrPlan) $ Query.singleUpsertQuery mrPlan apiReq conf - (respTime', pgrst) <- withTiming "responseTime" $ liftEither $ Response.singleUpsertResponse mrPlan apiReq resultSet + (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 + (respTime', pgrst) <- withTiming $ liftEither $ Response.singleUpsertResponse mrPlan apiReq resultSet return $ pgrstResponse (ServerTiming jwtTime parseTime planTime' txTime' respTime') pgrst (ActionMutate MutationDelete, TargetIdent identifier) -> do - (planTime', mrPlan) <- withTiming "queryTime" $ liftEither $ Plan.mutateReadPlan MutationDelete apiReq identifier conf sCache - (txTime', resultSet) <- withTiming "planTime" $ runQuery roleIsoLvl Nothing (Plan.mrTxMode mrPlan) $ Query.deleteQuery mrPlan apiReq conf - (respTime', pgrst) <- withTiming "responseTime" $ liftEither $ Response.deleteResponse mrPlan apiReq resultSet + (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 + (respTime', pgrst) <- withTiming $ liftEither $ Response.deleteResponse mrPlan apiReq resultSet return $ pgrstResponse (ServerTiming jwtTime parseTime planTime' txTime' respTime') pgrst (ActionInvoke invMethod, TargetProc identifier _) -> do - (planTime', cPlan) <- withTiming "queryTime" $ liftEither $ Plan.callReadPlan identifier conf sCache apiReq invMethod - (txTime', resultSet) <- withTiming "planTime" $ runQuery (fromMaybe roleIsoLvl $ pdIsoLvl (Plan.crProc cPlan)) (pdTimeout $ Plan.crProc cPlan) (Plan.crTxMode cPlan) $ Query.invokeQuery (Plan.crProc cPlan) cPlan apiReq conf pgVer - (respTime', pgrst) <- withTiming "responseTime" $ liftEither $ Response.invokeResponse cPlan invMethod (Plan.crProc cPlan) apiReq resultSet + (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 + (respTime', pgrst) <- withTiming $ liftEither $ Response.invokeResponse cPlan invMethod (Plan.crProc cPlan) apiReq resultSet return $ pgrstResponse (ServerTiming jwtTime parseTime planTime' txTime' respTime') pgrst (ActionInspect headersOnly, TargetDefaultSpec tSchema) -> do - (planTime', iPlan) <- withTiming "queryTime" $ liftEither $ Plan.inspectPlan apiReq - (txTime', oaiResult) <- withTiming "planTime" $ runQuery roleIsoLvl Nothing (Plan.ipTxmode iPlan) $ Query.openApiQuery sCache pgVer conf tSchema - (respTime', pgrst) <- withTiming "responseTime" $ liftEither $ Response.openApiResponse (T.decodeUtf8 prettyVersion, docsVersion) headersOnly oaiResult conf sCache iSchema iNegotiatedByProfile + (planTime', iPlan) <- withTiming $ liftEither $ Plan.inspectPlan apiReq + (txTime', oaiResult) <- withTiming $ runQuery roleIsoLvl Nothing (Plan.ipTxmode iPlan) $ Query.openApiQuery sCache pgVer conf tSchema + (respTime', pgrst) <- withTiming $ liftEither $ Response.openApiResponse (T.decodeUtf8 prettyVersion, docsVersion) headersOnly oaiResult conf sCache iSchema iNegotiatedByProfile return $ pgrstResponse (ServerTiming jwtTime parseTime planTime' txTime' respTime') pgrst (ActionInfo, TargetIdent identifier) -> do - (respTime', pgrst) <- withTiming "responseTime" $ liftEither $ Response.infoIdentResponse identifier sCache + (respTime', pgrst) <- withTiming $ liftEither $ Response.infoIdentResponse identifier sCache return $ pgrstResponse (ServerTiming jwtTime parseTime Nothing Nothing respTime') pgrst (ActionInfo, TargetProc identifier _) -> do - (planTime', cPlan) <- withTiming "planTime" $ liftEither $ Plan.callReadPlan identifier conf sCache apiReq ApiRequest.InvHead - (respTime', pgrst) <- withTiming "responseTime" $ liftEither $ Response.infoProcResponse (Plan.crProc cPlan) + (planTime', cPlan) <- withTiming $ liftEither $ Plan.callReadPlan identifier conf sCache apiReq ApiRequest.InvHead + (respTime', pgrst) <- withTiming $ liftEither $ Response.infoProcResponse (Plan.crProc cPlan) return $ pgrstResponse (ServerTiming jwtTime parseTime planTime' Nothing respTime') pgrst (ActionInfo, TargetDefaultSpec _) -> do - (respTime', pgrst) <- withTiming "responseTime" $ liftEither Response.infoRootResponse + (respTime', pgrst) <- withTiming $ liftEither Response.infoRootResponse return $ pgrstResponse (ServerTiming jwtTime parseTime Nothing Nothing respTime') pgrst _ -> @@ -249,20 +244,12 @@ handleRequest span AuthResult{..} conf appState authenticated prepared pgVer api pgrstResponse :: ServerTiming -> Response.PgrstResponse -> Wai.Response pgrstResponse timing (Response.PgrstResponse st hdrs bod) = Wai.responseLBS st (hdrs ++ ([serverTimingHeader timing | configServerTimingEnabled conf])) bod - withTiming label = calcTiming span label $ configServerTimingEnabled conf + withTiming = calcTiming $ configServerTimingEnabled conf -calcTiming :: Span -> Text -> Bool -> Handler IO a -> Handler IO (Maybe Double, a) -calcTiming span label timingEnabled f = do - (t, r) <- timeItT f - _ <- addEvent span $ NewEvent { newEventName = label, newEventAttributes = HM.fromList [("time", toAttribute t)], newEventTimestamp = Nothing } - if timingEnabled - then do - pure (Just t, r) - else do - pure (Nothing, r) + withOTel label = inSpan (getOTelTracer appState) label defaultSpanArguments -calcTiming' :: Bool -> Handler IO a -> Handler IO (Maybe Double, a) -calcTiming' timingEnabled f = if timingEnabled +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) @@ -285,11 +272,3 @@ addRetryHint delay response = do isServiceUnavailable :: Wai.Response -> Bool isServiceUnavailable response = Wai.responseStatus response == HTTP.status503 - -getTracer :: IO Tracer -getTracer = do - tp <- getGlobalTracerProvider - return $ - makeTracer tp - InstrumentationLibrary { libraryVersion = decodeUtf8 prettyVersion, libraryName = "postgrest"} - TracerOptions {tracerSchema=Nothing} diff --git a/src/PostgREST/AppState.hs b/src/PostgREST/AppState.hs index 71903d83993..7fabf6f7d76 100644 --- a/src/PostgREST/AppState.hs +++ b/src/PostgREST/AppState.hs @@ -16,6 +16,7 @@ module PostgREST.AppState , getJwtCache , getSocketREST , getSocketAdmin + , getOTelTracer , init , initSockets , initWithPool @@ -74,6 +75,7 @@ import PostgREST.Unix (createAndBindDomainSocket) import Data.Streaming.Network (bindPortTCP, bindRandomPortTCP) import Data.String (IsString (..)) +import OpenTelemetry.Trace (Tracer) import Protolude data AuthResult = AuthResult @@ -112,19 +114,21 @@ data AppState = AppState , stateSocketREST :: NS.Socket -- | Network socket for the admin UI , stateSocketAdmin :: Maybe NS.Socket + -- | OpenTelemetry tracer + , oTelTracer :: Tracer } type AppSockets = (NS.Socket, Maybe NS.Socket) -init :: AppConfig -> IO AppState -init conf = do +init :: AppConfig -> Tracer -> IO AppState +init conf tracer = do pool <- initPool conf (sock, adminSock) <- initSockets conf - state' <- initWithPool (sock, adminSock) pool conf - pure state' { stateSocketREST = sock, stateSocketAdmin = adminSock } + state' <- initWithPool (sock, adminSock) pool tracer conf + pure state' { stateSocketREST = sock, stateSocketAdmin = adminSock} -initWithPool :: AppSockets -> SQL.Pool -> AppConfig -> IO AppState -initWithPool (sock, adminSock) pool conf = do +initWithPool :: AppSockets -> SQL.Pool -> Tracer -> AppConfig -> IO AppState +initWithPool (sock, adminSock) pool tracer conf = do appState <- AppState pool <$> newIORef minimumPgVersion -- assume we're in a supported version when starting, this will be corrected on a later step <*> newIORef Nothing @@ -140,6 +144,7 @@ initWithPool (sock, adminSock) pool conf = do <*> C.newCache Nothing <*> pure sock <*> pure adminSock + <*> pure tracer debLogTimeout <- @@ -268,6 +273,9 @@ getSocketREST = stateSocketREST getSocketAdmin :: AppState -> Maybe NS.Socket getSocketAdmin = stateSocketAdmin +getOTelTracer :: AppState -> Tracer +getOTelTracer = oTelTracer + -- | Log to stderr with local time logWithZTime :: AppState -> Text -> IO () logWithZTime appState txt = do diff --git a/src/PostgREST/CLI.hs b/src/PostgREST/CLI.hs index 31749ca8c48..00b9aa60d4a 100644 --- a/src/PostgREST/CLI.hs +++ b/src/PostgREST/CLI.hs @@ -17,10 +17,11 @@ import qualified Options.Applicative as O import Data.Text.IO (hPutStrLn) import Text.Heredoc (str) -import PostgREST.AppState (AppState) -import PostgREST.Config (AppConfig (..)) -import PostgREST.SchemaCache (querySchemaCache) -import PostgREST.Version (prettyVersion) +import PostgREST.AppState (AppState) +import PostgREST.Config (AppConfig (..)) +import PostgREST.OpenTelemetry (withTracer) +import PostgREST.SchemaCache (querySchemaCache) +import PostgREST.Version (prettyVersion) import qualified PostgREST.App as App import qualified PostgREST.AppState as AppState @@ -28,10 +29,8 @@ import qualified PostgREST.Config as Config import Protolude hiding (hPutStrLn) -import OpenTelemetry.Trace - main :: CLI -> IO () -main CLI{cliCommand, cliPath} = withTracer $ \_tracer -> do +main CLI{cliCommand, cliPath} = withTracer "PostgREST" $ \tracer -> do conf@AppConfig{..} <- either panic identity <$> Config.readAppConfig mempty cliPath Nothing mempty mempty @@ -39,7 +38,7 @@ main CLI{cliCommand, cliPath} = withTracer $ \_tracer -> do -- explicitly close the connections to PostgreSQL on shutdown. -- 'AppState.destroy' takes care of that. bracket - (AppState.init conf) + (AppState.init conf tracer) AppState.destroy (\appState -> case cliCommand of CmdDumpConfig -> do @@ -47,12 +46,6 @@ main CLI{cliCommand, cliPath} = withTracer $ \_tracer -> do putStr . Config.toText =<< AppState.getConfig appState CmdDumpSchema -> putStrLn =<< dumpSchema appState CmdRun -> App.run appState) - where - withTracer :: ((TracerOptions -> Tracer) -> IO c) -> IO c - withTracer f = bracket - initializeGlobalTracerProvider - shutdownTracerProvider - (\tracerProvider -> f $ makeTracer tracerProvider "PostgREST") -- | Dump SchemaCache schema to JSON dumpSchema :: AppState -> IO LBS.ByteString diff --git a/src/PostgREST/OpenTelemetry.hs b/src/PostgREST/OpenTelemetry.hs new file mode 100644 index 00000000000..93cca589c57 --- /dev/null +++ b/src/PostgREST/OpenTelemetry.hs @@ -0,0 +1,128 @@ +{-# LANGUAGE ScopedTypeVariables, OverloadedLists #-} +module PostgREST.OpenTelemetry (withTracer) where + +import OpenTelemetry.Trace (InstrumentationLibrary (..), Tracer, + initializeGlobalTracerProvider, + makeTracer, shutdownTracerProvider, + tracerOptions, SpanArguments (..), Span, createSpanWithoutCallStack, setStatus, SpanStatus (..), recordException, endSpan) +import PostgREST.Version (prettyVersion) +import qualified Data.HashMap.Strict as H +import Protolude +import OpenTelemetry.Attributes (Attribute, ToAttribute (..)) +import qualified Data.Text as T +import Data.String (String) +import GHC.Stack +import OpenTelemetry.Context.ThreadLocal (getContext, adjustContext) +import OpenTelemetry.Context (insertSpan, lookupSpan, removeSpan) +import qualified Control.Exception as EUnsafe + + +withTracer :: Text -> (Tracer -> IO c) -> IO c +withTracer label f = bracket + initializeGlobalTracerProvider + shutdownTracerProvider + (\tracerProvider -> f $ makeTracer tracerProvider instrumentationLibrary tracerOptions) + where + instrumentationLibrary = InstrumentationLibrary {libraryName = label, libraryVersion = decodeUtf8 prettyVersion} + + +ownCodeAttributes :: (HasCallStack) => H.HashMap Text Attribute +ownCodeAttributes = case getCallStack callStack of + _ : caller : _ -> srcAttributes caller + _ -> mempty + + +callerAttributes :: (HasCallStack) => H.HashMap Text Attribute +callerAttributes = case getCallStack callStack of + _ : _ : caller : _ -> srcAttributes caller + _ -> mempty + + +srcAttributes :: (String, GHC.Stack.SrcLoc) -> H.HashMap Text Attribute +srcAttributes (fn, loc) = H.fromList + [ ("code.function", toAttribute $ T.pack fn) + , ("code.namespace", toAttribute $ T.pack $ srcLocModule loc) + , ("code.filepath", toAttribute $ T.pack $ srcLocFile loc) + , ("code.lineno", toAttribute $ srcLocStartLine loc) + , ("code.package", toAttribute $ T.pack $ srcLocPackage loc) + ] + +{- | The simplest function for annotating code with trace information. + + @since 0.0.1.0 +-} +inSpan + :: (MonadIO m, HasCallStack) + => Tracer + -> Text + -- ^ The name of the span. This may be updated later via 'updateName' + -> SpanArguments + -- ^ Additional options for creating the span, such as 'SpanKind', + -- span links, starting attributes, etc. + -> m a + -- ^ The action to perform. 'inSpan' will record the time spent on the + -- action without forcing strict evaluation of the result. Any uncaught + -- exceptions will be recorded and rethrown. + -> m a +inSpan t n args m = inSpan'' t n (args {attributes = H.union (attributes args) callerAttributes}) (const m) + + +inSpan' + :: (MonadIO m, HasCallStack) + => Tracer + -> Text + -- ^ The name of the span. This may be updated later via 'updateName' + -> SpanArguments + -> (Span -> m a) + -> m a +inSpan' t n args = inSpan'' t n (args {attributes = H.union (attributes args) callerAttributes}) + + +inSpan'' + :: (MonadIO m, HasCallStack) + => Tracer + -> Text + -- ^ The name of the span. This may be updated later via 'updateName' + -> SpanArguments + -> (Span -> m a) + -> m a +inSpan'' t n args f = do + bracketError + ( liftIO $ do + ctx <- getContext + s <- createSpanWithoutCallStack t ctx n args + adjustContext (insertSpan s) + pure (lookupSpan ctx, s) + ) + ( \e (parent, s) -> liftIO $ do + forM_ e $ \(SomeException inner) -> do + setStatus s $ Error $ T.pack $ displayException inner + recordException s [("exception.escaped", toAttribute True)] Nothing inner + endSpan s Nothing + adjustContext $ \ctx -> + maybe (removeSpan ctx) (`insertSpan` ctx) parent + ) + (\(_, s) -> f s) + +{- | Like 'Context.Exception.bracket', but provides the @after@ function with information about + uncaught exceptions. + + @since 0.1.0.0 +-} +bracketError :: (MonadIO m) => m a -> (Maybe SomeException -> a -> m b) -> (a -> m c) -> m c +bracketError before after thing = withRunInIO $ \run -> EUnsafe.mask $ \restore -> do + x <- run before + res1 <- EUnsafe.try $ restore $ run $ thing x + case res1 of + Left (e1 :: SomeException) -> do + -- explicitly ignore exceptions from after. We know that + -- no async exceptions were thrown there, so therefore + -- the stronger exception must come from thing + -- + -- https://github.com/fpco/safe-exceptions/issues/2 + _ :: Either SomeException b <- + EUnsafe.try $ EUnsafe.uninterruptibleMask_ $ run $ after (Just e1) x + EUnsafe.throwIO e1 + Right y -> do + _ <- EUnsafe.uninterruptibleMask_ $ run $ after Nothing x + return y diff --git a/stack.yaml b/stack.yaml index 7e53e590c48..0f80d14b6af 100644 --- a/stack.yaml +++ b/stack.yaml @@ -31,5 +31,6 @@ extra-deps: - 'propagators/b3' - 'propagators/w3c' - otlp + - 'instrumentation/wai' - thread-utils-context-0.3.0.4@sha256:e763da1c6cab3b6d378fb670ca74aa9bf03c9b61b6fcf7628c56363fb0e3e71e,1671 - thread-utils-finalizers-0.1.1.0@sha256:24944b71d9f1d01695a5908b4a3b44838fab870883114a323336d537995e0a5b,1381 diff --git a/stack.yaml.lock b/stack.yaml.lock index 8ae282d0574..3397285fc46 100644 --- a/stack.yaml.lock +++ b/stack.yaml.lock @@ -124,6 +124,19 @@ packages: original: subdir: otlp url: https://github.com/iand675/hs-opentelemetry/archive/54251bd15565e3a07cda0cecfa544d209ae63df6.tar.gz +- completed: + name: hs-opentelemetry-instrumentation-wai + pantry-tree: + sha256: 8caff8dcafdc6503610a30903f566be6f5125bd3fa38ae71c7fc1255e75f5db5 + size: 513 + sha256: eba9c66b5e90e4b4f4a90119053a75b68c0901454a992b463f17192600d034a9 + size: 357729 + subdir: instrumentation/wai + url: https://github.com/iand675/hs-opentelemetry/archive/54251bd15565e3a07cda0cecfa544d209ae63df6.tar.gz + version: 0.1.0.0 + original: + subdir: instrumentation/wai + url: https://github.com/iand675/hs-opentelemetry/archive/54251bd15565e3a07cda0cecfa544d209ae63df6.tar.gz - completed: hackage: thread-utils-context-0.3.0.4@sha256:e763da1c6cab3b6d378fb670ca74aa9bf03c9b61b6fcf7628c56363fb0e3e71e,1671 pantry-tree: diff --git a/test/spec/Main.hs b/test/spec/Main.hs index 4e5266e29fd..386af2027fb 100644 --- a/test/spec/Main.hs +++ b/test/spec/Main.hs @@ -10,6 +10,7 @@ import Test.Hspec import PostgREST.App (postgrest) import PostgREST.Config (AppConfig (..)) import PostgREST.Config.Database (queryPgVersion) +import PostgREST.OpenTelemetry (withTracer) import PostgREST.SchemaCache (querySchemaCache) import Protolude hiding (toList, toS) import SpecHelper @@ -78,16 +79,16 @@ main = do let -- For tests that run with the same refSchemaCache - app config = do - appState <- AppState.initWithPool sockets pool config + app config = withTracer "PostgREST.Spec" $ \tracer -> do + appState <- AppState.initWithPool sockets pool tracer config AppState.putPgVersion appState actualPgVersion AppState.putSchemaCache appState (Just baseSchemaCache) return ((), postgrest config appState $ pure ()) -- For tests that run with a different SchemaCache(depends on configSchemas) - appDbs config = do + appDbs config = withTracer "PostgREST.Spec" $ \tracer -> do customSchemaCache <- loadSchemaCache pool config - appState <- AppState.initWithPool sockets pool config + appState <- AppState.initWithPool sockets pool tracer config AppState.putPgVersion appState actualPgVersion AppState.putSchemaCache appState (Just customSchemaCache) return ((), postgrest config appState $ pure ())