Add otel pg tracing

CHANGELOG.md

@@ -15,6 +15,9 @@ All notable changes to this project will be documented in this file. From versio
 - Add `Vary` header to responses by @develop7 in #4609
 - Add config `db-timezone-enabled` for optional querying of timezones by @taimoorzaeem in #4751
 
+- Introduced producing OpenTelemetry traces by @develop7 in #3140
+  + Requires a new `server-otel-enabled` config parameter to be enabled first.
+
 ### Changed
 
 - All responses now include a `Vary` header by @develop7 in #4609

default.nix

@@ -150,6 +150,7 @@ rec {
       ghc = pkgs.haskell.compiler."${compiler}";
       inherit (pkgs.haskell.packages."${compiler}") hpc-codecov;
       inherit (pkgs.haskell.packages."${compiler}") weeder;
+      otelcol = pkgs.opentelemetry-collector;
     };
 } // pkgs.lib.optionalAttrs pkgs.stdenv.isLinux rec {
   # Static executable.

docs/integrations/opentelemetry.rst

@@ -0,0 +1,66 @@
+.. _opentelemetry:
+
+OpenTelemetry
+-------------
+
+PostgREST is able to act as OpenTelemetry traces producer. OpenTelemetry is configured
+using ``OTEL_*`` environment variables, per the `OpenTelemetry specification`_.
+
+The OpenTelemetry support is currently both experimental and in early stages of development, so expect some rough edges
+or lack of functionality, such as metrics or logs. Since current OpenTelemetry implementation incurs a small
+(~6% in our "Loadtest (mixed)" suite) performance hit, it is gated behind the :ref:`server-otel-enabled`
+configuration option, disabled by default.
+
+Example configuration:
+
+.. code-block:: shell
+
+    OTEL_EXPORTER_OTLP_ENDPOINT='https://api.honeycomb.io/' \
+    OTEL_EXPORTER_OTLP_HEADERS="x-honeycomb-team=<honeycomb_api_key>"  \
+    OTEL_SERVICE_NAME='PostgREST'\
+    OTEL_LOG_LEVEL='debug'\
+    OTEL_TRACES_SAMPLER='always_on' \
+    postgrest
+
+Prometheus metrics through the OpenTelemetry Collector
+~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
+
+PostgREST currently exports traces through OpenTelemetry, but not metrics. But,
+it's possible to scrape the :ref:`metrics` endpoint exposed by the
+:ref:`admin_server` and relay it through the OpenTelemetry Collector.
+
+Example collector configuration:
+
+.. code-block:: yaml
+
+    receivers:
+      prometheus:
+        config:
+          scrape_configs:
+            - job_name: postgrest
+              scrape_interval: 15s
+              metrics_path: /metrics
+              static_configs:
+                - targets: ["127.0.0.1:3001"]
+
+    processors:
+      batch:
+
+    exporters:
+      otlp:
+        endpoint: otel-collector:4317
+        tls:
+          insecure: true
+
+    service:
+      pipelines:
+        metrics:
+          receivers: [prometheus]
+          processors: [batch]
+          exporters: [otlp]
+
+This assumes the PostgREST :ref:`admin_server` is listening on port ``3001`` and that
+its ``/metrics`` endpoint is reachable by the collector. Adjust the target address and
+OTLP exporter settings for your deployment.
+
+.. _`OpenTelemetry specification`: https://opentelemetry.io/docs/specs/otel/configuration/sdk-environment-variables/

docs/postgrest.dict

@@ -57,6 +57,7 @@ HMAC
 htmx
 Htmx
 Homebrew
+hs
 hstore
 HTTP
 HTTPS
@@ -84,6 +85,7 @@ localhost
 login
 lookups
 Logins
+Loadtest
 LIBPQ
 logins
 lon
@@ -107,6 +109,10 @@ Observability
 Okta
 OpenAPI
 openapi
+OpenTelemetry
+opentelemetry
+otel
+OTLP
 ov
 parametrized
 passphrase

docs/references/configuration.rst

@@ -930,6 +930,21 @@ server-timing-enabled
   Enables the `Server-Timing <https://developer.mozilla.org/en-US/docs/Web/HTTP/Reference/Headers/Server-Timing>`_ header.
   See :ref:`server-timing_header`.
 
+.. _server-otel-enabled:
+
+server-otel-enabled
+-------------------
+
+  =============== =================================
+  **Type**        Boolean
+  **Default**     False
+  **Reloadable**  N
+  **Environment** PGRST_SERVER_OTEL_ENABLED
+  **In-Database** `n/a`
+  =============== =================================
+
+  When this is set to :code:`true`, OpenTelemetry tracing is enabled. See :ref:`opentelemetry` for details and settings.
+
 .. _server-unix-socket:
 
 server-unix-socket

nix/tools/tests.nix

@@ -10,6 +10,7 @@
 , hostPlatform
 , jq
 , lib
+, otelcol
 , postgrest
 , python3
 , runtimeShell
@@ -40,6 +41,7 @@ let
         args = [ "ARG_LEFTOVERS([hspec arguments])" ];
         workingDir = "/";
         withEnv = postgrest.env;
+        withPath = [ otelcol ];
       }
       ''
         ${withTools.withPg} -f test/observability/fixtures/load.sql \

postgrest.cabal

@@ -79,6 +79,7 @@ library
                       PostgREST.Query.QueryBuilder
                       PostgREST.Query.SqlFragment
                       PostgREST.Query.Statements
+                      PostgREST.OpenTelemetry
                       PostgREST.Plan
                       PostgREST.Plan.CallPlan
                       PostgREST.Plan.MutatePlan
@@ -112,6 +113,7 @@ library
                     , cookie                    >= 0.4.2 && < 0.6
                     , directory                 >= 1.2.6 && < 1.4
                     , either                    >= 4.4.1 && < 5.1
+                    , exceptions                >= 0.10 && < 0.12
                     , extra                     >= 1.7.0 && < 2.0
                     , fuzzyset                  >= 0.2.4 && < 0.3
                     , hasql                     >= 1.6.1.1 && < 1.7
@@ -121,6 +123,13 @@ library
                     , hasql-transaction         >= 1.0.1 && < 1.2
                     , http-client               >= 0.7.19 && < 0.8
                     , http-types                >= 0.12.2 && < 0.13
+                    , hs-opentelemetry-sdk      >= 0.1.0.0 && < 0.2.0.0
+                    , hs-opentelemetry-instrumentation-wai
+                    , hs-opentelemetry-api
+                    -- ^ this is due to hs-otel-sdk is not reexporting getTracerTracerProvider
+                    -- needed to initialize OpenTelemetry.middleware
+                    , hs-opentelemetry-utils-exceptions
+                    , hs-opentelemetry-propagator-w3c
                     , insert-ordered-containers >= 0.2.2 && < 0.3
                     , jose-jwt                  >= 0.9.6 && < 0.11
                     , lens                      >= 4.14 && < 5.4
@@ -271,6 +280,8 @@ test-suite spec
                     , hasql-pool        >= 1.0.1 && < 1.1
                     , hasql-transaction >= 1.0.1 && < 1.2
                     , heredoc           >= 0.2 && < 0.3
+                    , hs-opentelemetry-sdk      >= 0.1.0.0 && < 0.2.0.0
+                    , hs-opentelemetry-instrumentation-hspec
                     , hspec             >= 2.3 && < 2.12
                     , hspec-expectations >= 0.8.4 && < 0.9
                     , hspec-wai         >= 0.10 && < 0.12
@@ -306,11 +317,17 @@ test-suite observability
   hs-source-dirs:     test/observability
   main-is:            Main.hs
   other-modules:      ObsHelper
+                      OTelHelper
                       Observation.JwtCache
                       Observation.MetricsSpec
+                      Observation.OpenTelemetry
   build-depends:      base              >= 4.9 && < 4.20
+                    , aeson             >= 2.0.3 && < 2.3
                     , base64-bytestring >= 1 && < 1.3
                     , bytestring        >= 0.10.8 && < 0.13
+                    , containers        >= 0.5.7 && < 0.7
+                    , directory         >= 1.2.6 && < 1.4
+                    , filepath          >= 1.4.1 && < 1.6
                     , hasql-pool        >= 1.0.1 && < 1.1
                     , hasql-transaction >= 1.0.1 && < 1.2
                     , hspec             >= 2.3 && < 2.12
@@ -319,10 +336,15 @@ test-suite observability
                     , hspec-wai-json    >= 0.10 && < 0.12
                     , http-types        >= 0.12.3 && < 0.13
                     , jose-jwt          >= 0.9.6 && < 0.11
+                    , network           >= 2.6 && < 3.3
                     , postgrest
                     , prometheus-client >= 1.1.1 && < 1.2.0
+                    , process           >= 1.4.2 && < 1.7
                     , protolude         >= 0.3.1 && < 0.4
                     , text              >= 1.2.2 && < 2.2
+                    , retry             >= 0.7.4 && < 0.10
+                    , streaming-commons
+                    , temporary         >= 1.3 && < 1.4
                     , wai               >= 3.2.1 && < 3.3
   ghc-options:        -threaded -O0 -Werror -Wall -fwarn-identities
                       -fno-spec-constr -optP-Wno-nonportable-include-path

src/PostgREST/App.hs

@@ -33,22 +33,23 @@ import qualified Data.Text.Encoding       as T
 import qualified Network.Wai              as Wai
 import qualified Network.Wai.Handler.Warp as Warp
 
-import qualified PostgREST.Admin      as Admin
-import qualified PostgREST.ApiRequest as ApiRequest
-import qualified PostgREST.AppState   as AppState
-import qualified PostgREST.Auth       as Auth
-import qualified PostgREST.Cors       as Cors
-import qualified PostgREST.Error      as Error
-import qualified PostgREST.Listener   as Listener
-import qualified PostgREST.Logger     as Logger
-import qualified PostgREST.MainTx     as MainTx
-import qualified PostgREST.Plan       as Plan
-import qualified PostgREST.Query      as Query
-import qualified PostgREST.Response   as Response
-import qualified PostgREST.Unix       as Unix (installSignalHandlers)
+import qualified PostgREST.Admin         as Admin
+import qualified PostgREST.ApiRequest    as ApiRequest
+import qualified PostgREST.AppState      as AppState
+import qualified PostgREST.Auth          as Auth
+import qualified PostgREST.Cors          as Cors
+import qualified PostgREST.Error         as Error
+import qualified PostgREST.Listener      as Listener
+import qualified PostgREST.Logger        as Logger
+import qualified PostgREST.MainTx        as MainTx
+import qualified PostgREST.OpenTelemetry as OTel
+import qualified PostgREST.Plan          as Plan
+import qualified PostgREST.Query         as Query
+import qualified PostgREST.Response      as Response
+import qualified PostgREST.Unix          as Unix (installSignalHandlers)
 
 import PostgREST.ApiRequest           (ApiRequest (..))
-import PostgREST.AppState             (AppState)
+import PostgREST.AppState             (AppState, getOTelTracer)
 import PostgREST.Auth.Types           (AuthResult (..))
 import PostgREST.Config               (AppConfig (..), LogLevel (..))
 import PostgREST.Error                (Error)
@@ -68,12 +69,13 @@ import qualified Data.Text                 as T
 import qualified Network.HTTP.Types        as HTTP
 import qualified Network.HTTP.Types.Header as HTTP (hVary)
 import qualified Network.Socket            as NS
+import           OpenTelemetry.Trace       (defaultSpanArguments)
 import           PostgREST.Unix            (createAndBindDomainSocket)
 import           Protolude                 hiding (Handler)
 
 type Handler = ExceptT Error
 
-run :: AppState -> IO ()
+run :: HasCallStack => AppState -> IO ()
 run appState = do
   conf@AppConfig{..} <- AppState.getConfig appState
 
@@ -119,15 +121,16 @@ serverSettings AppConfig{..} =
     & setServerName ("postgrest/" <> prettyVersion)
 
 -- | PostgREST application
-postgrest :: LogLevel -> AppState.AppState -> IO () -> Wai.Application
+postgrest :: HasCallStack => LogLevel -> AppState.AppState -> IO () -> Wai.Application
 postgrest logLevel appState connWorker =
+  OTel.middleware appState .
   traceHeaderMiddleware appState .
   Cors.middleware appState .
   Auth.middleware appState .
   Logger.middleware logLevel Auth.getRole $
     -- fromJust can be used, because the auth middleware will **always** add
     -- some AuthResult to the vault.
-    \req respond -> do
+    \req respond -> OTel.inSpanM (getOTelTracer appState) "request" defaultSpanArguments $ do
       appConf@AppConfig{..} <- AppState.getConfig appState -- the config must be read again because it can reload
       case fromJust $ Auth.getResult req of
         Left err -> respond $ Error.errorResponseFor configClientErrorVerbosity err
@@ -154,7 +157,8 @@ postgrest logLevel appState connWorker =
           respond resp
 
 postgrestResponse
-  :: AppState.AppState
+  :: HasCallStack
+  => AppState.AppState
   -> AppConfig
   -> Maybe SchemaCache
   -> AuthResult
@@ -177,14 +181,16 @@ postgrestResponse appState conf@AppConfig{..} maybeSchemaCache authResult@AuthRe
       timezones = dbTimezones sCache
       prefs = ApiRequest.userPreferences conf req timezones
 
-  (parseTime, apiReq@ApiRequest{..}) <- withTiming $ liftEither . mapLeft Error.ApiRequestErr $ ApiRequest.userApiRequest conf prefs req body
-  (planTime, plan)                   <- withTiming $ liftEither $ Plan.actionPlan iAction conf apiReq sCache
+  (parseTime, apiReq@ApiRequest{..}) <-  withOTel "parse" $ withTiming $ liftEither . mapLeft Error.ApiRequestErr $ ApiRequest.userApiRequest conf prefs req body
+  (planTime, plan)                   <-  withOTel "plan" $ withTiming $ liftEither $ Plan.actionPlan iAction conf apiReq sCache
 
-  let mainQ = Query.mainQuery plan conf apiReq authResult configDbPreRequest
+  traceContext <- lift OTel.renderTraceContext
+
+  let mainQ = Query.mainQuery plan conf apiReq authResult configDbPreRequest traceContext
       tx = MainTx.mainTx mainQ conf authResult apiReq plan sCache
       obsQuery s = when configLogQuery $ observer $ QueryObs mainQ s
 
-  (txTime, txResult) <- withTiming $ do
+  (txTime, txResult) <- withOTel "query" $ withTiming $ do
     case tx of
       MainTx.NoDbTx r -> pure r
       MainTx.DbTx{..} -> do
@@ -197,7 +203,7 @@ postgrestResponse appState conf@AppConfig{..} maybeSchemaCache authResult@AuthRe
         lift $ whenLeft eitherResp $ obsQuery . Error.status
         liftEither eitherResp
 
-  (respTime, resp) <- withTiming $ do
+  (respTime, resp) <- withOTel "response" $ withTiming $ do
     let response = Response.actionResponse txResult apiReq (T.decodeUtf8 prettyVersion, docsVersion) conf sCache
         status' = either Error.status Response.pgrstStatus response
 
@@ -208,7 +214,7 @@ postgrestResponse appState conf@AppConfig{..} maybeSchemaCache authResult@AuthRe
   return $ toWaiResponse (ServerTiming jwtTime parseTime planTime txTime respTime) resp
 
   where
-    toWaiResponse :: ServerTiming -> Response.PgrstResponse -> Wai.Response
+    toWaiResponse :: HasCallStack => ServerTiming -> Response.PgrstResponse -> Wai.Response
     toWaiResponse timing (Response.PgrstResponse st hdrs bod) =
       Wai.responseLBS st (hdrs ++ serverTimingHeaders timing ++ [varyHeader | not $ varyHeaderPresent hdrs]) bod
 
@@ -221,7 +227,7 @@ postgrestResponse appState conf@AppConfig{..} maybeSchemaCache authResult@AuthRe
     varyHeaderPresent :: [HTTP.Header] -> Bool
     varyHeaderPresent = any (\(h, _v) -> h == HTTP.hVary)
 
-    withTiming :: Handler IO a -> Handler IO (Maybe Double, a)
+    withTiming :: HasCallStack => Handler IO a -> Handler IO (Maybe Double, a)
     withTiming f = if configServerTimingEnabled
         then do
           (t, r) <- timeItT f
@@ -230,6 +236,10 @@ postgrestResponse appState conf@AppConfig{..} maybeSchemaCache authResult@AuthRe
           r <- f
           pure (Nothing, r)
 
+    withOTel :: HasCallStack => Text -> Handler IO a -> Handler IO a
+    withOTel label = do
+      OTel.inSpanM (getOTelTracer appState) label defaultSpanArguments
+
 traceHeaderMiddleware :: AppState -> Wai.Middleware
 traceHeaderMiddleware appState app req respond = do
   conf <- AppState.getConfig appState