shibuya-pgmq-adapter-0.19.0.0: test/Shibuya/Adapter/Pgmq/CorrelationSpec.hs
-- | Trace correlation of PGMQ processing spans against a real PostgreSQL.
--
-- Each case sends a message carrying a known producer @traceparent@, runs a
-- traced Shibuya app over the adapter with an in-memory span exporter, and
-- inspects the exported Consumer spans: their trace, their parent and their
-- links. The dead-letter cases also read the dead-letter queue message's
-- headers, which 'Shibuya.Adapter.Pgmq.Internal.mergeDlqHeaders' writes from
-- the active processing span.
--
-- Run with: cabal test shibuya-pgmq-adapter-test --test-option=--match --test-option=Correlation
module Shibuya.Adapter.Pgmq.CorrelationSpec (spec) where
import Control.Concurrent (threadDelay)
import Control.Exception qualified as Exception
import Control.Monad (void)
import Data.Aeson (Value (..), object, (.=))
import Data.Aeson.Key qualified as Key
import Data.Aeson.KeyMap qualified as KeyMap
import Data.Foldable (toList)
import Data.IORef (IORef, atomicModifyIORef', newIORef, readIORef)
import Data.Maybe (isNothing)
import Data.Text (Text)
import Data.Text.Encoding qualified as Text
import Data.Vector qualified as Vector
import Effectful (Eff, IOE, liftIO, runEff, (:>))
import Effectful.Error.Static (Error, runErrorNoCallStack)
import Hasql.Pool qualified as Pool
import OpenTelemetry.Attributes (emptyAttributes)
import OpenTelemetry.Exporter.InMemory (inMemoryListExporter)
import OpenTelemetry.Trace.Core qualified as OTel
import OpenTelemetry.Trace.Id (Base (..))
import OpenTelemetry.Trace.Id qualified as OTel.Id
import OpenTelemetry.Trace.Id.Generator (IdGenerator (..))
import OpenTelemetry.Util (appendOnlyBoundedCollectionValues)
import Pgmq.Effectful (Pgmq, PgmqRuntimeError, runPgmq)
import Pgmq.Hasql.Sessions qualified as Sessions
import Pgmq.Hasql.Statements.Types (ReadMessage (..), SendMessageWithHeaders (..))
import Pgmq.Types (Message (..), MessageBody (..), MessageHeaders (..))
import Shibuya.Adapter (Adapter (..))
import Shibuya.Adapter.Pgmq
( AdapterTelemetry (traceCorrelation),
PgmqAdapterConfig (..),
PollingConfig (..),
TraceCorrelation (..),
defaultAdapterTelemetry,
defaultConfig,
directDeadLetter,
mkPgmqAdapterEnv,
pgmqAdapter,
)
import Shibuya.App (ProcessorId (..), ShutdownConfig (..), defaultAppConfig, defaultShutdownConfig, mkProcessor, runApp, stopAppGracefully)
import Shibuya.Core.Ack (AckDecision (..), DeadLetterReason (..), RetryDelay (..))
import Shibuya.Core.Ingested (Message (..))
import Shibuya.Core.Types (Attempt (..), Envelope (..))
import Shibuya.Handler (Handler)
import Shibuya.Telemetry.Effect (Tracing, runTracing)
import Shibuya.Telemetry.Propagation (extractTraceContext)
import Shibuya.Telemetry.Semantic (processSpanName)
import System.Environment (lookupEnv)
import Test.Hspec
import TmpPostgres (TestFixture (..), runPgmqSession, withPgmqDb, withTestFixture)
spec :: Spec
spec = around withTempDbFixture $ describe "Correlation" $ do
it "ParentAndLink: process span is a child of the producer with one link" $ \fixture -> do
run <- runCorrelated fixture defaultAdapterTelemetry False (countingHandler AckOk) 1
run.adapterPolicy `shouldBe` ParentAndLink
[sp] <- pure run.spans
sp.name `shouldBe` processSpanName processorName
hexTrace sp.context `shouldBe` producerTraceHex
fmap hexSpan sp.parent `shouldBe` Just producerSpanHex
linkIds sp `shouldBe` [(producerTraceHex, producerSpanHex)]
it "LinkOnly: process span is a linked root" $ \fixture -> do
run <- runCorrelated fixture linkOnly False (countingHandler AckOk) 1
run.adapterPolicy `shouldBe` LinkOnly
[sp] <- pure run.spans
hexTrace sp.context `shouldNotBe` producerTraceHex
isNothing sp.parent `shouldBe` True
linkIds sp `shouldBe` [(producerTraceHex, producerSpanHex)]
it "ParentAndLink: every redelivery stays in the producer's trace" $ \fixture -> do
run <- runCorrelated fixture defaultAdapterTelemetry False retryOnceHandler 2
length run.spans `shouldBe` 2
map (hexTrace . (.context)) run.spans `shouldBe` [producerTraceHex, producerTraceHex]
map (fmap hexSpan . (.parent)) run.spans `shouldBe` [Just producerSpanHex, Just producerSpanHex]
map linkIds run.spans `shouldBe` replicate 2 [(producerTraceHex, producerSpanHex)]
it "LinkOnly: each redelivery is its own linked trace" $ \fixture -> do
run <- runCorrelated fixture linkOnly False retryOnceHandler 2
case run.spans of
[first, second] -> do
hexTrace first.context `shouldNotBe` hexTrace second.context
mapM_ (\sp -> hexTrace sp.context `shouldNotBe` producerTraceHex) [first, second]
mapM_ (\sp -> isNothing sp.parent `shouldBe` True) [first, second]
mapM_ (\sp -> linkIds sp `shouldBe` [(producerTraceHex, producerSpanHex)]) [first, second]
other -> expectationFailure ("expected two processing spans, got " <> show (length other))
it "LinkOnly: DLQ traceparent is the consumer's, upstream preserved" $ \fixture -> do
run <- runCorrelated fixture linkOnly True (countingHandler (AckDeadLetter (PoisonPill "correlation"))) 1
[sp] <- pure run.spans
isNothing sp.parent `shouldBe` True
linkIds sp `shouldBe` [(producerTraceHex, producerSpanHex)]
hdrs <- readDlqHeaders fixture
let stringHeader :: Text -> Maybe Text
stringHeader k = case KeyMap.lookup (Key.fromText k) hdrs of
Just (String v) -> Just v
_ -> Nothing
active = [(Text.encodeUtf8 k, Text.encodeUtf8 v) | k <- ["traceparent", "tracestate"], Just v <- [stringHeader k]]
case extractTraceContext active of
Nothing -> expectationFailure ("expected a decodable consumer traceparent in the DLQ, got " <> show hdrs)
Just ctx -> do
hexTrace ctx `shouldBe` hexTrace sp.context
hexSpan ctx `shouldBe` hexSpan sp.context
hexTrace ctx `shouldNotBe` producerTraceHex
hexSpan ctx `shouldNotBe` producerSpanHex
stringHeader "x-shibuya-upstream-traceparent" `shouldBe` Just producerParent
stringHeader "x-shibuya-upstream-tracestate" `shouldBe` Just producerState
--------------------------------------------------------------------------------
-- Fixtures
--------------------------------------------------------------------------------
producerParent :: Text
producerParent = "00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01"
producerState :: Text
producerState = "vendor=opaque"
producerTraceHex :: Text
producerTraceHex = "0af7651916cd43dd8448eb211c80319c"
producerSpanHex :: Text
producerSpanHex = "b7ad6b7169203331"
processorName :: Text
processorName = "pgmq-correlation"
linkOnly :: AdapterTelemetry
linkOnly = defaultAdapterTelemetry {traceCorrelation = LinkOnly}
data CorrelatedRun = CorrelatedRun
{ adapterPolicy :: TraceCorrelation,
spans :: [ConsumerSpan]
}
-- | Send one message with the producer headers, process it with the given
-- telemetry until the handler has been called @deliveries@ times, and return
-- the exported Consumer spans in the order they ended.
runCorrelated ::
TestFixture ->
AdapterTelemetry ->
Bool ->
(IORef Int -> Handler '[Tracing, Pgmq, Error PgmqRuntimeError, IOE] Value) ->
Int ->
IO CorrelatedRun
runCorrelated TestFixture {pool, queueName, dlqName} telemetry withDlq handler deliveries = do
runPgmqSession pool $
void $
Sessions.sendMessageWithHeaders $
SendMessageWithHeaders
{ queueName = queueName,
messageBody = MessageBody (String "correlated"),
messageHeaders = MessageHeaders (object ["traceparent" .= producerParent, "tracestate" .= producerState]),
delay = Just 0
}
let config =
(defaultConfig queueName)
{ visibilityTimeout = 5,
batchSize = 1,
polling = StandardPolling {pollInterval = 0.05},
deadLetterConfig = if withDlq then Just (directDeadLetter dlqName True) else Nothing,
telemetry = telemetry
}
calls <- newIORef (0 :: Int)
(spanProcessor, spansRef) <- inMemoryListExporter
policy <-
Exception.bracket
(OTel.createTracerProvider [spanProcessor] OTel.emptyTracerProviderOptions {OTel.tracerProviderOptionsIdGenerator = DefaultIdGenerator})
(\p -> OTel.shutdownTracerProvider p (Just 5_000_000))
$ \provider -> do
let tracer = OTel.makeTracer provider (OTel.InstrumentationLibrary "pgmq-correlation" "" "" emptyAttributes) OTel.tracerOptions
runAdapterIO pool $ runTracing tracer $ do
adapter <- requireAdapter pool config
result <- runApp defaultAppConfig [(ProcessorId processorName, mkProcessor adapter (handler calls))]
case result of
Left err -> liftIO (expectationFailure (show err))
Right appHandle -> do
liftIO $ waitForCalls calls deliveries 5_000_000
drained <- stopAppGracefully defaultShutdownConfig {drainTimeout = 5} appHandle
liftIO $ drained `shouldBe` True
pure adapter.telemetry.traceCorrelation
readIORef calls `shouldReturn` deliveries
exported <- readIORef spansRef
consumers <- consumerSpans exported
pure CorrelatedRun {adapterPolicy = policy, spans = consumers}
countingHandler :: (IOE :> es) => AckDecision -> IORef Int -> Handler es Value
countingHandler decision calls _ = do
liftIO $ atomicModifyIORef' calls (\n -> (n + 1, ()))
pure decision
-- | Ask for an immediate redelivery on the first attempt, succeed afterwards.
retryOnceHandler :: (IOE :> es) => IORef Int -> Handler es Value
retryOnceHandler calls message = do
liftIO $ atomicModifyIORef' calls (\n -> (n + 1, ()))
pure $ case message.envelope.attempt of
Just (Attempt n) | n > 0 -> AckOk
_ -> AckRetry (RetryDelay 0)
readDlqHeaders :: TestFixture -> IO (KeyMap.KeyMap Value)
readDlqHeaders TestFixture {pool, dlqName} = do
messages <- runPgmqSession pool $ Sessions.readMessage $ ReadMessage dlqName 30 (Just 10) Nothing
case Vector.toList messages of
[msg] -> case msg.headers of
Just (Object hdrs) -> pure hdrs
other -> expectationFailure ("expected DLQ headers, got " <> show other) >> pure KeyMap.empty
other -> expectationFailure ("expected one DLQ message, got " <> show (length other)) >> pure KeyMap.empty
waitForCalls :: IORef Int -> Int -> Int -> IO ()
waitForCalls ref target = go
where
go remaining
| remaining <= 0 = pure ()
| otherwise = do
n <- readIORef ref
if n >= target then pure () else threadDelay 20_000 >> go (remaining - 20_000)
withTempDbFixture :: (TestFixture -> IO ()) -> IO ()
withTempDbFixture action = do
skipDb <- lookupEnv "PGMQ_TEST_SKIP_DB"
case skipDb of
Just "1" -> pendingWith "Database tests skipped (PGMQ_TEST_SKIP_DB=1)"
_ -> do
result <- withPgmqDb $ \pool -> withTestFixture pool action
case result of
Left err -> expectationFailure $ "Failed to start temp database: " <> show err
Right () -> pure ()
runAdapterIO :: Pool.Pool -> Eff '[Pgmq, Error PgmqRuntimeError, IOE] a -> IO a
runAdapterIO pool action = do
result <- runEff $ runErrorNoCallStack $ runPgmq pool action
either (\err -> error ("Pgmq error: " <> show err)) pure result
requireAdapter ::
(Pgmq :> es, Error PgmqRuntimeError :> es, IOE :> es, Tracing :> es) =>
Pool.Pool ->
PgmqAdapterConfig ->
Eff es (Adapter es Value)
requireAdapter pool config =
pgmqAdapter (mkPgmqAdapterEnv pool) config
>>= either (\err -> liftIO (error ("Invalid PGMQ adapter config: " <> show err))) pure
--------------------------------------------------------------------------------
-- Span inspection
--------------------------------------------------------------------------------
data ConsumerSpan = ConsumerSpan
{ name :: Text,
context :: OTel.SpanContext,
parent :: Maybe OTel.SpanContext,
links :: [OTel.SpanContext]
}
consumerSpans :: [OTel.ImmutableSpan] -> IO [ConsumerSpan]
consumerSpans exported = traverse describeSpan [sp | sp <- exported, OTel.spanKind sp == OTel.Consumer]
where
describeSpan sp = do
hot <- readIORef (OTel.spanHot sp)
parent <- traverse OTel.getSpanContext (OTel.spanParent sp)
pure
ConsumerSpan
{ name = OTel.hotName hot,
context = OTel.spanContext sp,
parent,
links = map OTel.frozenLinkContext (toList (appendOnlyBoundedCollectionValues (OTel.hotLinks hot)))
}
linkIds :: ConsumerSpan -> [(Text, Text)]
linkIds sp = [(hexTrace l, hexSpan l) | l <- sp.links]
hexTrace :: OTel.SpanContext -> Text
hexTrace ctx = OTel.Id.traceIdBaseEncodedText Base16 ctx.traceId
hexSpan :: OTel.SpanContext -> Text
hexSpan ctx = OTel.Id.spanIdBaseEncodedText Base16 ctx.spanId