Fix non-deterministic stdout and stderr interleaving

docs/src/content/docs/cli/test-compare.mdx

@@ -21,9 +21,11 @@ Runs tests and compares their output against saved expected results, reporting a
 
 For each test:
 
-1. Runs the test and captures output
-2. Compares output to the `expected` file in the test directory
-3. Reports differences (if any)
+1. Runs the test, capturing stdout and stderr separately
+2. Compares stdout to the `expected` file and stderr to the `expected_stderr` file in the test directory
+3. Reports differences (if any), labeled by stream
+
+A test fails if either stream differs from its expected file. Comparing the streams separately avoids flaky diffs from stdout/stderr interleaving, since the operating system does not guarantee their relative ordering when captured independently.
 
 Use [`spawn test expect`](/cli/test-expect/) to update the expected output.
 

docs/src/content/docs/cli/test-expect.mdx

@@ -20,8 +20,8 @@ Runs a test and saves its output as the new expected result for future compariso
 ## Behavior
 
 1. Runs the specified test
-2. Captures the output
-3. Writes it to `tests/<name>/expected.txt`
+2. Captures stdout and stderr separately
+3. Writes them to `tests/<name>/expected` and `tests/<name>/expected_stderr` respectively
 
 Use this command when test behavior changes intentionally and you want to update the baseline for [`spawn test compare`](/cli/test-compare/).
 

docs/src/content/docs/cli/test-run.mdx

@@ -19,7 +19,7 @@ Executes one or all tests against the configured database and displays the resul
 
 ## Behavior
 
-Runs the SQL for the test against the database, showing the output from that test.
+Runs the SQL for the test against the database, showing the output from that test. Stdout is printed first; if the test produced any stderr output (e.g. `NOTICE`/`ERROR` messages from psql), it is shown afterward under a `--- stderr ---` separator.
 
 ## Examples
 

src/commands/test/compare.rs

@@ -46,15 +46,21 @@ impl Command for CompareTests {
             let tester = Tester::new(config, &test_file);
 
             match tester.run_compare(None).await {
-                Ok(result) => match result.diff {
-                    None => {
+                Ok(result) => match (&result.stdout_diff, &result.stderr_diff) {
+                    (None, None) => {
                         println!("{}[PASS]{} {}", GREEN, RESET, test_file);
                     }
-                    Some(diff) => {
+                    (stdout_diff, stderr_diff) => {
                         failed = true;
                         println!("\n{}[FAIL]{} {}{}{}", RED, RESET, BOLD, test_file, RESET);
-                        println!("{}--- Diff ---{}", BOLD, RESET);
-                        println!("{}", diff);
+                        if let Some(diff) = stdout_diff {
+                            println!("{}--- stdout diff ---{}", BOLD, RESET);
+                            println!("{}", diff);
+                        }
+                        if let Some(diff) = stderr_diff {
+                            println!("{}--- stderr diff ---{}", BOLD, RESET);
+                            println!("{}", diff);
+                        }
                         println!("{}-------------{}\n", BOLD, RESET);
                     }
                 },

src/commands/test/run.rs

@@ -37,7 +37,11 @@ impl Command for RunTest {
         for test_name in test_names {
             let tester = Tester::new(config, &test_name);
             let result = tester.run(None).await?;
-            println!("{}", result);
+            println!("{}", result.stdout);
+            if !result.stderr.is_empty() {
+                println!("--- stderr ---");
+                println!("{}", result.stderr);
+            }
         }
 
         Ok(Outcome::Success)

src/engine/mod.rs

@@ -313,16 +313,15 @@ pub trait Engine: Send + Sync {
     /// Execute SQL by running the provided writer function.
     /// - `write_fn`: Closure that writes SQL to the provided Write handle
     /// - `stdout_writer`: Optional writer to capture stdout. If None, stdout is discarded.
-    /// - `merge_stderr`: If true and stdout_writer is Some, stderr is merged into stdout
-    ///                   at the OS level for true interleaving. Useful for tests.
-    ///                   Note: when merged, stderr is not separately available in errors.
+    /// - `stderr_writer`: Optional writer to capture stderr. If None, stderr is only
+    ///                    captured internally for the `ExecutionFailed` error case.
     /// Engine-specific setup (like psql flags) is handled internally.
     /// Returns stderr content on failure.
     async fn execute_with_writer(
         &self,
         write_fn: WriterFn,
         stdout_writer: StdoutWriter,
-        merge_stderr: bool,
+        stderr_writer: StdoutWriter,
     ) -> Result<(), EngineError>;
 
     async fn migration_apply(

src/engine/postgres_psql.rs

@@ -172,88 +172,48 @@ impl Engine for PSQL {
         &self,
         write_fn: WriterFn,
         stdout_writer: StdoutWriter,
-        merge_stderr: bool,
+        stderr_writer: StdoutWriter,
     ) -> Result<(), EngineError> {
         // 1. Create the pipe for stdin
         let (reader, mut writer) = std::io::pipe()?;
 
         // 2. Configure stdout/stderr and spawn psql
-        //
-        // When merge_stderr is true, we create our own pipe and give the
-        // write end to both stdout and stderr so the OS interleaves them.
-        // Otherwise, stdout is piped (or null) and stderr is piped separately.
-        let merge = merge_stderr && stdout_writer.is_some();
-
-        let (mut child, combined_read) = if merge {
-            let (out_read, out_write) = std::io::pipe()?;
-            let out_write_dup = out_write.try_clone()?;
-            let child = Command::new(&self.psql_command[0])
-                .args(&self.psql_command[1..])
-                .stdin(Stdio::from(reader))
-                .stdout(Stdio::from(out_write))
-                .stderr(Stdio::from(out_write_dup))
-                .spawn()
-                .map_err(EngineError::Io)?;
-            (child, Some(out_read))
+        let stdout_config = if stdout_writer.is_some() {
+            Stdio::piped()
         } else {
-            let stdout_config = if stdout_writer.is_some() {
-                Stdio::piped()
-            } else {
-                Stdio::null()
-            };
-            let child = Command::new(&self.psql_command[0])
-                .args(&self.psql_command[1..])
-                .stdin(Stdio::from(reader))
-                .stdout(stdout_config)
-                .stderr(Stdio::piped())
-                .spawn()
-                .map_err(EngineError::Io)?;
-            (child, None)
+            Stdio::null()
         };
+        let mut child = Command::new(&self.psql_command[0])
+            .args(&self.psql_command[1..])
+            .stdin(Stdio::from(reader))
+            .stdout(stdout_config)
+            .stderr(Stdio::piped())
+            .spawn()
+            .map_err(EngineError::Io)?;
 
         // 3. Copy output to stdout_writer if provided
         let stdout_handle = if let Some(mut stdout_dest) = stdout_writer {
-            if let Some(mut combined_read) = combined_read {
-                // Merged mode: read from our combined pipe in a blocking
-                // thread (it's a std::io::PipeReader, not a tokio type),
-                // then write to the async destination.
-                Some(tokio::task::spawn(async move {
-                    let buf = tokio::task::spawn_blocking(move || {
-                        use std::io::Read;
-                        let mut buf = Vec::new();
-                        let _ = combined_read.read_to_end(&mut buf);
-                        buf
-                    })
-                    .await
-                    .unwrap_or_default();
-                    use tokio::io::AsyncWriteExt;
-                    let _ = stdout_dest.write_all(&buf).await;
-                }))
-            } else {
-                let mut stdout = child.stdout.take().expect("stdout should be piped");
-                Some(tokio::task::spawn(async move {
-                    use tokio::io::AsyncWriteExt;
-                    let mut buf = Vec::new();
-                    let _ = stdout.read_to_end(&mut buf).await;
-                    let _ = stdout_dest.write_all(&buf).await;
-                }))
-            }
-        } else {
-            None
-        };
-
-        // 4. Drain stderr in background (prevents deadlock).
-        //    When merged, child.stderr is None (it shares the stdout pipe).
-        let stderr_handle = if let Some(mut stderr) = child.stderr.take() {
-            Some(tokio::spawn(async move {
+            let mut stdout = child.stdout.take().expect("stdout should be piped");
+            Some(tokio::task::spawn(async move {
+                use tokio::io::AsyncWriteExt;
                 let mut buf = Vec::new();
-                let _ = stderr.read_to_end(&mut buf).await;
-                buf
+                let _ = stdout.read_to_end(&mut buf).await;
+                let _ = stdout_dest.write_all(&buf).await;
             }))
         } else {
             None
         };
 
+        // 4. Drain stderr in background (prevents deadlock). It's always
+        //    captured to a buffer so it's available for the ExecutionFailed
+        //    error case, and additionally forwarded to stderr_writer below.
+        let mut stderr = child.stderr.take().expect("stderr should be piped");
+        let stderr_handle = tokio::spawn(async move {
+            let mut buf = Vec::new();
+            let _ = stderr.read_to_end(&mut buf).await;
+            buf
+        });
+
         // 5. Run the writer function in a blocking thread
         let writer_handle = tokio::task::spawn_blocking(move || -> std::io::Result<()> {
             // PSQL-specific setup - QUIET must be first to suppress output from other settings
@@ -280,10 +240,12 @@ impl Engine for PSQL {
 
         // 8. Wait for psql and check result
         let status = child.wait().await?;
-        let stderr_bytes = match stderr_handle {
-            Some(handle) => handle.await.unwrap_or_default(),
-            None => Vec::new(),
-        };
+        let stderr_bytes = stderr_handle.await.unwrap_or_default();
+
+        if let Some(mut sink) = stderr_writer {
+            use tokio::io::AsyncWriteExt;
+            let _ = sink.write_all(&stderr_bytes).await;
+        }
 
         if !status.success() {
             return Err(EngineError::ExecutionFailed {
@@ -645,7 +607,7 @@ impl PSQL {
                 Ok(())
             }),
             Some(Box::new(SharedBufWriter(stdout_buf_clone))),
-            false, // Don't merge stderr for internal queries
+            None, // Not capturing stderr for internal queries
         )
         .await
         .map_err(|e| anyhow!("SQL execution failed: {}", e))?;
@@ -808,7 +770,7 @@ impl PSQL {
                 Ok(())
             }),
             None,
-            false, // Don't merge stderr for recording migrations
+            None, // Not capturing stderr for recording migrations
         )
         .await
         .map_err(|e| match e {
@@ -908,7 +870,7 @@ impl PSQL {
                     Ok(())
                 }),
                 None,
-                false, // Don't merge stderr for migration apply
+                None, // Not capturing stderr for migration apply
             )
             .await;
 

src/sqltest/mod.rs

@@ -21,7 +21,15 @@ pub struct Tester {
 
 #[derive(Debug)]
 pub struct TestOutcome {
-    pub diff: Option<String>,
+    pub stdout_diff: Option<String>,
+    pub stderr_diff: Option<String>,
+}
+
+/// Captured output of a test run, split by stream.
+#[derive(Debug)]
+pub struct TestOutput {
+    pub stdout: String,
+    pub stderr: String,
 }
 
 impl Tester {
@@ -49,6 +57,10 @@ impl Tester {
         format!("{}/expected", self.test_folder())
     }
 
+    pub fn expected_stderr_file_path(&self) -> String {
+        format!("{}/expected_stderr", self.test_folder())
+    }
+
     /// Opens the specified script file and generates a test script, compiled
     /// using minijinja.
     pub async fn generate(&self, variables: Option<crate::variables::Variables>) -> Result<String> {
@@ -71,14 +83,16 @@ impl Tester {
     }
 
     // Runs the test and compares the actual output to expected.
-    pub async fn run(&self, variables: Option<crate::variables::Variables>) -> Result<String> {
+    pub async fn run(&self, variables: Option<crate::variables::Variables>) -> Result<TestOutput> {
         let content = self.generate(variables.clone()).await?;
 
         let engine = self.config.new_engine().await?;
 
-        // Create a shared buffer to capture stdout
+        // Create shared buffers to capture stdout and stderr independently.
         let stdout_buf = Arc::new(Mutex::new(Vec::new()));
         let stdout_buf_clone = stdout_buf.clone();
+        let stderr_buf = Arc::new(Mutex::new(Vec::new()));
+        let stderr_buf_clone = stderr_buf.clone();
 
         match engine
             .execute_with_writer(
@@ -87,45 +101,54 @@ impl Tester {
                     Ok(())
                 }),
                 Some(Box::new(SharedBufWriter(stdout_buf_clone))),
-                true, // Merge stderr into stdout for tests
+                Some(Box::new(SharedBufWriter(stderr_buf_clone))),
             )
             .await
         {
             Ok(()) => {}
             Err(EngineError::ExecutionFailed { .. }) => {
                 // psql exited non-zero (e.g. ON_ERROR_STOP triggered).
-                // The combined output buffer already has the error output,
+                // The stderr buffer already has the error output,
                 // so we just continue and return it.
             }
             Err(e) => return Err(e).context("failed to write content to test db"),
         }
 
-        let buf = stdout_buf.lock().unwrap();
-        let generated = String::from_utf8_lossy(&buf).to_string();
+        let stdout = String::from_utf8_lossy(&stdout_buf.lock().unwrap()).to_string();
+        let stderr = String::from_utf8_lossy(&stderr_buf.lock().unwrap()).to_string();
 
-        Ok(generated)
+        Ok(TestOutput { stdout, stderr })
     }
 
     pub async fn run_compare(
         &self,
         variables: Option<crate::variables::Variables>,
     ) -> Result<TestOutcome> {
-        let generated = self.run(variables).await?;
+        let output = self.run(variables).await?;
+
         let expected_bytes = self
             .config
             .operator()
             .read(&self.expected_file_path())
             .await
-            .context("unable to read expectations file")?
+            .context("unable to read expected file")?
             .to_bytes();
-        let expected = String::from_utf8(expected_bytes.to_vec())
+        let expected_stdout = String::from_utf8(expected_bytes.to_vec())
             .context("expected file is not valid UTF-8")?;
 
-        let outcome = match self.compare(&generated, &expected) {
-            Ok(()) => TestOutcome { diff: None },
-            Err(differences) => TestOutcome {
-                diff: Some(differences.to_string()),
-            },
+        let expected_stderr_bytes = self
+            .config
+            .operator()
+            .read(&self.expected_stderr_file_path())
+            .await
+            .context("unable to read expected_stderr file")?
+            .to_bytes();
+        let expected_stderr = String::from_utf8(expected_stderr_bytes.to_vec())
+            .context("expected_stderr file is not valid UTF-8")?;
+
+        let outcome = TestOutcome {
+            stdout_diff: Self::diff(&expected_stdout, &output.stdout).err(),
+            stderr_diff: Self::diff(&expected_stderr, &output.stderr).err(),
         };
 
         Ok(outcome)
@@ -135,12 +158,17 @@ impl Tester {
         &self,
         variables: Option<crate::variables::Variables>,
     ) -> Result<()> {
-        let content = self.run(variables).await?;
+        let output = self.run(variables).await?;
+        self.config
+            .operator()
+            .write(&self.expected_file_path(), output.stdout)
+            .await
+            .context("unable to write expected file")?;
         self.config
             .operator()
-            .write(&self.expected_file_path(), content)
+            .write(&self.expected_stderr_file_path(), output.stderr)
             .await
-            .context("unable to write expectation file")?;
+            .context("unable to write expected_stderr file")?;
 
         Ok(())
     }
@@ -157,7 +185,7 @@ impl Tester {
         Ok(self.script_path.clone())
     }
 
-    pub fn compare(&self, generated: &str, expected: &str) -> std::result::Result<(), String> {
+    fn diff(expected: &str, generated: &str) -> std::result::Result<(), String> {
         let diff = TextDiff::from_lines(expected, generated);
 
         let mut diff_display = String::new();