fix: route a statement's diagnostics in driver order (#478)

lib/reader.js

@@ -81,36 +81,40 @@ class Query extends BasePromises {
   }
 
   /* route non-critical info messages to its own event to prevent streams based readers from halting */
-  // moreResults: the batch carries on after these errors, so 'more' is true for all of them
+  // in the order the driver gave them (#478). 'more' is counted over the errors only: an
+  // error has more when another error follows it, or when the batch carries on after them
+  // (moreResults).
   routeStatementError (errorsAndInfo, callback, notify, moreResults = false) {
     if (!Array.isArray(errorsAndInfo)) {
       errorsAndInfo = [errorsAndInfo]
     }
-    let i = 0
-    const onlyErrors = errorsAndInfo.reduce((agg, latest) => {
-      if (!this.isInfo(latest)) {
-        agg.push(latest)
-      }
-      return agg
-    }, [])
-    const errorCount = onlyErrors.length
+    const errorCount = errorsAndInfo.filter(e => !this.isInfo(e)).length
+    let errorIndex = 0
     errorsAndInfo.forEach(err => {
       const info = this.isInfo(err)
+      const more = moreResults || (info ? errorIndex < errorCount : errorIndex < errorCount - 1)
+      if (!info) ++errorIndex
       if (callback && !info) {
-        const more = moreResults || i < errorsAndInfo.length - 1
         callback(err, null, more)
       } else {
         const ev = info ? 'info' : 'error'
         if (notify) {
-          const more = moreResults || i < errorCount - 1
-          if (notify.listenerCount(ev) > 0) {
-            notify.emit(ev, err, more)
+          const emit = () => {
+            if (notify.listenerCount(ev) > 0) {
+              notify.emit(ev, err, more)
+            }
+          }
+          // the connection defers the user's callback by a tick: info that follows an error
+          // in the set waits as long, so it still comes after the error
+          if (callback && info && errorIndex > 0) {
+            setImmediate(emit)
+          } else {
+            emit()
           }
         } else {
           throw new Error(err)
         }
       }
-      ++i
     })
   }
 
@@ -161,25 +165,15 @@ class Query extends BasePromises {
     }
   }
 
+  // a set of diagnostics with no error in it: route the info now, and nothing is returned.
+  // with an error in it: route nothing, and return the whole set, info included, so that
+  // the error path routes it in driver order - the error first, then e.g. 3621 "The
+  // statement has been terminated" (#478)
   dispatchInfoReturnErrors (e) {
-    const infoMessages = []
-    const errorMessages = []
-
-    if (e && Array.isArray(e)) {
-      e.forEach(errorOrInfo => {
-        if (this.isInfo(errorOrInfo)) {
-          infoMessages.push(errorOrInfo)
-        } else {
-          errorMessages.push(errorOrInfo)
-        }
-      })
-    }
-    // route info even alongside errors: a print just before a failing statement arrives
-    // in the same set of diagnostics as the error
-    if (infoMessages.length > 0) {
-      this.routeStatementError(infoMessages, this.callback, this.notify, false)
-    }
-    return errorMessages
+    if (!e || !Array.isArray(e) || e.length === 0) return []
+    if (e.some(m => !this.isInfo(m))) return e
+    this.routeStatementError(e, this.callback, this.notify, false)
+    return []
   }
 
   async nativeNextResult (queryId) {
@@ -189,13 +183,13 @@ class Query extends BasePromises {
       this.native.nextResultSet(this.queryId, this.notify.getHandle(), (e, res) => {
         setImmediate(() => {
           // may contain info messages e.g. raised by PRINT statements - do not want to reject these
-          const errorMessages = e ? this.dispatchInfoReturnErrors(e) : []
-          if (errorMessages.length > 0 && res && !res.endOfResults) {
+          const withErrors = e ? this.dispatchInfoReturnErrors(e) : []
+          if (withErrors.length > 0 && res && !res.endOfResults) {
             // a statement in the batch failed but the batch goes on: report and carry on
-            this.routeStatementError(errorMessages, this.callback, this.notify, true)
+            this.routeStatementError(withErrors, this.callback, this.notify, true)
             resolve(res)
-          } else if (errorMessages.length > 0) {
-            reject(errorMessages)
+          } else if (withErrors.length > 0) {
+            reject(withErrors)
           } else {
             this.infoFromNextResult = e != null && Array.isArray(e) && e.length > 0
             resolve(res)
@@ -351,7 +345,8 @@ class Query extends BasePromises {
   // the query was cancelled, so report it as such.
   asCancelled (errors) {
     if (!this.notify.getCancelSent()) return errors
-    const fromCancel = errors.length > 0 && errors.every(e => cancelSideEffectStates.has(e?.sqlstate))
+    const real = errors.filter(e => !this.isInfo(e))
+    const fromCancel = real.length > 0 && real.every(e => cancelSideEffectStates.has(e?.sqlstate))
     if (!fromCancel) return errors
     logger.debugLazy(() => `query ${this.queryId} fetch after cancel failed with ${errors[0].sqlstate} - report as cancelled`, this.context)
     const cancelled = new Error('[msnodesql] Operation canceled')

test/contract/HANDOVER.md

@@ -142,9 +142,27 @@ clears the token first. New, agreed: `cancel/twice-*`, `cancel/again-after-confi
 `cancel/paused-again-after-confirm-at-100`, `cancel/paused-before-execute-twice`, and
 `cancel/paused-resumed-after-cancel-at-100` (a resume after the cancel does nothing).
 
+## Progress — 2026-10-18: diagnostics in driver order (#478)
+
+`dispatchInfoReturnErrors` routed a set's info at once and handed back only its errors, so
+3621 "The statement has been terminated." overtook its 2627. Now a set with an error in it is
+routed whole, in driver order, by the error path. A set of info only is routed at once, as
+before. `routeStatementError` counts `more` over errors only: an error has more when another
+error follows it or the batch goes on. Before, it also counted info, which was latent while
+info and errors were routed apart. In callback mode, info that follows an error in a set is
+emitted a tick on, after the (deferred) callback. `asCancelled` ignores info. New:
+`errors/two-errors-one-statement` (1779 then 1750). All `dup-key-*` and `scripts/issue-478`
+are agreed; the Linux pins were reordered by hand and stay known-bug for #483.
+
+Found while there, not fixed: info from some DDL is mostly lost, on master too. 1756
+"Skipping FOREIGN KEY constraint ... for temporary table" from
+`create table #fk (id int constraint fk_x references no_such_table(id))` came 0 of 20 times
+on master and 1 of 20 here, while PRINT info always comes. It is probably native: the
+diagnostics are not read when the driver returns plain `SQL_SUCCESS`.
+
 ## Next
 
-1. #478: route each set of diagnostics in driver order; count `more` over errors only.
+1. Info lost from DDL (above): pin it with a scenario, then look at the native diagnostics reads.
 2. Hold an error *at execute* while paused. `free` now waits for `done`, which removes the
    reason it was not held (below).
 3. Prepared executions: `free` per execution, or document that only `free()` raises it.

test/contract/corpus/errors/dup-key-a.callback.txt

@@ -1,10 +1,10 @@
 # scenario: errors/dup-key-a.callback
-# status: known-bug
+# status: agreed
 # setup: create table #t (id int constraint pk_t primary key); insert #t values (1)
 # sql: insert #t values (1)
 submitted
-info 01000 3621 The statement has been terminated.
 cb error 23000 2627 Violation of PRIMARY KEY constraint 'pk_t'. Cannot insert duplicate key in object 'dbo.#t'. The duplicate key value is (1). more=false
+info 01000 3621 The statement has been terminated.
 done
 free
 check ok

test/contract/corpus/errors/dup-key-a.events.txt

@@ -1,10 +1,10 @@
 # scenario: errors/dup-key-a.events
-# status: known-bug
+# status: agreed
 # setup: create table #t (id int constraint pk_t primary key); insert #t values (1)
 # sql: insert #t values (1)
 submitted
-info 01000 3621 The statement has been terminated.
 error 23000 2627 Violation of PRIMARY KEY constraint 'pk_t'. Cannot insert duplicate key in object 'dbo.#t'. The duplicate key value is (1). more=false
+info 01000 3621 The statement has been terminated.
 done
 free
 check ok

test/contract/corpus/errors/dup-key-b.callback.txt

@@ -1,13 +1,13 @@
 # scenario: errors/dup-key-b.callback
-# status: known-bug
+# status: agreed
 # setup: create table #t (id int constraint pk_t primary key); insert #t values (1)
 # sql: select 1 as n; insert #t values (1)
 submitted
 meta n
 row
 column 0 1
-info 01000 3621 The statement has been terminated.
 cb error 23000 2627 Violation of PRIMARY KEY constraint 'pk_t'. Cannot insert duplicate key in object 'dbo.#t'. The duplicate key value is (1). more=false
+info 01000 3621 The statement has been terminated.
 done
 free
 check ok

test/contract/corpus/errors/dup-key-b.events.txt

@@ -1,13 +1,13 @@
 # scenario: errors/dup-key-b.events
-# status: known-bug
+# status: agreed
 # setup: create table #t (id int constraint pk_t primary key); insert #t values (1)
 # sql: select 1 as n; insert #t values (1)
 submitted
 meta n
 row
 column 0 1
-info 01000 3621 The statement has been terminated.
 error 23000 2627 Violation of PRIMARY KEY constraint 'pk_t'. Cannot insert duplicate key in object 'dbo.#t'. The duplicate key value is (1). more=false
+info 01000 3621 The statement has been terminated.
 done
 free
 check ok

test/contract/corpus/errors/dup-key-c.callback.txt

@@ -1,13 +1,13 @@
 # scenario: errors/dup-key-c.callback
-# status: unreviewed
+# status: agreed
 # setup: create table #t (id int constraint pk_t primary key); insert #t values (1)
 # sql: select 1 as n; insert #t values (1); select 2 as m
 submitted
 meta n
 row
 column 0 1
-info 01000 3621 The statement has been terminated.
 cb error 23000 2627 Violation of PRIMARY KEY constraint 'pk_t'. Cannot insert duplicate key in object 'dbo.#t'. The duplicate key value is (1). more=true
+info 01000 3621 The statement has been terminated.
 cb ok rows=1 more=true
 rowcount 0
 meta m

test/contract/corpus/errors/dup-key-c.events.txt

@@ -1,13 +1,13 @@
 # scenario: errors/dup-key-c.events
-# status: unreviewed
+# status: agreed
 # setup: create table #t (id int constraint pk_t primary key); insert #t values (1)
 # sql: select 1 as n; insert #t values (1); select 2 as m
 submitted
 meta n
 row
 column 0 1
-info 01000 3621 The statement has been terminated.
 error 23000 2627 Violation of PRIMARY KEY constraint 'pk_t'. Cannot insert duplicate key in object 'dbo.#t'. The duplicate key value is (1). more=true
+info 01000 3621 The statement has been terminated.
 rowcount 0
 meta m
 row

test/contract/corpus/errors/dup-key-d.callback.linux.txt

@@ -3,8 +3,8 @@
 # setup: create table #t (id int constraint pk_t primary key); insert #t values (1)
 # sql: insert #t values (1); select 2 as m
 submitted
-info 01000 3621 The statement has been terminated.
 cb error 23000 2627 Violation of PRIMARY KEY constraint 'pk_t'. Cannot insert duplicate key in object 'dbo.#t'. The duplicate key value is (1). more=false
+info 01000 3621 The statement has been terminated.
 done
 free
 check ok

test/contract/corpus/errors/dup-key-d.callback.txt

@@ -1,10 +1,10 @@
 # scenario: errors/dup-key-d.callback
-# status: unreviewed
+# status: agreed
 # setup: create table #t (id int constraint pk_t primary key); insert #t values (1)
 # sql: insert #t values (1); select 2 as m
 submitted
-info 01000 3621 The statement has been terminated.
 cb error 23000 2627 Violation of PRIMARY KEY constraint 'pk_t'. Cannot insert duplicate key in object 'dbo.#t'. The duplicate key value is (1). more=true
+info 01000 3621 The statement has been terminated.
 rowcount 0
 meta m
 cb ok rows=0 more=true

test/contract/corpus/errors/dup-key-d.events.linux.txt

@@ -3,8 +3,8 @@
 # setup: create table #t (id int constraint pk_t primary key); insert #t values (1)
 # sql: insert #t values (1); select 2 as m
 submitted
-info 01000 3621 The statement has been terminated.
 error 23000 2627 Violation of PRIMARY KEY constraint 'pk_t'. Cannot insert duplicate key in object 'dbo.#t'. The duplicate key value is (1). more=false
+info 01000 3621 The statement has been terminated.
 done
 free
 check ok

test/contract/corpus/errors/dup-key-d.events.txt

@@ -1,5 +1,5 @@
 # scenario: errors/dup-key-d.events
-# status: unreviewed
+# status: agreed
 # setup: create table #t (id int constraint pk_t primary key); insert #t values (1)
 # sql: insert #t values (1); select 2 as m
 submitted

test/contract/corpus/errors/two-errors-one-statement.callback.txt

@@ -0,0 +1,10 @@
+# scenario: errors/two-errors-one-statement.callback
+# status: agreed
+# setup: create table #t (id int constraint pk_t primary key); insert #t values (1)
+# sql: alter table #t add constraint pk_t2 primary key (id)
+submitted
+cb error 42000 1779 Table '#t' already has a primary key defined on it. more=true
+cb error 42000 1750 Could not create constraint or index. See previous errors. more=false
+done
+free
+check ok

test/contract/corpus/errors/two-errors-one-statement.events.txt

@@ -0,0 +1,10 @@
+# scenario: errors/two-errors-one-statement.events
+# status: agreed
+# setup: create table #t (id int constraint pk_t primary key); insert #t values (1)
+# sql: alter table #t add constraint pk_t2 primary key (id)
+submitted
+error 42000 1779 Table '#t' already has a primary key defined on it. more=true
+error 42000 1750 Could not create constraint or index. See previous errors. more=false
+done
+free
+check ok

test/contract/corpus/scripts/issue-478.linux.txt

@@ -8,33 +8,33 @@ setup: done
 setup: free
 == A insert #t values (1)
 A: submitted
-A: info 01000 3621 The statement has been terminated.
 A: error 23000 2627 Violation of PRIMARY KEY constraint 'pk_t'. Cannot insert duplicate key in object 'dbo.#t'. The duplicate key value is (1). more=false
+A: info 01000 3621 The statement has been terminated.
 A: done
 A: free
 == B select 1 as n; insert #t values (1)
 B: submitted
 B: meta n
 B: row
-B: info 01000 3621 The statement has been terminated.
 B: error 23000 2627 Violation of PRIMARY KEY constraint 'pk_t'. Cannot insert duplicate key in object 'dbo.#t'. The duplicate key value is (1). more=false
+B: info 01000 3621 The statement has been terminated.
 B: done
 B: free
 == C select 1 as n; insert #t values (1); select 2 as m
 C: submitted
 C: meta n
 C: row
-C: info 01000 3621 The statement has been terminated.
 C: error 23000 2627 Violation of PRIMARY KEY constraint 'pk_t'. Cannot insert duplicate key in object 'dbo.#t'. The duplicate key value is (1). more=true
+C: info 01000 3621 The statement has been terminated.
 C: rowcount 0
 C: meta m
 C: row
 C: done
 C: free
 == D insert #t values (1); select 2 as m
 D: submitted
-D: info 01000 3621 The statement has been terminated.
 D: error 23000 2627 Violation of PRIMARY KEY constraint 'pk_t'. Cannot insert duplicate key in object 'dbo.#t'. The duplicate key value is (1). more=false
+D: info 01000 3621 The statement has been terminated.
 D: done
 D: free
 check ok

test/contract/corpus/scripts/issue-478.txt

@@ -1,5 +1,5 @@
 # scenario: scripts/issue-478
-# status: known-bug
+# status: agreed
 # script: test/contract/scripts/issue-478.js
 setup: submitted
 setup: rowcount 1
@@ -8,24 +8,24 @@ setup: done
 setup: free
 == A insert #t values (1)
 A: submitted
-A: info 01000 3621 The statement has been terminated.
 A: error 23000 2627 Violation of PRIMARY KEY constraint 'pk_t'. Cannot insert duplicate key in object 'dbo.#t'. The duplicate key value is (1). more=false
+A: info 01000 3621 The statement has been terminated.
 A: done
 A: free
 == B select 1 as n; insert #t values (1)
 B: submitted
 B: meta n
 B: row
-B: info 01000 3621 The statement has been terminated.
 B: error 23000 2627 Violation of PRIMARY KEY constraint 'pk_t'. Cannot insert duplicate key in object 'dbo.#t'. The duplicate key value is (1). more=false
+B: info 01000 3621 The statement has been terminated.
 B: done
 B: free
 == C select 1 as n; insert #t values (1); select 2 as m
 C: submitted
 C: meta n
 C: row
-C: info 01000 3621 The statement has been terminated.
 C: error 23000 2627 Violation of PRIMARY KEY constraint 'pk_t'. Cannot insert duplicate key in object 'dbo.#t'. The duplicate key value is (1). more=true
+C: info 01000 3621 The statement has been terminated.
 C: rowcount 0
 C: meta m
 C: row