Skip to content

feat: produce OpenTelemetry traces with hs-opentelemetry #3140

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
develop7 wants to merge 1 commit into
base: main
Choose a base branch
from
+355 −66
Open

feat: produce OpenTelemetry traces with hs-opentelemetry #3140

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 2 additions & 0 deletions CHANGELOG.md
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -12,6 +12,8 @@ All notable changes to this project will be documented in this file. From versio
- Log host, port and pg version of listener database connection by @mkleczek in #4617 #4618
- Optimize requests with `Prefer: count=exact` that do not use ranges or `db-max-rows` by @laurenceisla in #3957
+ Removed unnecessary double count when building the `Content-Range`.
- Introduced producing OpenTelemetry traces by @develop7 in #3140
+ Requires a new `server-otel-enabled` config parameter to be enabled first.

### Fixed

Expand Down
26 changes: 26 additions & 0 deletions docs/integrations/opentelemetry.rst
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,26 @@
.. _opentelemetry:

OpenTelemetry
-------------

PostgREST is able to act as OpenTelemetry traces producer. OpenTelemetry is configured
using ``OTEL_*`` environment variables, per the `OpenTelemetry specification`_.

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

Since current OpenTelemetry implementation incurs a small (~6% in our "Loadtest (mixed)" suite)
Copy link
Member

@steve-chavez steve-chavez Feb 4, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Since OTel is only applied to the timing headers, maybe the loss in perf is not from OTel but from the timing headers? The measured loss matches the one reported in #3410 (comment)

performance hit, it is gated behind the :ref:`server-otel-enabled` configuration option, disabled by default.

.. _hs-opentelemetry: https://github.com/iand675/hs-opentelemetry/

.. _`OpenTelemetry specification`: https://opentelemetry.io/docs/specs/otel/configuration/sdk-environment-variables/

6 changes: 6 additions & 0 deletions docs/postgrest.dict
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -56,6 +56,7 @@ HMAC
htmx
Htmx
Homebrew
hs
hstore
HTTP
HTTPS
Expand Down Expand Up @@ -83,6 +84,7 @@ localhost
login
lookups
Logins
Loadtest
LIBPQ
logins
lon
Expand All @@ -106,6 +108,10 @@ Observability
Okta
OpenAPI
openapi
OpenTelemetry
opentelemetry
otel
OTLP
ov
parametrized
passphrase
Expand Down
15 changes: 15 additions & 0 deletions docs/references/configuration.rst
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -888,6 +888,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
Expand Down
2 changes: 2 additions & 0 deletions nix/tools/loadtest.nix
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -68,6 +68,8 @@ let
# TODO clean once PGRST_JWT_CACHE_MAX_ENTRIES merged and released
export PGRST_JWT_CACHE_MAX_LIFETIME="86400"

export OTEL_SDK_DISABLED="true"

mkdir -p "$(dirname "$_arg_output")"
abs_output="$(realpath "$_arg_output")"

Expand Down
10 changes: 10 additions & 0 deletions postgrest.cabal
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -78,6 +78,7 @@ library
PostgREST.Query.QueryBuilder
PostgREST.Query.SqlFragment
PostgREST.Query.Statements
PostgREST.OpenTelemetry
PostgREST.Plan
PostgREST.Plan.CallPlan
PostgREST.Plan.MutatePlan
Expand Down Expand Up @@ -111,6 +112,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
Expand All @@ -120,6 +122,12 @@ 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
, insert-ordered-containers >= 0.2.2 && < 0.3
, jose-jwt >= 0.9.6 && < 0.11
, lens >= 4.14 && < 5.4
Expand Down Expand Up @@ -269,6 +277,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
Expand Down
103 changes: 56 additions & 47 deletions src/PostgREST/App.hs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -27,22 +27,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)
Expand All @@ -57,11 +58,12 @@ 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 OpenTelemetry.Trace (defaultSpanArguments)
import Protolude hiding (Handler)

type Handler = ExceptT Error

run :: AppState -> IO ()
run :: HasCallStack => AppState -> IO ()
run appState = do
let observer = AppState.getObserver appState
conf@AppConfig{..} <- AppState.getConfig appState
Expand Down Expand Up @@ -89,41 +91,44 @@ 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 -> 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

let
eitherResponse :: IO (Either Error Wai.Response)
eitherResponse =
runExceptT $ postgrestResponse appState appConf maybeSchemaCache 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. However, when there's an empty schema cache
-- postgrest responds with the error `PGRST002`; this means that the schema
-- cache is still loading, so we don't launch the connWorker here because
-- it would duplicate the loading process, e.g. https://github.com/PostgREST/postgrest/issues/3704
-- TODO: this process may be unnecessary when the Listener is enabled. Revisit once https://github.com/PostgREST/postgrest/issues/1766 is done
when (isServiceUnavailable response && isJust maybeSchemaCache) connWorker
resp <- do
delay <- AppState.getNextDelay appState
return $ addRetryHint delay response
respond resp
\req respond -> OTel.inSpanM (getOTelTracer appState) "request" 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

let
eitherResponse :: IO (Either Error Wai.Response)
eitherResponse =
runExceptT $ postgrestResponse appState appConf maybeSchemaCache 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. However, when there's an empty schema cache
-- postgrest responds with the error `PGRST002`; this means that the schema
-- cache is still loading, so we don't launch the connWorker here because
-- it would duplicate the loading process, e.g. https://github.com/PostgREST/postgrest/issues/3704
-- TODO: this process may be unnecessary when the Listener is enabled. Revisit once https://github.com/PostgREST/postgrest/issues/1766 is done
when (isServiceUnavailable response && isJust maybeSchemaCache) connWorker
resp <- do
delay <- AppState.getNextDelay appState
return $ addRetryHint delay response
respond resp

postgrestResponse
:: AppState.AppState
:: HasCallStack
=> AppState.AppState
-> AppConfig
-> Maybe SchemaCache
-> AuthResult
Expand All @@ -146,14 +151,14 @@ postgrestResponse appState conf@AppConfig{..} maybeSchemaCache authResult@AuthRe
timezones = dbTimezones sCache
prefs = ApiRequest.userPreferences conf req timezones

(parseTime, apiReq@ApiRequest{..}) <- withTiming $ liftEither . mapLeft Error.ApiRequestError $ 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.ApiRequestError $ 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
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
Expand All @@ -166,7 +171,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 iSchema iNegotiatedByProfile
status' = either Error.status Response.pgrstStatus response

Expand All @@ -177,10 +182,10 @@ 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 ++ ([serverTimingHeader timing | configServerTimingEnabled])) bod

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
Expand All @@ -189,6 +194,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
Expand Down
20 changes: 15 additions & 5 deletions src/PostgREST/AppState.hs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -15,6 +15,7 @@ module PostgREST.AppState
, getJwtCacheState
, getSocketREST
, getSocketAdmin
, getOTelTracer
, init
, initSockets
, initWithPool
Expand Down Expand Up @@ -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 AppState = AppState
Expand Down Expand Up @@ -109,6 +111,10 @@ data AppState = AppState
, stateJwtCache :: JwtCache.JwtCacheState
, stateLogger :: Logger.LoggerState
, stateMetrics :: Metrics.MetricsState
-- | OpenTelemetry tracer. @Nothing@ represents disabled OTel SDK.
-- It's a workaround for now, as @hs-opentelemetry-api@ doesn't have @Tracer.tracerIsEnabled@ released yet.
-- Tracking issue: https://github.com/iand675/hs-opentelemetry/issues/212
, stateOTelTracer :: Maybe Tracer
}

-- | Schema cache status
Expand All @@ -119,8 +125,8 @@ data SchemaCacheStatus

type AppSockets = (NS.Socket, Maybe NS.Socket)

init :: AppConfig -> IO AppState
init conf@AppConfig{configLogLevel, configDbPoolSize} = do
init :: AppConfig -> Maybe Tracer -> IO AppState
init conf@AppConfig{configLogLevel, configDbPoolSize} tracer = do
loggerState <- Logger.init
metricsState <- Metrics.init configDbPoolSize
let observer = liftA2 (>>) (Logger.observationLogger loggerState configLogLevel) (Metrics.observationMetrics metricsState)
Expand All @@ -129,11 +135,11 @@ init conf@AppConfig{configLogLevel, configDbPoolSize} = do

pool <- initPool conf observer
(sock, adminSock) <- initSockets conf
state' <- initWithPool (sock, adminSock) pool conf loggerState metricsState observer
state' <- initWithPool (sock, adminSock) pool conf loggerState metricsState tracer observer
pure state' { stateSocketREST = sock, stateSocketAdmin = adminSock}

initWithPool :: AppSockets -> SQL.Pool -> AppConfig -> Logger.LoggerState -> Metrics.MetricsState -> ObservationHandler -> IO AppState
initWithPool (sock, adminSock) pool conf loggerState metricsState observer = do
initWithPool :: AppSockets -> SQL.Pool -> AppConfig -> Logger.LoggerState -> Metrics.MetricsState -> Maybe Tracer -> ObservationHandler -> IO AppState
initWithPool (sock, adminSock) pool conf loggerState metricsState tracer observer = do

appState <- AppState pool
<$> newIORef minimumPgVersion -- assume we're in a supported version when starting, this will be corrected on a later step
Expand All @@ -152,6 +158,7 @@ initWithPool (sock, adminSock) pool conf loggerState metricsState observer = do
<*> JwtCache.init conf observer
<*> pure loggerState
<*> pure metricsState
<*> pure tracer

deb <-
let decisecond = 100000 in
Expand Down Expand Up @@ -319,6 +326,9 @@ getSocketREST = stateSocketREST
getSocketAdmin :: AppState -> Maybe NS.Socket
getSocketAdmin = stateSocketAdmin

getOTelTracer :: AppState -> Maybe Tracer
getOTelTracer = stateOTelTracer

getMainThreadId :: AppState -> ThreadId
getMainThreadId = stateMainThreadId

Expand Down
Loading