Fixed the SQLBatch token-stream desync where an INFO token sharing a response with a result set hung SqlClient until command timeout.

Author: RyanLamansky

SqlServerSimulator.Tests.SqlClient/InfoMessageTests.cs

@@ -51,4 +51,67 @@ public async Task RaiseError_LowSeverity_ArrivesAsInfoMessage()
 
         Contains("warn", messages);
     }
+
+    // The go-sqlcmd shakedown (2026-07-14) exposed a token-stream desync when
+    // an INFO token shares a SQLBatch response with a result set: SqlClient
+    // hung until command timeout on every mixed shape below (go-mssqldb
+    // instead silently dropped the message). Real SQL Server gives the
+    // message-producing statement its own DONE and never emits INFO after
+    // the final DONE. CommandTimeout is set so a regression fails the test
+    // instead of stalling the suite.
+
+    private async Task<(List<string> Messages, List<int> Values)> DrainBatch(string sql)
+    {
+        var simulation = new Simulation();
+        _ = Wire.ReadAllInProc(simulation, "create table t (id int); insert t values (1)");
+        await using var listener = await simulation.ListenAsync(0, TestContext.CancellationToken);
+        await using var connection = await Wire.OpenAsync(listener, TestContext.CancellationToken);
+        var messages = Subscribe(connection);
+
+        await using var command = new SqlCommand(sql, connection) { CommandTimeout = 15 };
+        var values = new List<int>();
+        await using (var reader = await command.ExecuteReaderAsync(TestContext.CancellationToken))
+        {
+            do
+            {
+                while (await reader.ReadAsync(TestContext.CancellationToken))
+                    values.Add(reader.GetInt32(0));
+            }
+            while (await reader.NextResultAsync(TestContext.CancellationToken));
+        }
+
+        return (messages, values);
+    }
+
+    [TestMethod]
+    public async Task Print_ThenSelect_DeliversInfoAndRows()
+    {
+        var (messages, values) = await DrainBatch("print 'before select'; select 42");
+        Contains("before select", messages);
+        AreEqual(42, values.Single());
+    }
+
+    [TestMethod]
+    public async Task Select_ThenPrint_DeliversRowsAndInfo()
+    {
+        var (messages, values) = await DrainBatch("select 42; print 'after select'");
+        Contains("after select", messages);
+        AreEqual(42, values.Single());
+    }
+
+    [TestMethod]
+    public async Task RaiseError_LowSeverity_ThenSelect_DeliversInfoAndRows()
+    {
+        var (messages, values) = await DrainBatch("raiserror('warn', 10, 1); select 42");
+        Contains("warn", messages);
+        AreEqual(42, values.Single());
+    }
+
+    [TestMethod]
+    public async Task Print_BetweenOutcomeStatements_DeliversAll()
+    {
+        var (messages, values) = await DrainBatch("insert t values (2); print 'mid'; select id from t order by id");
+        Contains("mid", messages);
+        CollectionAssert.AreEqual(new[] { 1, 2 }, values);
+    }
 }

SqlServerSimulator/Network/TdsSession.Rpc.cs

@@ -56,13 +56,13 @@ private async ValueTask ExecuteRpcMessageAsync(TdsMessage message, TdsTokenWrite
             }
             catch (SimulatedSqlException ex)
             {
-                this.FlushInfoMessages(writer);
+                _ = this.FlushInfoMessages(writer);
                 WriteErrors(writer, ex);
                 writer.WriteDoneToken(Tds.TokenDoneProc, (ushort)(Tds.DoneError | (moreRequests ? Tds.DoneMore : Tds.DoneFinal)), 0);
             }
             catch (NotSupportedException ex)
             {
-                this.FlushInfoMessages(writer);
+                _ = this.FlushInfoMessages(writer);
                 writer.WriteErrorOrInfo(Tds.TokenError, 50000, 1, 16, $"SqlServerSimulator: {ex.Message}", "SIMULATED", "", 1);
                 writer.WriteDoneToken(Tds.TokenDoneProc, (ushort)(Tds.DoneError | (moreRequests ? Tds.DoneMore : Tds.DoneFinal)), 0);
             }

SqlServerSimulator/Network/TdsSession.cs

@@ -211,18 +211,18 @@ private async ValueTask ExecuteBatchAsync(TdsMessage message, TdsTokenWriter wri
         }
         catch (SimulatedSqlException ex)
         {
-            this.FlushInfoMessages(writer);
+            _ = this.FlushInfoMessages(writer);
             WriteErrors(writer, ex);
             writer.WriteDone(Tds.DoneError, 0);
         }
         catch (NotSupportedException ex)
         {
-            this.FlushInfoMessages(writer);
+            _ = this.FlushInfoMessages(writer);
             writer.WriteErrorOrInfo(Tds.TokenError, 50000, 1, 16, $"SqlServerSimulator: {ex.Message}", "SIMULATED", "", 1);
             writer.WriteDone(Tds.DoneError, 0);
         }
 
-        this.FlushInfoMessages(writer);
+        _ = this.FlushInfoMessages(writer);
         var databaseAfter = this.connection.Database;
         if (!string.Equals(databaseAfter, databaseBefore, StringComparison.Ordinal))
             writer.WriteEnvChange(Tds.EnvDatabase, databaseAfter, databaseBefore);
@@ -241,16 +241,19 @@ private async ValueTask StreamOutcomesAsync(SimulatedDbCommand command, TdsToken
         using var outcomes = simulation.CreateResultSetsForCommand(command).GetEnumerator();
 
         var hasOutcome = outcomes.MoveNext();
-        if (!hasOutcome && !trailingTokensFollow)
-        {
-            this.FlushInfoMessages(writer);
-            writer.WriteDone(Tds.DoneFinal, 0);
-        }
-
+        var anyOutcome = hasOutcome;
         while (hasOutcome)
         {
             var outcome = outcomes.Current;
-            this.FlushInfoMessages(writer);
+            // Messages from a preceding no-outcome statement (PRINT,
+            // severity<=10 RAISERROR): real SQL Server gives that statement
+            // its own DONE after the INFO tokens. Without it SqlClient's
+            // token reader stalls on the INFO/COLMETADATA adjacency until
+            // command timeout (go-sqlcmd shakedown, 2026-07-14). RPC
+            // responses skip the extra DONEINPROC — their per-statement
+            // DONEINPROC stream is already well-formed for proc-body PRINT.
+            if (this.FlushInfoMessages(writer) && !trailingTokensFollow)
+                writer.WriteDoneToken(doneToken, Tds.DoneMore, 0);
             if (outcome is SimulatedQueryResult query)
             {
                 TdsTypeCodec.ValidateSchema(query.Schema);
@@ -267,24 +270,37 @@ private async ValueTask StreamOutcomesAsync(SimulatedDbCommand command, TdsToken
                 }
 
                 hasOutcome = outcomes.MoveNext();
-                var status = hasOutcome || trailingTokensFollow ? Tds.DoneMore : Tds.DoneFinal;
-                writer.WriteDoneToken(doneToken, (ushort)(status | Tds.DoneCount), rows);
+                writer.WriteDoneToken(doneToken, (ushort)(this.OutcomeDoneStatus(hasOutcome, trailingTokensFollow) | Tds.DoneCount), rows);
             }
             else
             {
                 var affected = outcome.RecordsAffected;
                 hasOutcome = outcomes.MoveNext();
-                var status = hasOutcome || trailingTokensFollow ? Tds.DoneMore : Tds.DoneFinal;
+                var status = this.OutcomeDoneStatus(hasOutcome, trailingTokensFollow);
                 if (affected >= 0)
                     status |= Tds.DoneCount;
 
                 writer.WriteDoneToken(doneToken, status, Math.Max(affected, 0));
             }
         }
 
-        this.FlushInfoMessages(writer);
+        // Trailing messages (batch ends in PRINT): INFO may never follow the
+        // final DONE, so the last outcome's DONE stayed DONE_MORE (see
+        // OutcomeDoneStatus) and the batch closes with its own final DONE.
+        var flushedTrailing = this.FlushInfoMessages(writer);
+        if (!trailingTokensFollow && (flushedTrailing || !anyOutcome))
+            writer.WriteDoneToken(doneToken, Tds.DoneFinal, 0);
     }
 
+    /// <summary>
+    /// DONE status for a completed outcome: more tokens follow when another
+    /// outcome exists, the response is an RPC (RETURNSTATUS / DONEPROC still
+    /// come), or queued info messages remain to be written — the trailing-
+    /// PRINT case, whose INFO must precede the batch's final DONE.
+    /// </summary>
+    private ushort OutcomeDoneStatus(bool hasOutcome, bool trailingTokensFollow) =>
+        hasOutcome || trailingTokensFollow || this.pendingInfoMessages.Count > 0 ? Tds.DoneMore : Tds.DoneFinal;
+
     private void ResetConnection()
     {
         var previous = this.connection!;
@@ -302,10 +318,17 @@ private void ResetConnection()
         this.connection = fresh;
     }
 
-    private void FlushInfoMessages(TdsTokenWriter writer)
+    /// <summary>Writes all queued info messages as INFO tokens; true when any were written.</summary>
+    private bool FlushInfoMessages(TdsTokenWriter writer)
     {
+        var any = false;
         while (this.pendingInfoMessages.TryDequeue(out var error))
+        {
             writer.WriteErrorOrInfo(Tds.TokenInfo, error.Number, error.State, error.Class, error.Message, error.Server, error.Procedure, error.LineNumber);
+            any = true;
+        }
+
+        return any;
     }
 
     private static void WriteErrors(TdsTokenWriter writer, SimulatedSqlException exception)

docs/claude/backlog.md

@@ -22,7 +22,7 @@ This file is the home for net-new non-function feature proposals too. CLAUDE.md'
 
 The endpoint ships with SQLBatch + RPC + Transaction Manager support and credential enforcement via the `CREATE LOGIN` registry (see [`tds-endpoint.md`](tds-endpoint.md)); EF Core runs over the wire through vanilla `UseSqlServer`. Remaining phases, roughly in value order:
 
-- **Tool shakedown** — point sqlcmd/SSMS/DBeaver at the endpoint and harvest their exotic catalog queries / SET shapes into this backlog. SSMS is the boss fight. Likely to want `sys.server_principals` / `sys.sql_logins` projected over the login registry.
+- **Tool shakedown** — point sqlcmd/SSMS/DBeaver at the endpoint and harvest their exotic catalog queries / SET shapes into this backlog. SSMS is the boss fight. Likely to want `sys.server_principals` / `sys.sql_logins` projected over the login registry. **go-sqlcmd leg done (2026-07-14)**, first non-SqlClient client (go-mssqldb): connect/auth/batches/GO files/`:setvar`/`:r`/transactions/output modes all clean; headline find was the INFO-token/result-set DONE desync (fixed — see [`tds-endpoint.md`](tds-endpoint.md) batch-loop section); engine-level harvest landed under Fidelity gaps. SSMS + DBeaver legs remain (GUI, need a host-exposed port).
 - **TVP parameters over the wire** (TYPE_INFO 0xF3) — the in-process TVP surface ships; the RPC reader rejects the wire form. Needed for `SqlDbType.Structured` and EF bulk patterns.
 - **Wire forms deferred by the codec**: `text`/`ntext`/`image` (textptr ROW form + table-name-bearing COLMETADATA), `hierarchyid`/`geography`/`geometry` (UDT 0xF0), `sql_variant` (no simulator type at all).
 - **Smaller fidelity items**: Msg 4060 (not 911) for login to a missing database; mid-stream attention (cancel during a large result requires a concurrent reader); `SqlBulkCopy` (BulkLoadBCP); MARS; TDS 8.0 / `Encrypt=Strict` (ALPN via `SslApplicationProtocol`); user-supplied `X509Certificate2`; off-loopback binding — the last two are add-on-demand public-surface expansions.
@@ -53,6 +53,8 @@ Low priority / niche — simulatable (as placeholder constants or a small model)
 
 Real bugs / limitations against shipped behavior — fixes are concrete work, not design decisions.
 
+- **`SimulatedSqlException` ERROR tokens carry `Server=''` / `Line 0`** — real SQL Server fills the server name and a 1-based line number on every error; the simulator's query errors surface blank/0 both in-process and over the wire (sqlcmd renders `Server , Line 0`). Inconsistently, `NotSupportedException`-derived wire errors *do* carry `Server=SIMULATED, Line 1`. Engine-level: the fix is stamping `SimulatedError.Server` (from `SERVERPROPERTY('ServerName')` = `SIMULATED`) at construction and threading real line numbers from the tokenizer — the latter is the large part. Harvested from the go-sqlcmd shakedown (2026-07-14).
+- **String literals typed at container width, not value width** — `SELECT 'included'` advertises `varchar(8000)` (and `@@VERSION` `nvarchar(4000)`) in projection schema; real types literals at exact length (`varchar(8)`). Correct data, but clients that size display columns from COLMETADATA (sqlcmd) render absurdly wide output, and `GetSchemaTable`-driven consumers see wrong sizes. Fix lives in literal `SqlType` inference (`Literal` → length-parameterized type), with CONCAT/CASE/set-op width-combination ripple effects — probe real's width algebra before starting. Harvested from the go-sqlcmd shakedown (2026-07-14).
 - **Trailing-space MIN/MAX representative** — for a group of values differing only in trailing spaces (sort-equal under SQL Server), MIN/MAX returns a different byte-variant than the live server's scan-order representative. Surfaced by the AdventureWorks crosscheck on synthetic XML data (`vJobCandidateEducation._max_Edu_Loc_CountryRegion`). Needs trailing-space-insensitive compare + SQL Server's unspecified MAX-tie scan-order. See [`collations.md`](collations.md) "byte-exact sort" trailing-space note. **Deferred** — synthetic data, and the representative is unspecified scan-order on the live side.
 - **Leaked-connection session cleanup** — a `SimulatedDbConnection` that's never `Dispose`d never reclaims its session state: an open transaction holds its locks and pins the MVCC version store, `##temp` tables linger, session-owned app locks stay held, and the SPID accumulates. Real SqlClient's GC-finalization eventually closes a leaked connection and the server resets the session, so this is a genuine fidelity divergence. **Scope correction (2026-07-11): the fix is bigger than "weaken the registry."** Investigation found *three* global strong-reference cycles that pin exactly the connections that hold session state, so GC can't collect them and a finalizer never fires: (1) `LockResource.Hold.Owner` is a strong `SimulatedDbConnection` (reachable Database → table → lock → hold) — pins any lock- or session-app-lock-holding connection; (2) `HeapTable.OwnerConnection` is strong and `Simulation.GlobalTempTables` holds the table — pins any `##temp` owner; (3) `Database.ActiveSnapshotTxs` holds the transaction, which strongly refs its connection — pins any open-snapshot session. Weakening `Simulation.Connections` alone accomplishes nothing because the resource *is* the pin. A correct fix must break all three cycles — cleanest via a one-way `SessionToken` indirection (resources reference a lightweight token identity; the connection references the token, not vice versa) plus a finalizer that enqueues a **deferred teardown** drained on a normal worker thread (next `CreateDbConnection` / version-store GC) so transaction rollback stays off the finalizer thread. This is a broad, mechanical owner-indirection refactor landing on the most regression-sensitive subsystem (lock manager × GC timing × threading). Payoff is bounded (EF disposes scrupulously; only buggy consumer code leaks), so it's **deliberately deferred** as high-risk / low-frequency. Eventual home: [`locking.md`](locking.md).
 - **Workload-harness divergence reporting quirks** (`.vs/workload/Program.cs`, local-only) — the parity report's example line rebuilds parameters from the op seed and can mismatch the actual divergent instance, and divergent instances aren't re-run single-threaded to classify transient-vs-stable. Both made the 2026-07-10 shared-plan-state hunt slower than it needed to be (the fixed bug class itself — instance-bound aggregate/window results, baked TOP/OFFSET counts, frozen RAND, unstamped replay clock — is documented in [`plan-cache.md`](plan-cache.md)'s shared-plan contract section).

docs/claude/tds-endpoint.md

@@ -27,7 +27,7 @@ Everything lives in `Network/` (internal) except the public `SimulatedNetworkLis
 
 - **SQLBatch** (type 1): ALL_HEADERS skipped via its leading length DWORD; UCS-2 text executed on the session connection. Per result set: COLMETADATA + ROW stream + DONE (`DONE_COUNT` + `DONE_MORE` when more outcomes follow); per non-query statement: DONE with `DONE_COUNT` only when `RecordsAffected >= 0`. Zero outcomes → single final DONE. All tokens are `0xFD DONE` (DONEPROC/DONEINPROC are proc-scoped and RPC isn't shipped).
 - **Errors**: `SimulatedSqlException.Errors` map field-for-field onto ERROR tokens (number/state/class/message/server/procedure/line) + DONE with `DONE_ERROR`; the session survives and keeps serving. `NotSupportedException` becomes a synthetic ERROR number 50000 class 16 prefixed `SqlServerSimulator:`.
-- **PRINT / low-severity RAISERROR**: the session subscribes to `SimulatedDbConnection.InfoMessage` and drains the queue as INFO tokens between statements and at batch end.
+- **PRINT / low-severity RAISERROR**: the session subscribes to `SimulatedDbConnection.InfoMessage` and drains the queue as INFO tokens between statements and at batch end. **Each INFO flush in a SQLBatch response gets its own DONE**, mirroring real per-statement DONEs: info preceding an outcome is followed by `DONE_MORE` count 0 before the outcome's tokens, and trailing info (batch ends in PRINT) forces the last outcome's DONE to `DONE_MORE` with a closing `DONE_FINAL` count 0 after the INFO — an INFO token must never follow the final DONE. Without both, SqlClient's token reader stalls until command timeout on any batch mixing PRINT with a result set, and go-mssqldb silently drops the message (go-sqlcmd shakedown, 2026-07-14; the pre-fix oracle only covered PRINT-without-result-set). RPC responses are unaffected — every DONEINPROC already carries `DONE_MORE`.
 - **`USE`**: database change detected by before/after comparison and emitted as ENVCHANGE type 1 (after the DONEs, before flush — SqlClient processes it anywhere pre-EOM).
 - **Reset-connection status bit** (pooled-connection recycle): backing connection disposed and recreated on the same database, acked with the empty ENVCHANGE type 18 before the batch's tokens.
 - **Attention** (type 6): acked with DONE `DONE_ATTN`. Execution is synchronous per message, so attention is only observed between messages — a cancel never interrupts a running statement server-side, it just gets acked when the stream drains. In-process execution is fast enough that this matches observable SqlClient behavior.