diff --git a/pqi-conformance.cabal b/pqi-conformance.cabal --- a/pqi-conformance.cabal +++ b/pqi-conformance.cabal @@ -1,18 +1,12 @@ cabal-version: 3.0 name: pqi-conformance -version: 0.0.1.0 +version: 0.0.1.1 category: Database, PostgreSQL, Testing synopsis: Differential conformance tests for pqi adapters description: - A reusable @hspec@ toolkit that checks any @pqi@ 'Pqi.IsConnection' - adapter against the FFI reference adapter. It boots a throwaway PostgreSQL - container (via @testcontainers@), runs the same operation on the candidate and - the FFI connection, and asserts that the protocol-derived observations match. - - . + A reusable [@hspec@](https://hackage.haskell.org/package/hspec) toolkit that checks any [@pqi@](https://hackage.haskell.org/package/pqi) 'Pqi.IsConnection' adapter against the FFI reference adapter. It boots a throwaway PostgreSQL container (via [@testcontainers@](https://hackage.haskell.org/package/testcontainers)), runs the same operation on the candidate and the FFI connection, and asserts that the protocol-derived observations match. - Each adapter's own test suite reuses these spec builders, wiring itself in as - the candidate. + Each adapter's own test suite reuses these spec builders, wiring itself in as the candidate. homepage: https://github.com/nikita-volkov/pqi-conformance bug-reports: https://github.com/nikita-volkov/pqi-conformance/issues @@ -99,7 +93,8 @@ Pqi.Conformance.Observation Pqi.Conformance.Operation.BackendPID Pqi.Conformance.Operation.Cancel - Pqi.Conformance.Operation.CancelCleanup + Pqi.Conformance.Operation.Cancel.Cleanup + Pqi.Conformance.Operation.Cancel.Stale Pqi.Conformance.Operation.ClientEncoding Pqi.Conformance.Operation.CmdStatus Pqi.Conformance.Operation.CmdTuples @@ -208,6 +203,6 @@ directory >=1.3 && <1.4, hspec >=2.11 && <2.12, postgresql-libpq >=0.11 && <0.12, - pqi ^>=0, + pqi ^>=0.0, testcontainers-postgresql ^>=0.2, text >=1.2 && <3, diff --git a/src/library/Pqi/Conformance.hs b/src/library/Pqi/Conformance.hs --- a/src/library/Pqi/Conformance.hs +++ b/src/library/Pqi/Conformance.hs @@ -18,7 +18,6 @@ import Pqi.Conformance.Harness import qualified Pqi.Conformance.Operation.BackendPID as BackendPID import qualified Pqi.Conformance.Operation.Cancel as Cancel -import qualified Pqi.Conformance.Operation.CancelCleanup as CancelCleanup import qualified Pqi.Conformance.Operation.ClientEncoding as ClientEncoding import qualified Pqi.Conformance.Operation.CmdStatus as CmdStatus import qualified Pqi.Conformance.Operation.CmdTuples as CmdTuples @@ -187,7 +186,6 @@ -- Cancellation GetCancel.spec proxy Cancel.spec proxy - CancelCleanup.spec proxy -- Notifications and notices Notifies.spec proxy DisableNoticeReporting.spec proxy diff --git a/src/library/Pqi/Conformance/Operation/Cancel.hs b/src/library/Pqi/Conformance/Operation/Cancel.hs --- a/src/library/Pqi/Conformance/Operation/Cancel.hs +++ b/src/library/Pqi/Conformance/Operation/Cancel.hs @@ -11,6 +11,8 @@ import Pqi (IsCancel (..), IsConnection (..)) import Pqi.Conformance.Harness +import qualified Pqi.Conformance.Operation.Cancel.Cleanup as Cleanup +import qualified Pqi.Conformance.Operation.Cancel.Stale as Stale import Pqi.Conformance.Prelude import Pqi.Conformance.Scenario (drainResults, execScenario) import Test.Hspec @@ -44,3 +46,6 @@ usable <- execScenario "select 1" connection pure (sent, cancelled, results, usable) pure outcomes + + Cleanup.spec proxy + Stale.spec proxy diff --git a/src/library/Pqi/Conformance/Operation/Cancel/Cleanup.hs b/src/library/Pqi/Conformance/Operation/Cancel/Cleanup.hs new file mode 100644 --- /dev/null +++ b/src/library/Pqi/Conformance/Operation/Cancel/Cleanup.hs @@ -0,0 +1,84 @@ +-- | Regression coverage for the stale-cancel bug that corrupts a connection +-- after a pipelined query completes. +-- +-- Root cause: in pqi-native, 'Pqi.getResult' returns 'Nothing' (the pipeline +-- separator) __before__ reading the trailing 'ReadyForQuery' message, leaving +-- @asyncPending = True@. If 'Pqi.cancel' is called while @asyncPending@ is +-- still @True@ — as 'Hasql.Comms.Session.cleanUpAfterInterruption' does after +-- draining results — a cancel request is sent to the server even though the +-- query has already finished. The server receives the signal, sets +-- @QueryCancelPending@, and the __next__ command (e.g. @ABORT@) is cancelled +-- with SQLSTATE @57014@, leaving the connection unusable. +module Pqi.Conformance.Operation.Cancel.Cleanup + ( spec, + ) +where + +import Control.Exception (bracket) +import Pqi (ExecStatus (..), IsCancel (..), IsConnection (..), IsResult (..)) +import qualified Pqi as Lq +import Pqi.Conformance.Prelude +import Test.Hspec + +spec :: forall c. (IsConnection c) => Proxy c -> SpecWith ByteString +spec proxy = + describe "cancel cleanup" do + -- Reproduces the state that hasql's cleanUpAfterInterruption reaches after + -- a timeout fires mid-pipeline: + -- + -- 1. drainResults reads CommandComplete → separator, exits loop. + -- In pqi-native asyncPending is still True here (ReadyForQuery not + -- yet consumed); in libpq the ReadyForQuery has already been + -- processed internally. + -- 2. cancel is called. pqi-native sends a cancel because + -- asyncPending=True; the query has long since finished so this is + -- a stale cancel. + -- 3. drainResults reads the remaining ReadyForQuery. + -- 4. The connection re-enters serial mode. + -- 5. exec runs a follow-up command — it must NOT be cancelled by the + -- stale signal that arrived in step 2. + it "does not corrupt subsequent commands when cancel is called after pipeline results are drained" \conninfo -> + bracket (connectdb conninfo :: IO c) finish \connection -> do + -- Enter pipeline mode and dispatch a fast query. + _ <- enterPipelineMode connection + _ <- sendQueryParams connection "select 1" [] Lq.Text + _ <- pipelineSync connection + + -- Wait for the server to process the query so both messages + -- (CommandComplete + ReadyForQuery) are already in the socket by the + -- time we start reading. + threadDelay 10_000 -- 10 ms + + -- Drain the command result then the pipeline separator (Nothing). + -- After this loop exits, asyncPending=True in pqi-native because + -- ReadyForQuery has not been read yet. + let drainAll = do + mr <- getResult connection + case mr of + Nothing -> pure () + Just _ -> drainAll + drainAll + + -- Send cancel. Because asyncPending=True in pqi-native, a cancel + -- request is dispatched to the server despite the query being done. + handle <- getCancel connection + for_ handle cancel + + -- Give the stale cancel enough time to reach the server and set + -- QueryCancelPending before the next command arrives. + threadDelay 10_000 -- 10 ms + + -- Read the ReadyForQuery that was still pending. + drainAll + + -- Exit pipeline mode (sends an implicit Sync in the reference impl). + _ <- exitPipelineMode connection + + -- A follow-up command must succeed; 57014 here means the stale cancel + -- corrupted the connection. + mResult <- exec connection "select 1" + case mResult of + Nothing -> expectationFailure "exec returned no result after pipeline cleanup" + Just (result :: ResultOf c) -> do + status <- resultStatus result + status `shouldBe` TuplesOk diff --git a/src/library/Pqi/Conformance/Operation/Cancel/Stale.hs b/src/library/Pqi/Conformance/Operation/Cancel/Stale.hs new file mode 100644 --- /dev/null +++ b/src/library/Pqi/Conformance/Operation/Cancel/Stale.hs @@ -0,0 +1,113 @@ +-- | Deterministic regression coverage for the stale-cancel bug: a cancel +-- dispatched during pipeline clean-up must not corrupt the next command run on +-- the connection. +-- +-- Root cause: 'Pqi.cancel' opens a TCP connection to the postmaster, sends the +-- @CancelRequest@, and — in the buggy implementation — immediately closes its +-- end. The request can then sit unread in the postmaster's socket buffer while +-- the client races ahead and issues its next query. The postmaster eventually +-- reads the request and delivers @SIGINT@ to the backend, which by then is +-- executing the /next/ statement, cancelling it with SQLSTATE @57014@. +-- +-- The race is reliably opened by the pipeline clean-up sequence that +-- @hasql@ runs after a timeout fires mid-read: once the pipeline is aborted, +-- 'Pqi.getResult' returns synthetic results for the outstanding commands +-- __without blocking on the wire__ (see @getNextResult@ in +-- @Pqi.Native.Query@). That lets the client reach its follow-up query before +-- the postmaster has processed the cancel. +-- +-- The fix mirrors libpq's @PQcancel@: after sending the request, drain the +-- cancel socket until the server closes its end (which it only does after the +-- signal has been dispatched), so the cancel can no longer land on a later +-- command. +-- +-- A single run hits the race only intermittently (the postmaster usually +-- processes the cancel in time), so this spec replays the scenario many times. +-- On the buggy implementation at least one iteration reliably loses the race +-- and reports @57014@ on the victim query; the fixed implementation passes +-- every iteration. +module Pqi.Conformance.Operation.Cancel.Stale + ( spec, + ) +where + +import Control.Exception (bracket) +import Pqi (ExecStatus (..), FieldCode (..), IsCancel (..), IsConnection (..)) +import qualified Pqi as Lq +import Pqi.Conformance.Observation (ResultObservation (..)) +import Pqi.Conformance.Prelude +import Pqi.Conformance.Scenario (drainResults, execScenario, float8Oid) +import System.Timeout (timeout) +import Test.Hspec + +-- | How many times to replay the racy scenario. Each iteration that loses the +-- race on buggy code surfaces SQLSTATE @57014@ on the victim query; enough +-- iterations make at least one failure overwhelmingly likely (the underlying +-- per-run failure rate on buggy code is roughly 30%). +iterations :: Int +iterations = 30 + +spec :: forall c. (IsConnection c) => Proxy c -> SpecWith ByteString +spec proxy = + describe "stale cancel" do + it "does not corrupt the next command when a cancel is sent during pipeline clean-up" \conninfo -> do + outcomes <- for [1 .. iterations] \i -> do + outcome <- runScenario proxy conninfo + pure (i, outcome) + -- Every iteration's victim query must have succeeded. Any iteration that + -- did not means a stale cancel corrupted the connection (57014). + let corrupted = [(i, outcome) | (i, Just outcome) <- outcomes] + corrupted `shouldBe` [] + +-- | Run one stale-cancel scenario on a fresh connection. Returns 'Nothing' if +-- the victim query succeeded, or @Just (status, sqlstate)@ describing how it +-- failed (e.g. @(FatalError, Just "57014")@). +runScenario :: + forall c. + (IsConnection c) => + Proxy c -> + ByteString -> + IO (Maybe (ExecStatus, Maybe ByteString)) +runScenario _ conninfo = + bracket (connectdb conninfo :: IO c) finish \connection -> do + -- Build a pipeline with a fast query followed by a slow one, mirroring the + -- sequence hasql issues. Two prepared statements keep pendingParses in + -- play, matching the real-world reproduction. + _ <- enterPipelineMode connection + _ <- sendPrepare connection "s1" "select $1::int" Nothing + _ <- sendQueryPrepared connection "s1" [Just ("42", Lq.Text)] Lq.Text + _ <- sendPrepare connection "s2" "select pg_sleep($1)" (Just [float8Oid]) + _ <- sendQueryPrepared connection "s2" [Just ("0.1", Lq.Text)] Lq.Text + _ <- pipelineSync connection + + -- Interrupt the read mid-pipeline, exactly as hasql's timeout does: the + -- slow pg_sleep is still running when the read is abandoned. + _ <- timeout 50_000 (drainResults connection) + + -- cleanUpAfterInterruption: drain, cancel, drain. The cancel is sent while + -- the pipeline is mid-flight; on buggy code its SIGINT can arrive late. + _ <- drainResults connection + mHandle <- getCancel connection + _ <- for mHandle cancel + _ <- drainResults connection + + -- leavePipeline: the exact restore sequence hasql performs, including the + -- retry it falls back to. + statusBefore <- pipelineStatus connection + when (statusBefore == Lq.PipelineOn) do + _ <- pipelineSync connection + _ <- drainResults connection + _ <- sendFlushRequest connection + _ <- drainResults connection + ok <- exitPipelineMode connection + unless ok do + _ <- drainResults connection + void (exitPipelineMode connection) + + -- The victim. It must not be cancelled by the stale signal. + execScenario "select 99" connection >>= \case + Nothing -> pure (Just (FatalError, Just "no-result")) + Just observation -> + case observation.status of + TuplesOk -> pure Nothing + status -> pure (Just (status, fromMaybe Nothing (lookup DiagSqlstate observation.errorFields))) diff --git a/src/library/Pqi/Conformance/Operation/CancelCleanup.hs b/src/library/Pqi/Conformance/Operation/CancelCleanup.hs deleted file mode 100644 --- a/src/library/Pqi/Conformance/Operation/CancelCleanup.hs +++ /dev/null @@ -1,84 +0,0 @@ --- | Regression coverage for the stale-cancel bug that corrupts a connection --- after a pipelined query completes. --- --- Root cause: in pqi-native, 'Pqi.getResult' returns 'Nothing' (the pipeline --- separator) __before__ reading the trailing 'ReadyForQuery' message, leaving --- @asyncPending = True@. If 'Pqi.cancel' is called while @asyncPending@ is --- still @True@ — as 'Hasql.Comms.Session.cleanUpAfterInterruption' does after --- draining results — a cancel request is sent to the server even though the --- query has already finished. The server receives the signal, sets --- @QueryCancelPending@, and the __next__ command (e.g. @ABORT@) is cancelled --- with SQLSTATE @57014@, leaving the connection unusable. -module Pqi.Conformance.Operation.CancelCleanup - ( spec, - ) -where - -import Control.Exception (bracket) -import Pqi (ExecStatus (..), IsCancel (..), IsConnection (..), IsResult (..)) -import qualified Pqi as Lq -import Pqi.Conformance.Prelude -import Test.Hspec - -spec :: forall c. (IsConnection c) => Proxy c -> SpecWith ByteString -spec proxy = - describe "cancel cleanup" do - -- Reproduces the state that hasql's cleanUpAfterInterruption reaches after - -- a timeout fires mid-pipeline: - -- - -- 1. drainResults reads CommandComplete → separator, exits loop. - -- In pqi-native asyncPending is still True here (ReadyForQuery not - -- yet consumed); in libpq the ReadyForQuery has already been - -- processed internally. - -- 2. cancel is called. pqi-native sends a cancel because - -- asyncPending=True; the query has long since finished so this is - -- a stale cancel. - -- 3. drainResults reads the remaining ReadyForQuery. - -- 4. The connection re-enters serial mode. - -- 5. exec runs a follow-up command — it must NOT be cancelled by the - -- stale signal that arrived in step 2. - it "does not corrupt subsequent commands when cancel is called after pipeline results are drained" \conninfo -> - bracket (connectdb conninfo :: IO c) finish \connection -> do - -- Enter pipeline mode and dispatch a fast query. - _ <- enterPipelineMode connection - _ <- sendQueryParams connection "select 1" [] Lq.Text - _ <- pipelineSync connection - - -- Wait for the server to process the query so both messages - -- (CommandComplete + ReadyForQuery) are already in the socket by the - -- time we start reading. - threadDelay 10_000 -- 10 ms - - -- Drain the command result then the pipeline separator (Nothing). - -- After this loop exits, asyncPending=True in pqi-native because - -- ReadyForQuery has not been read yet. - let drainAll = do - mr <- getResult connection - case mr of - Nothing -> pure () - Just _ -> drainAll - drainAll - - -- Send cancel. Because asyncPending=True in pqi-native, a cancel - -- request is dispatched to the server despite the query being done. - handle <- getCancel connection - for_ handle cancel - - -- Give the stale cancel enough time to reach the server and set - -- QueryCancelPending before the next command arrives. - threadDelay 10_000 -- 10 ms - - -- Read the ReadyForQuery that was still pending. - drainAll - - -- Exit pipeline mode (sends an implicit Sync in the reference impl). - _ <- exitPipelineMode connection - - -- A follow-up command must succeed; 57014 here means the stale cancel - -- corrupted the connection. - mResult <- exec connection "select 1" - case mResult of - Nothing -> expectationFailure "exec returned no result after pipeline cleanup" - Just (result :: ResultOf c) -> do - status <- resultStatus result - status `shouldBe` TuplesOk