From c7a780d5af747856a2c479394efe55c159f65f9b Mon Sep 17 00:00:00 2001 From: Senthil <79847390+datacore-senthil@users.noreply.github.com> Date: Thu, 6 Aug 2026 17:35:45 +0530 Subject: [PATCH 1/2] Fix use-after-free and double-free in kmem_vasprintf() (SSV-26896) Fixes a kernel use-after-free plus double-free that corrupted the shared kmem/vmem freelists and produced bugchecks in unrelated subsystems (nvlist and ABD teardown) long after the fact. Introduced by the SSV-26770 CodeQL remediation; found by root-causing a cluster of ZFSin crash dumps, one of which was captured under Driver Verifier. Root cause kmem_vasprintf() used the "measure with a NULL destination, then allocate that much" idiom. The SSV-26770 work replaced the underlying _vsnprintf(NULL, 0, ...) - which returns the true, unbounded required length - with zfs_vsnprintf(NULL, 0, ...), which routes to zfs_vscprintf(). Kernel mode has no linkable way to measure a format without writing it (_vscprintf is declared by the WDK but not exported by the kernel-mode CRT import lib; _vsnprintf_s rejects count == 0), so zfs_vscprintf() measures by formatting into a bounded 1024-byte scratch buffer and therefore reports a capped 1023 for anything longer. Sizing an allocation from that capped length under-allocates, which made a previously unreachable error path in kmem_vasprintf() reachable for the first time: for any format whose output is >= 1024 characters, kmem_alloc(size + 1) is too small, the real write returns -1, and the error path ran kmem_free(ptr, size); /* allocated size + 1: mismatched size */ r = -1; /* r is discarded; ptr is NOT cleared */ ... return (ptr); /* returns the freed pointer */ so the caller received a dangling pointer into freed memory. Before the remediation this path was dead code: the measurement was exact, so the write always returned exactly size and the condition was never true. The principal caller is log_internal() in module/zfs/spa_history.c, which does msg = kmem_vasprintf(fmt, adx); fnvlist_add_string(nvl, ZPOOL_HIST_INT_STR, msg); /* UAF read */ kmem_strfree(msg); /* double free */ i.e. it reads freed memory into the pool-history nvlist and then frees the block a second time, with a size derived from whatever string happens to occupy it. That is reached from spa_history_log_internal(), which logs nearly every pool operation, so the resulting freelist corruption surfaced later as "bad free" panics in vmem_hash_delete() and as nvlists and ABDs containing another owner's data. Fix kmem_vasprintf() now grows a scratch buffer and retries the real write until the whole string fits, with no measurement pass, so the freed size always matches the allocated size and it never returns a freed pointer. It still returns a buffer allocated at exactly strlen() + 1: callers free these with kmem_strfree(), which computes the size as strlen(str) + 1, so anything else (for example returning the grown power-of-two buffer directly) would reintroduce the same mismatched-free bug at all ~25 kmem_asprintf() call sites. kmem_asprintf() now delegates to kmem_vasprintf(). Both keep their existing "never returns NULL" contract, accepting a truncated but valid string at a 64 KB ceiling. __dprintf() had the same dependency on an exact measurement, so it is rebuilt on the now-safe helpers instead of hand-computing offsets into a single buffer. That also removes a second off-by-one, missed by an earlier review, in the prefix write: snprintf(buf, size + 1, ...) told it one more byte than buf actually had. The allocation length is recorded before the trailing-newline strip edits the string in place, since strlen() + 1 afterwards is a byte short of what was allocated. The comment on zfs_vscprintf() in types.h asserted that a capped measurement was harmless because a later write would truncate identically. That reasoning is what produced this bug - it holds only when the measured length is not used to size the buffer. Replaced with an explicit warning that the value is capped and must never size an allocation. Audited for the same patterns: the only remaining buf==NULL/size==0 callers are under module/os/freebsd, which is not part of this driver. The vendored zlib's equivalent size==0 branch is unreachable (its callers always pass sizeof(buf)). No caller modifies a kmem_asprintf() result before kmem_strfree(). The ~23 sites that consume an snprintf() return value are unaffected, as both the old _snprintf and the new _vsnprintf_s(_TRUNCATE) return -1 on truncation, and none of them can reach the exact-fit boundary where the two differ. Not yet build-verified or re-scanned; pushed for review and testing. --- include/os/windows/spl/sys/types.h | 29 +++++----- module/os/windows/spl/spl-kmem.c | 86 +++++++++++++++++++++--------- module/os/windows/zfs/zfs_debug.c | 48 +++++++---------- 3 files changed, 99 insertions(+), 64 deletions(-) diff --git a/include/os/windows/spl/sys/types.h b/include/os/windows/spl/sys/types.h index 04d65ebe5952..2639f8b5acca 100644 --- a/include/os/windows/spl/sys/types.h +++ b/include/os/windows/spl/sys/types.h @@ -117,19 +117,24 @@ typedef uintptr_t pc_t; * caller in this tree only checks `if (n < 0)`), so this is purely additive. */ /* + * WARNING: this returns a *capped* length, NOT the true required length. + * * "Measure the required length without writing" (the buf==NULL/size==0 - * idiom used by kmem_asprintf()/kmem_vasprintf()/zfs_dbgmsg()). Neither - * _vscprintf (declared in the WDK headers but not exported by the - * kernel-mode CRT import lib - confirmed via a link failure) nor - * _vsnprintf_s (its count==0 case triggers the invalid-parameter handler) - * can do this directly in kernel mode. Measure into a generously-sized - * scratch buffer instead: every caller in this tree builds short, bounded - * strings (dataset/snapshot names, log messages), so 1024 bytes is never - * exceeded in practice. If a caller's format+args ever did exceed it, the - * result here is a consistently-truncated (safely null-terminated) length - * - the caller's later real write with the same format+args into a - * same-size-or-larger buffer would truncate identically, not silently - * disagree with what was measured. + * idiom) cannot be done natively in kernel mode here: _vscprintf is declared + * by the WDK but not exported by the kernel-mode CRT import lib (confirmed + * via a link failure), and _vsnprintf_s rejects count == 0. So this measures + * by formatting into a bounded scratch buffer, which means that for any + * format+args longer than the scratch buffer it reports sizeof(scratch) - 1 + * instead of the real length. + * + * Consequently this must NEVER be used to size an allocation. Doing so + * silently under-allocates for long strings; kmem_vasprintf() used to do + * exactly that, which drove it into an error path that freed the buffer with + * a mismatched size and returned the freed pointer to its caller - a + * use-after-free plus double-free that corrupted the shared kmem/vmem + * freelists and crashed unrelated subsystems (nvlist and ABD teardown) much + * later. Callers that need a correctly sized buffer must grow-and-retry a + * real write instead; see kmem_vasprintf() in spl-kmem.c. */ static inline int zfs_vscprintf(const char *fmt, va_list ap) diff --git a/module/os/windows/spl/spl-kmem.c b/module/os/windows/spl/spl-kmem.c index 84e604307eb2..287eaf4994b1 100644 --- a/module/os/windows/spl/spl-kmem.c +++ b/module/os/windows/spl/spl-kmem.c @@ -6613,21 +6613,21 @@ kmem_asdprintf(const char *fmt, ...) return (ptr); } +/* + * Largest buffer kmem_vasprintf() will grow to before it accepts a truncated + * result. Every format used in this tree (dataset/snapshot names, property + * lists, pool history messages) is far below this. + */ +#define KMEM_VASPRINTF_MAX 65536 + char * kmem_asprintf(const char *fmt, ...) { - int size; va_list adx; char *buf; va_start(adx, fmt); - size = zfs_vsnprintf(NULL, 0, fmt, adx) + 1; - va_end(adx); - - buf = kmem_alloc(size, KM_SLEEP); - - va_start(adx, fmt); - (void) zfs_vsnprintf(buf, size, fmt, adx); + buf = kmem_vasprintf(fmt, adx); va_end(adx); return (buf); @@ -6638,27 +6638,65 @@ kmem_asprintf(const char *fmt, ...) * Copyright (C) 2014 insane coder * (http://insanecoding.blogspot.com/, http://asprintf.insanecoding.org/) */ +/* + * Format into a newly allocated buffer. Callers free the result with + * kmem_strfree(), which computes the size as strlen(str) + 1, so the + * returned allocation must be exactly that size. + * + * This deliberately does NOT use the "measure with a NULL destination, then + * allocate that much" idiom. In kernel mode there is no linkable way to + * measure a format's true length without writing it (_vscprintf is declared + * by the WDK but not exported by the kernel-mode CRT, and _vsnprintf_s + * rejects count == 0), so any measuring helper must format into a bounded + * scratch buffer and therefore reports a *capped* length once the format + * exceeds it. Sizing an allocation from a capped length under-allocates, + * which used to drive this function into an error path that freed the buffer + * with a mismatched size and then returned the freed pointer to the caller - + * a use-after-free plus double-free that corrupted the shared kmem/vmem + * freelists and crashed unrelated subsystems later. + * + * Grow-and-retry instead: no measurement, the freed size always matches the + * allocated size, and the result is always a valid, null-terminated string. + */ char * kmem_vasprintf(const char *fmt, va_list ap) { - char *ptr; - int size; - int r = -1; - - size = zfs_vsnprintf(NULL, 0, fmt, ap); - if ((size >= 0) && (size < INT_MAX)) { - ptr = (char *)kmem_alloc(size + 1, KM_SLEEP); // +1 for null - if (ptr) { - r = zfs_vsnprintf(ptr, size + 1, fmt, ap); // +1 for null - if ((r < 0) || (r > size)) { - kmem_free(ptr, size); - r = -1; - } - } - } else { - ptr = 0; + char *scratch, *ptr; + size_t cap = 256; + size_t len; + + for (;;) { + va_list ap_copy; + int r; + + scratch = kmem_alloc(cap, KM_SLEEP); + + /* + * Every attempt must walk the argument list from the start, so + * never consume the caller's va_list directly. + */ + va_copy(ap_copy, ap); + r = zfs_vsnprintf(scratch, cap, fmt, ap_copy); + va_end(ap_copy); + + /* + * r >= 0 means the whole string fit (r excludes the + * terminator); r < 0 means it was truncated. Accept truncation + * once the ceiling is reached - the buffer is still valid and + * null-terminated, and callers here assume a non-NULL result. + */ + if (r >= 0 || cap >= KMEM_VASPRINTF_MAX) + break; + + kmem_free(scratch, cap); /* always the size allocated */ + cap *= 2; } + len = strlen(scratch); + ptr = kmem_alloc(len + 1, KM_SLEEP); + strlcpy(ptr, scratch, len + 1); + kmem_free(scratch, cap); + return (ptr); } diff --git a/module/os/windows/zfs/zfs_debug.c b/module/os/windows/zfs/zfs_debug.c index 59eb3f316333..ea4b2c282501 100644 --- a/module/os/windows/zfs/zfs_debug.c +++ b/module/os/windows/zfs/zfs_debug.c @@ -198,9 +198,9 @@ void __dprintf(boolean_t dprint, const char *file, const char *func, int line, const char *fmt, ...) { - int size, i; va_list adx; - char *buf, *nl; + char *buf, *body, *nl; + size_t alloc_len; char *prefix = (dprint) ? "dprintf: " : ""; const char *newfile; @@ -227,37 +227,29 @@ __dprintf(boolean_t dprint, const char *file, const char *func, newfile = file; } + /* + * Build the message with kmem_vasprintf()/kmem_asprintf() instead of + * measuring the format up front and hand-computing offsets into one + * buffer. The old code did the latter, which depended on a "measure + * without writing" call returning the true, unbounded length - + * something kernel mode cannot do here (see the comment on + * kmem_vasprintf()) - and which also told both of its writes that buf + * had one more byte than it really did. + */ va_start(adx, fmt); - size = zfs_vsnprintf(NULL, 0, fmt, adx); + body = kmem_vasprintf(fmt, adx); va_end(adx); - size += snprintf(NULL, 0, "%s%s:%d:%s(): ", prefix, newfile, line, - func); - - size++; /* null byte in the "buf" string */ - - /* - * There is one byte of string in sizeof (zfs_dbgmsg_t), used - * for the terminating null. - */ - buf = kmem_alloc(size, KM_SLEEP); - int roger = 0; + buf = kmem_asprintf("%s%s:%d:%s(): %s", prefix, newfile, line, func, + body); + kmem_strfree(body); - va_start(adx, fmt); - i = snprintf(buf, size + 1, "%s%s:%d:%s(): ", - prefix, newfile, line, func); /* - * buf has exactly `size` bytes total; `i` bytes are already used by - * the prefix, leaving `size - i` true remaining bytes at buf + i - * (not size - i + 1 - that overstates the real remaining capacity - * by one byte). This was harmless while zfs_vsnprintf's size==0 - * "measure" path could return an unbounded true length, but - * zfs_vscprintf now caps that measurement at a 1023-character - * scratch buffer, so a fmt+args needing >= 1024 characters would - * make this call write one byte past the end of buf. + * Record the allocation size now: the newline strip below edits the + * string in place, after which strlen() + 1 (what kmem_strfree() would + * compute) is a byte short of what was actually allocated. */ - roger = zfs_vsnprintf(buf + i, size - i, fmt, adx); - va_end(adx); + alloc_len = strlen(buf) + 1; /* * Get rid of trailing newline for dprintf logs. @@ -275,7 +267,7 @@ __dprintf(boolean_t dprint, const char *file, const char *func, /* Also emit string to log/console */ printBuffer("%s\n", buf); - kmem_free(buf, size); + kmem_free(buf, alloc_len); } #else From eff66bce7fe294a7267e1558be99f17f51b87897 Mon Sep 17 00:00:00 2001 From: Senthil <79847390+datacore-senthil@users.noreply.github.com> Date: Fri, 7 Aug 2026 19:02:57 +0530 Subject: [PATCH 2/2] Revert the __dprintf rewrite; keep only its off-by-one fixes (SSV-26896) The previous commit fixed a real use-after-free in kmem_vasprintf(), but also rewrote __dprintf() to build its message with kmem_vasprintf()/kmem_asprintf(). That second change was not required by the fix and should not have been bundled with it. __dprintf() is reachable from inside the kmem and vmem allocators themselves - spl-kmem.c calls dprintf() in 22 places and spl-vmem.c in 54, including from kmem_error() - so it must stay to a single bounded allocation. The rewrite turned one kmem_alloc/kmem_free pair into roughly six to eight allocator operations per debug message (two helper calls, each with a grow-and-retry loop and an exact-size copy), in the most reentrancy-sensitive path in the driver, in exchange for untruncated debug text. That is the wrong trade. __dprintf() is therefore reverted to its original single-allocation structure, keeping only the two genuine off-by-one corrections. The substantive delta against the long-shipping code is now three lines: - snprintf(buf, size + 1, ...) -> snprintf(buf, size, ...) - zfs_vsnprintf(buf + i, size - i + 1, ..) -> zfs_vsnprintf(buf + i, size - i, ..) - i = snprintf(...) -> i = (int)strlen(buf) buf holds exactly `size` bytes, so both writes now get the true remaining capacity rather than one byte more. The third change closes a latent hazard present in the original: on truncation _vsnprintf_s returns -1, and buf + (-1) is a wild pointer. A truncating write still null-terminates, so strlen() is always the real prefix length and always leaves size - i >= 1, with no branch and no failure mode. kmem_alloc(size)/kmem_free(buf, size) symmetry is restored. An alternative - making __dprintf allocation-free with a fixed stack buffer and a per-thread recursion guard - was considered and rejected: it is more new code in the same dangerous path, and it was motivated by a theory that does not hold up (below). __zfs_dbgmsg() still does kmem_zalloc, a pre-existing reentrancy that predates this work and is deliberately left alone. Theory withdrawn: an earlier analysis claimed this reentrancy caused the KMERR_BADCACHE crashes seen after the previous commit. That is not established. Reentrancy into the allocator produces deadlock, not a wrong-size free, and the original __dprintf allocated too without crashing. The rewrite is reverted because it was unjustified in a dangerous path, not because it was proven guilty. The cause of those crashes remains unidentified. kmem_vasprintf()/kmem_asprintf() are deliberately left exactly as committed previously - that fix is the one part of this work whose mechanism was traced end to end and is not in question. The zfs_vscprintf() comment in types.h previously stated a blanket prohibition on using its capped result to size an allocation. __dprintf legitimately does exactly that, so an absolute rule the code contradicts is worse than none. It now states the real rule: sizing an allocation from a capped measurement is safe if and only if every write into the buffer is bounded by the buffer's real size and the free passes the size that was allocated. __dprintf satisfies both; kmem_vasprintf violated both, which is why it corrupted the heap. Also adds contrib/windows/docs/ZFSin-kmem-corruption-investigation.md, a consolidated record of the whole investigation: every crash analysed, what was proven versus suspected, the hypotheses that were disproven (so they are not retried), the reference facts that were expensive to establish, and a WinDbg cookbook. --- .../ZFSin-kmem-corruption-investigation.md | 401 ++++++++++++++++++ include/os/windows/spl/sys/types.h | 28 +- module/os/windows/zfs/zfs_debug.c | 54 ++- 3 files changed, 457 insertions(+), 26 deletions(-) create mode 100644 contrib/windows/docs/ZFSin-kmem-corruption-investigation.md diff --git a/contrib/windows/docs/ZFSin-kmem-corruption-investigation.md b/contrib/windows/docs/ZFSin-kmem-corruption-investigation.md new file mode 100644 index 000000000000..5e29fd0b57aa --- /dev/null +++ b/contrib/windows/docs/ZFSin-kmem-corruption-investigation.md @@ -0,0 +1,401 @@ +# ZFSin kernel-heap corruption investigation (SSV-26770 / SSV-26896) + +**Status:** one root cause found and fixed (§5). An unnecessary rewrite bundled into that +same fix has been reverted (§6). **The cause of the latest crashes (F/G) is still +unidentified** — three hypotheses have already been wrong (§8), so the next step is +instrumentation, not another theory (§10). + +**Purpose of this document:** self-contained context recovery. It records what was +changed, every crash analysed, what was proven vs. merely suspected, which hypotheses +were **disproven** (so nobody re-treads them), and the reference facts that were +expensive to establish. Written 2026-08. + +--- + +## 1. Repos, branches, commits + +| Item | Value | +|---|---| +| ZFSin repo | `C:\Checkout\openzfscmd` → `origin` = `github.com/DataCoreSoftware/openzfs`, `upstream` = `openzfsonwindows/openzfs` | +| DataCore drivers repo | `C:\Checkout\datacore-sds-another\datacore-sds` | +| DSM/MPIO repo | `C:\Checkout\NewWik\wik` | +| Base branch | `rel-10psp22` | +| `79b7320ad` | Squash-merge of the SSV-26770 ZFSin CodeQL remediation (PR #113) onto `rel-10psp22`. Contains the four original commits `b8173063b`, `0fdfeb109`, `7c144d956`, `fdab61f86`. | +| **`SSV-26896-fix`** | Branch pushed to `origin`. Single commit **`c7a780d5a`** — the `kmem_vasprintf` fix (§5) plus the `__dprintf` rewrite (§6, **now known to be harmful**) plus a `types.h` warning comment. | +| Tested build | cbuf reports `zfs-0.8.0-2224-gc7a780d5a-dirty` — i.e. the crashing build **does** contain `c7a780d5a`, plus unidentified uncommitted local changes (`-dirty`). | + +Scoped CodeQL runner: `contrib/windows/codeql/Invoke-CodeQLZFSinAnalysis.ps1` +(builds only the `ZFSin` target to avoid dual-compilation noise; exit code = finding count). + +--- + +## 2. Background: what SSV-26770 changed + +A CodeQL `mustfix.qls` remediation took the ZFSin driver from 223 Must-Fix findings to 0. +Three change families: + +1. `ExAllocatePoolWithTag` → `ExAllocatePoolUninitialized` (~30 sites). +2. `strcpy`/`strncpy`/`strcat` → `strlcpy`/`strlcat`; `sprintf`/`sscanf`/`_snwprintf` in + Windows-only files → `RtlStringCb*`/`RtlStringCch*`. +3. **The root-cause change that matters here:** the Windows-only macros + `#define snprintf _snprintf` / `#define vsnprintf _vsnprintf` in + `include/os/windows/spl/sys/types.h` were replaced with wrappers + `zfs_snprintf`/`zfs_vsnprintf` built on `_vsnprintf_s(..., _TRUNCATE, ...)`, plus a + new `zfs_vscprintf()` for the "measure without writing" idiom. + +### 2.1 Critical fact: the allocator swaps in ZFSin are no-ops + +In WDK 10.0.19041.0 (`km/wdm.h` ~line 23363): + +```c +FORCEINLINE PVOID ExAllocatePoolUninitialized(PoolType, NumberOfBytes, Tag) +{ return ExAllocatePoolWithTag(PoolType, NumberOfBytes, Tag); } +``` + +So **every `ExAllocatePoolWithTag` → `ExAllocatePoolUninitialized` swap in ZFSin is +compile-time identical** — same code, same (non-)zeroing. These can be permanently +excluded as a cause of any ZFSin crash. + +**Do not confuse this with the DataCore repo**, where the change was +`ExAllocatePoolZero` → `ExAllocatePoolUninitialized` (commit `0b23a33fe`), which *did* +drop zeroing and required `RtlZeroMemory` to be restored (`eaa1e602b`). Different repo, +different change, real risk. + +### 2.2 The `zfs_vscprintf` hazard (the origin of everything in §5–§6) + +Kernel mode has **no linkable way to measure a format's length without writing it**: + +- `_vscprintf` — declared in the WDK headers but **not exported by the kernel-mode CRT + import library** (confirmed by an actual LNK2001 link failure). +- `_vsnprintf_s` — rejects `count == 0` (invokes the invalid-parameter handler). + +So `zfs_vscprintf()` measures by formatting into a bounded **1024-byte scratch buffer** +and returns `1023` for anything longer. The original code's `_vsnprintf(NULL, 0, ...)` +returned the **true, unbounded** length. + +**Consequence:** any `measure → allocate → write` sequence silently under-allocates for +long strings. The original in-code comment claimed this was harmless because "the later +write truncates identically" — **that reasoning is wrong** and directly caused §5. It has +been replaced with an explicit warning in `types.h`. + +--- + +## 3. Crash inventory + +All ZFSin unless noted. Build path is always `C:\BuildAgent\work\e347f52f66de7020\...`. + +| # | Signature | Where | Verdict | +|---|---|---|---| +| **A** | `nvlist_free` GP fault, `nvpair.c:881` (`curr = curr->nvi_next`). Node 27 of a 37-entry list had `nvi_next` = `0x656d616e74736f68` = ASCII **"hostname"**, `_nvi_hashtable_next` = **"Windows\0"**. Path: `dispatcher` → `ioctlDispatcher` → `zfsdev_ioctl` → `zfsdev_ioctl_common` → `nvlist_free(innvl)` (`zfs_ioctl.c` ~7858). `zpool.exe`, VMware. Pool had been destroyed/exported shortly before. | ZFSin | **Explained by §5** (multi-owner memory) | +| **B** | `CScsiPort::ScsiControl` AV writing to `0xb`; `pSrb` = `8`. PnP `_AddDevice` path. | **DcsSp** | **Root-caused, separate bug.** See §7 and `datacore-sds/Tools/Docs/DcsSp-BSOD-RCA-IOCTL_GET_PORT_INTERFACE.md` | +| **C** | `memcpy` AV reading NULL — `abd_copy_to_buf_off_cb` (`abd.c:829`). `zvol_os_write_zv` → `dmu_tx_check_ioerr` → `arc_read` → `zio_decompress_data`. `rdx` = exactly `-rcx`, so **src = NULL** (not overflow). Scatter ABD chunk pointer was NULL. HyperV, `ReplaceRaidDiskVerifyDataIntegrity`. | ZFSin | Consistent with §5 (clobbered ABD chunk array) | +| **D** | `vmem_hash_delete` panic "bad free" (`spl-vmem.c:796`, `vsp == NULL`). `txg_sync_thread` → `spa_sync` → `dsl_scan_sync` → `ddt_sync` → `ddt_object_destroy` → `arc_hdr_destroy` → `abd_free_struct_impl` → `vmem_xfree`. Garbage 6.4 MB size. | ZFSin | Consistent with §5 | +| **E** | **Driver Verifier.** `nvlist_free` → `nvp_buf_free` (`nvpair.c:884`) → `vmem_xfree` → `vmem_hash_delete` "bad free". **Same ioctl stack as A.** | ZFSin | **This dump led to finding §5** | +| **F** | `kmem_error` → `KMERR_BADCACHE`. `kmem_cache_reap` → `kmem_depot_ws_reap` → `kmem_magazine_destroy`. `kmem_panic_info`: `kmp_error=6`, `kmp_cache`=`kmem_alloc_256`, `kmp_realcache`=`kmem_alloc_384`, `kmp_bufctl=NULL`. Build confirmed to contain `c7a780d5a`. | ZFSin | **§6 — regression from the §5 fix** | +| **G** | Identical to F, reproducible. Buffer dump showed multi-owner contents (see §6.2). | ZFSin | Same as F | + +--- + +## 4. Ruling out the remediation, per crash + +For every crash, each file in the stack was checked against the four remediation commits: + +- **Crash A/E path:** `module/nvpair/nvpair.c` — **never touched**. `zfs_ioctl.c` — only + `zfs_get_parent()` (`strncpy`→`strlcpy`), a different function. `zfs_ioctl_os.c` — only + `zpool_zfs_get_metrics()`, a different function. +- `BufferUserBuffer()` in `zfs_vnops_windows.c` *was* rewritten by the remediation, but is + **not in this call path** — `zc`/`innvl` arrive via `kmem_zalloc` + `copyin()` + + `get_nvlist()`'s own `ddi_copyin`, not `BufferUserBuffer`. **Ruled out.** +- **Crash C/D paths:** `abd.c`, `abd_os.c`, `arc.c`, `dbuf.c`, `dnode.c`, `dmu_object.c`, + `ddt.c`, `dsl_scan.c`, `spa.c`, `txg.c`, `spl-vmem.c`, `zio_compress.c`, `dmu_tx.c`, + `zvol_os.c` — **none touched**. `zfs_windows_zvol_scsi.c` and `spl-taskq.c` *were* + touched but only in unrelated functions (`ScsiOpInquiry`; `taskq_create_common`'s + `tq_name`, not `taskq_thread`), plus no-op allocator swaps per §2.1. + +--- + +## 5. ROOT CAUSE (fixed): use-after-free + double-free in `kmem_vasprintf()` + +### 5.1 The defect + +`kmem_vasprintf()` used measure-then-allocate. Once `zfs_vsnprintf(NULL, 0, ...)` began +returning a **capped 1023** (§2.2), a previously **unreachable** error path became live for +any format producing ≥1024 characters: + +```c +size = zfs_vsnprintf(NULL, 0, fmt, ap); /* capped at 1023 */ +ptr = kmem_alloc(size + 1, KM_SLEEP); /* 1024 - too small */ +r = zfs_vsnprintf(ptr, size + 1, fmt, ap); /* returns -1 (truncated) */ +if ((r < 0) || (r > size)) { + kmem_free(ptr, size); /* 1023 vs allocated 1024 - mismatched size */ + r = -1; /* r is discarded; ptr NOT cleared */ +} +return (ptr); /* returns the FREED pointer */ +``` + +Before the remediation the measurement was exact, so the write always returned exactly +`size` and this branch was dead code. + +### 5.2 Why it was catastrophic + +`log_internal()` (`module/zfs/spa_history.c:536`): + +```c +msg = kmem_vasprintf(fmt, adx); +fnvlist_add_string(nvl, ZPOOL_HIST_INT_STR, msg); /* use-after-free READ */ +kmem_strfree(msg); /* DOUBLE FREE, garbage size */ +``` + +`kmem_strfree` computes `strlen(msg) + 1` on freed memory, so the second free uses an +arbitrary size. Reached from `spa_history_log_internal()`, which logs nearly every pool +operation — hence corruption surfacing later in unrelated subsystems (nvlist teardown, +ABD teardown), matching crashes A, C, D, E. + +### 5.3 The fix (in `c7a780d5a`, keep this) + +`kmem_vasprintf()` now grows a scratch buffer and retries the real write — no measurement +pass — then returns a copy allocated at **exactly `strlen + 1`**. `kmem_asprintf()` +delegates to it. + +**Hard invariant that constrains any future rewrite:** callers free these with +`kmem_strfree()`, which is `kmem_free(str, strlen(str) + 1)` +(`spl-kmem.c:6577`, and a macro at `zfs_context.h:694`). Returning the grown power-of-two +buffer directly would reintroduce mismatched frees at **all ~25 `kmem_asprintf` call +sites**. Hence the final exact-size copy. + +--- + +## 6. `__dprintf` — unnecessary rewrite, now REVERTED + +> **Theory withdrawn.** An earlier version of this document asserted that +> `__dprintf` reentrancy into the allocator *caused* crashes F/G. **That is not +> established.** Reentrancy produces deadlock, not `KMERR_BADCACHE`, and the +> original `__dprintf` also allocated (one `kmem_alloc`) without crashing. The +> claim was pattern-matching, not proof. The rewrite was reverted because it was +> unjustified scope creep in a dangerous path — not because it was proven guilty. +> **The actual cause of F/G remains unidentified; see §10.** + +### 6.1 Why the rewrite was wrong regardless + +Fixing §5 did not require touching `__dprintf` at all. The rewrite bought +untruncated debug messages — a cosmetic gain — at the cost of turning 1 +allocation into 6–8 in the most reentrancy-sensitive path in the driver: + +The same commit also rewrote `__dprintf()` to build its message with +`kmem_vasprintf()` + `kmem_asprintf()`. But: + +- `module/os/windows/spl/spl-kmem.c` calls `dprintf()` **22 times** +- `module/os/windows/spl/spl-vmem.c` calls `dprintf()` **54 times** +- `kmem_error()` itself calls `dprintf()` (lines 955, 965, 966, 970) + +**The allocator logs through the debug logger, and the debug logger was made to allocate.** + +| | kmem operations per debug message | +|---|---| +| Original `__dprintf` | 1 `kmem_alloc` + 1 `kmem_free` (formatting via non-allocating `snprintf`) | +| After `c7a780d5a` | `kmem_vasprintf` (alloc + grow loop + alloc + free) + `kmem_asprintf` (same again) + `kmem_strfree` + `kmem_free` ≈ **6–8 ops** | + +Any `dprintf` issued from inside `vmem_xalloc`, `kmem_slab_alloc`, or the magazine/depot +layer — frequently **while holding `vm_lock`/`cache_lock`** — now triggers 6–8 reentrant +allocator operations. ZFS's kmem/vmem is not reentrant on those paths. This is a direct +mechanism for freelist corruption, and it also means the diagnostics perturb the very heap +being diagnosed. + +### 6.2 Evidence (crash G buffer dump) + +One 384-byte buffer simultaneously contained: `"%recv\0"`, a GUID tail +`"21-5939-4cb4-b3bb-fb40a9530e43\0"`, a `dsl_scan` dbgmsg fragment +(`"nned dataset 45 (Z.a1b513f7-.../$ORIGIN) with min=3 max=1640; suspending=0"`), a +`metaslab_load` dbgmsg fragment, several kernel pointers, and `0xbaddcafe` +(`KMEM_UNINITIALIZED_PATTERN`) filler. **Four-plus distinct owners in one buffer.** + +Size arithmetic corroborates the dbgmsg path: + +``` +zfs_dbgmsg_t = zdm_node(16) + zdm_timestamp(8) + zdm_size(4) + zdm_msg[1] + → offsetof(zdm_msg) = 28, sizeof = 32 +__zfs_dbgmsg(): size = 32 + strlen(msg) + strlen ~220 → 252 → kmem_alloc_256 + strlen ~350 → 382 → kmem_alloc_384 ← exactly the two caches in KMERR_BADCACHE +``` + +**Why `BADCACHE` is a downstream symptom, not the origin:** `zdm_size` occupies offset +24–27, which in the dumped buffer holds ASCII `"0e43"`. Once a `zfs_dbgmsg_t` header is +overwritten, `zfs_dbgmsg_purge()` calls `kmem_free(zdm, )`, freeing to an +arbitrary wrong cache — precisely `KMERR_BADCACHE`. + +### 6.3 What was actually done: minimal revert + +`__dprintf` was reverted to its original **single-allocation** structure, keeping only +the two genuine off-by-one corrections. Substantive delta vs. the shipping code is now +three lines: + +| Was | Now | Why | +|---|---|---| +| `snprintf(buf, size + 1, ...)` | `snprintf(buf, size, ...)` | `buf` holds exactly `size` bytes | +| `zfs_vsnprintf(buf + i, size - i + 1, ...)` | `zfs_vsnprintf(buf + i, size - i, ...)` | ditto (found by external review) | +| `i = snprintf(...)` | `i = (int)strlen(buf)` | on truncation `_vsnprintf_s` returns **-1**, and `buf + (-1)` is a wild pointer. A truncating write still null-terminates, so `strlen` is always the true prefix length and always leaves `size - i >= 1`. Latent hazard in the original. | + +`kmem_alloc(size)` / `kmem_free(buf, size)` symmetry restored. + +**A rejected alternative, recorded so it is not retried:** making `__dprintf` +allocation-free with a fixed stack buffer plus a per-thread recursion guard. That is +*more* new code in the same dangerous path, justified by the theory withdrawn above. +Not warranted. Note `__zfs_dbgmsg()` still does `kmem_zalloc` — a pre-existing +reentrancy that predates the remediation and is deliberately left alone. + +### 6.4 The invariant that makes the capped measurement safe here + +`__dprintf` *does* size its allocation from `zfs_vscprintf`'s capped value, which is +fine because it satisfies both halves of the rule now documented in `types.h`: + +1. every write is bounded by the buffer's real size (not by the measured length), and +2. the free passes the same size that was allocated. + +A capped measurement then costs only truncated message text. §5 was unsafe precisely +because it violated both. + +--- + +## 7. Second confirmed root cause (different driver): DcsSp `IOCTL_GET_PORT_INTERFACE` + +Pre-existing, unrelated to the remediation. Full write-up: +`datacore-sds/Tools/Docs/DcsSp-BSOD-RCA-IOCTL_GET_PORT_INTERFACE.md`. + +Chain: `IRP_MJ_SCSI` and `IRP_MJ_INTERNAL_DEVICE_CONTROL` are **the same value `0x0f`** +(`km/wdm.h`), so `DcsSp`'s `IRP_MJ_SCSI` handler also receives internal IOCTLs. +`CDriverShim::GetScsiPortInterface()` sends the custom `IOCTL_GET_PORT_INTERFACE` with +`OutputBufferLength = sizeof(ppPort) = 8`. `CScsiPort::ScsiControl()` reads +`Parameters.Scsi.Srb`, which **aliases** `Parameters.DeviceIoControl.OutputBufferLength` in +the `IO_STACK_LOCATION` union → `pSrb = 8`, passes the `!pSrb` NULL check, then writes +`SrbStatus` at `[8+3] = 0xb`. + +`IOCTL_GET_PORT_INTERFACE` is referenced **nowhere** in `SpDriver`. Four sibling drivers +(`NVMeTCPDriver`, `iScsiServerDriver`, `iScsiManagerDriver`, `iScsiIsp4KDriver`) handle it +correctly via an `OnInternalIoctl()` override that checks `IoControlCode` first. +`CScsiPort` derives from `IScsiPort`, not `CFdo`, so it never joined that convention. +Also note `_AddDevice` probes both SCSI and FC devices because +`FILE_DEVICE_SCSI_PORT == FILE_DEVICE_FCP_PORT`. + +Environment correlate: the crashing VM had an **LSI Logic SAS** vSCSI controller +(`lsi_sas.sys` loaded). Not yet confirmed whether non-crashing VMs differ — but every +DataCore-fronted SCSI-port device is exposed, and it only fires on a PnP add/re-enumeration. + +--- + +## 8. Disproven / superseded hypotheses — do not re-tread + +| Hypothesis | Status | +|---|---| +| **`spa_add_feature_stats()` / `spa_feat_stats` missing-lock race** as the cause of crash A | **WRONG.** Superseded by §5. The file `contrib/windows/docs/ZFSin-BSOD-RCA-spa_feat_stats.md` (untracked) states this conclusion and **should be deleted**. `nvlist_add_nvlist` does a genuine deep copy via `nvlist_copy_embedded`, so there is no aliasing there. The unlocked `nvlist_free(spa->spa_feat_stats)` in `spa_remove()` (`spa_misc.c:825`) is still a real asymmetry worth fixing defensively, but it is not the cause. | +| `BufferUserBuffer()` (the `FsRtlAllocatePoolWithQuotaTag` rewrite) causing crash A | Ruled out — not in that call path (§4). | +| `zfs_dbgmsg_fini()` as the cause of `KMERR_BADCACHE` | Wrong — it only runs at driver unload, and its recomputed size matches in the normal case. It *is* a latent antipattern worth fixing (see §9). | +| Crash C being "pointer-arithmetic overflow" | Imprecise. `rdx` is exactly `-rcx`, so `[rcx+rdx]` is MSVC `memcpy`'s addressing idiom and the source pointer is a **clean NULL**, not a wrapped valid pointer. | +| An off-by-one free size producing `KMERR_BADCACHE` | Not possible — ZFS buckets caches, so 1023 and 1024 both resolve to `kmem_alloc_1024`. `BADCACHE` requires a **bucket-crossing** discrepancy. | +| ZFSin allocator swaps changing behaviour | Impossible, see §2.1. | + +--- + +## 9. Other real findings, not yet fixed + +1. **`zfs_dbgmsg_fini()`** (`zfs_debug.c:141`) recomputes the free size as + `sizeof(zfs_dbgmsg_t) + strlen(zdm->zdm_msg)` while `zfs_dbgmsg_purge()` (line 91) + correctly uses the stored `zdm->zdm_size`. Same "derive the free size from mutable + data" antipattern as §5. Fix defensively. +2. **`abd_alloc_chunks()`** (`abd_os.c:184-187`) stores `kmem_cache_alloc()` results into + `abd_chunks[i]` with **no NULL check**, although `abd_verify_scatter()` + (`abd_os.c:174-177`) asserts them non-NULL — and `ASSERT3P` compiles out in Release, so + the guard is inert in shipping builds. This is an unguarded path to crash C's symptom. +3. **`spa_remove()`** (`spa_misc.c:825`) frees `spa->spa_feat_stats` without + `spa_feat_stats_lock`, unlike every other access. Cheap defensive fix. +4. Other `kmem_free(p, strlen(p) + 1)` sites that would break if the string is ever + mutated: `spa_misc.c:1513`, `include/os/windows/spl/sys/sid.h:68`, + `module/icp/os/modhash.c:230,237,528`. + +--- + +## 10. Recommended next steps, in order + +1. **Stop theorising and instrument.** Three hypotheses have already been wrong (§8); + each costs a build/install/test cycle. Run a build with full kmem auditing. In + `spl-kmem.c`, `kmem_flags` is `KMF_LITE`; the full set is commented out one line above: + ```c + int kmem_flags = KMF_DEADBEEF | KMF_REDZONE | KMF_CONTENTS | KMF_AUDIT; + ``` + With `KMF_AUDIT`, `kmp_bufctl` is populated and `kmem_error()` dumps the **previous + transaction's thread and call stack for that exact buffer** — naming the offending + free directly instead of guessing across ~80 candidate sites. + + **Caveat, per the in-tree comment above that line: `KMF_AUDIT` never releases the + audit records, so the machine will eventually grind to a halt.** It is a + bounded-repro diagnostic only and must not ship. For that reason it lives on its own + throwaway branch (`SSV-26896-kmem-audit-diag`), never on `SSV-26896-fix`. + Note `kmem_flags` is inside `#ifdef DEBUG`, so the audit build must be a DEBUG build. +2. Establish what the `-dirty` in `zfs-0.8.0-2224-gc7a780d5a-dirty` was — the tested + binary contained uncommitted changes beyond `c7a780d5a`, which is a hole in the + evidence chain for every conclusion drawn from crashes F/G. +4. Re-run `Invoke-CodeQLZFSinAnalysis.ps1` after any fix to confirm still 0 Must-Fix. +5. Fix the §9 items. +6. Decide on the DcsSp fix (§7) — add an `IoControlCode` check in `PortScsiControl` + mirroring `CIsp4k::OnInternalIoctl()`. + +--- + +## 11. WinDbg cookbook (commands that actually paid off) + +``` +!analyze -v +.cxr ; !analyze resets scope afterwards - re-enter it +kb ; stack with args, after .cxr + +.sympath+ ; then: +.reload /f ZFSin.sys + +u L20 ; map registers to source vars via disassembly + ; (needed when private symbols are missing and + ; `dv` fails with "Private symbols required") + +dt ZFSin!kmem_panic_info ; THE command for any kmem_error panic: + ; kmp_error/buffer/realbuf/cache/realcache/slab/bufctl +dt ZFSin!kmem_cache_t cache_name cache_bufsize +db L180 ; buffer contents - identifies the owner(s) + +dt ZFSin!cbuf ; 1 MB circular debug log; contains the +s -a L100000 "bad free" ; software version string and dprintf output +.writemem C:\cbuf.txt L100000 + +; walk an nvlist's i_nvp_t chain when !list can't resolve the field offset +; (nvi_next is at offset 0, per the nvlist_free disassembly): +r $t0 = nvp_list> +r $t1 = 0 +.for (; @$t0 != 0; r $t1 = @$t1 + 1) { .printf "node %d: %p\n", @$t1, @$t0; r $t0 = poi(@$t0) } +``` + +Notes: +- `!list -t ZFSin!i_nvp_t.nvi_next -e ` fails (`GetFieldOffset failed`), and this + build's `!list` rejects a raw numeric offset — use the `.for` loop above. +- WinDbg's `&&` in a `.for` condition is a parse error; drop the compound condition. +- `kmem_error()` **re-derives** its error code (`spl-kmem.c:855`), overriding the value its + caller passed. `spl-kmem.c:976` is the common `DbgBreakPoint()` exit for all nine codes, + so the faulting line number tells you nothing about which check failed — always read + `kmem_panic_info`. +- Error codes: `MODIFIED 0, REDZONE 1, DUPFREE 2, BADADDR 3, BADBUFTAG 4, BADBUFCTL 5, + BADCACHE 6, BADSIZE 7, BADBASE 8`. +- Registers in `kmem_error`'s frame have consistently held: `rdx`/`rbp` = error code, + `rsi` = slab, `r12` = buffer, `rdi` = realcache. + +--- + +## 12. Process lessons + +- The `__dprintf` off-by-one and the `kmem_vasprintf` UAF were **the same bug class**: a + capped measurement turning a dormant latent bug into a live one. After an external + reviewer found the first instance, the other two consumers of the measurement path + (`kmem_asprintf`, `kmem_vasprintf`) were not audited. **When changing a shared + primitive's contract, enumerate and audit every consumer.** +- "Compiles clean + CodeQL clean + driver-scoped scan at 0 findings" validated nothing + about cross-function invariants. A full multi-target build later surfaced `LNK2001` + errors, and Driver Verifier surfaced the UAF. +- Several hypotheses in this investigation were confidently wrong (§8). Register-based + inference in particular proved unreliable until cross-checked against + `kmem_panic_info`. Prefer one decisive command over three plausible theories. diff --git a/include/os/windows/spl/sys/types.h b/include/os/windows/spl/sys/types.h index 2639f8b5acca..0071be4354af 100644 --- a/include/os/windows/spl/sys/types.h +++ b/include/os/windows/spl/sys/types.h @@ -127,14 +127,26 @@ typedef uintptr_t pc_t; * format+args longer than the scratch buffer it reports sizeof(scratch) - 1 * instead of the real length. * - * Consequently this must NEVER be used to size an allocation. Doing so - * silently under-allocates for long strings; kmem_vasprintf() used to do - * exactly that, which drove it into an error path that freed the buffer with - * a mismatched size and returned the freed pointer to its caller - a - * use-after-free plus double-free that corrupted the shared kmem/vmem - * freelists and crashed unrelated subsystems (nvlist and ABD teardown) much - * later. Callers that need a correctly sized buffer must grow-and-retry a - * real write instead; see kmem_vasprintf() in spl-kmem.c. + * Sizing an allocation from this value is only safe when BOTH of the + * following hold, in which case a capped measurement costs nothing but + * truncated text: + * + * 1. every write into the buffer is bounded by the buffer's real size + * (not by the measured length, and not by measured + 1), and + * 2. the eventual free passes the same size that was allocated. + * + * It is NOT safe for any caller that treats the measurement as exact. + * kmem_vasprintf() used to do that: it sized the buffer from the measured + * length, then treated the resulting short write as an error and, on that + * path, freed the buffer with the measured size (one less than allocated) + * and returned the freed pointer to its caller - a use-after-free plus + * double-free that corrupted the shared kmem/vmem freelists and crashed + * unrelated subsystems (nvlist and ABD teardown) much later. It now + * grows-and-retries a real write and never measures; see spl-kmem.c. + * + * __dprintf() in zfs_debug.c does size its allocation from this value, and + * is correct because it satisfies (1) and (2) above. It must keep doing so + * with a single allocation: it is called from inside the allocators. */ static inline int zfs_vscprintf(const char *fmt, va_list ap) diff --git a/module/os/windows/zfs/zfs_debug.c b/module/os/windows/zfs/zfs_debug.c index ea4b2c282501..baa3948e5a7d 100644 --- a/module/os/windows/zfs/zfs_debug.c +++ b/module/os/windows/zfs/zfs_debug.c @@ -198,9 +198,9 @@ void __dprintf(boolean_t dprint, const char *file, const char *func, int line, const char *fmt, ...) { + int size, i; va_list adx; - char *buf, *body, *nl; - size_t alloc_len; + char *buf, *nl; char *prefix = (dprint) ? "dprintf: " : ""; const char *newfile; @@ -228,28 +228,46 @@ __dprintf(boolean_t dprint, const char *file, const char *func, } /* - * Build the message with kmem_vasprintf()/kmem_asprintf() instead of - * measuring the format up front and hand-computing offsets into one - * buffer. The old code did the latter, which depended on a "measure - * without writing" call returning the true, unbounded length - - * something kernel mode cannot do here (see the comment on - * kmem_vasprintf()) - and which also told both of its writes that buf - * had one more byte than it really did. + * This logger is reachable from inside the kmem/vmem allocators + * themselves (spl-kmem.c and spl-vmem.c call dprintf() in many places, + * including kmem_error()). It must therefore stay to a single bounded + * allocation: no grow-and-retry, no helper that allocates more than + * once. Do not "improve" this into kmem_vasprintf()/kmem_asprintf(). + * + * zfs_vsnprintf()'s measuring path (size == 0) returns a length capped + * by zfs_vscprintf()'s scratch buffer, so a longer message is simply + * truncated below. That is safe because every write is bounded by the + * real remaining capacity, and the free uses the same `size` as the + * allocation - a capped measurement only ever costs message text. */ va_start(adx, fmt); - body = kmem_vasprintf(fmt, adx); + size = zfs_vsnprintf(NULL, 0, fmt, adx); va_end(adx); - buf = kmem_asprintf("%s%s:%d:%s(): %s", prefix, newfile, line, func, - body); - kmem_strfree(body); + size += snprintf(NULL, 0, "%s%s:%d:%s(): ", prefix, newfile, line, + func); + + size++; /* terminating null */ + + buf = kmem_alloc(size, KM_SLEEP); /* - * Record the allocation size now: the newline strip below edits the - * string in place, after which strlen() + 1 (what kmem_strfree() would - * compute) is a byte short of what was actually allocated. + * buf holds exactly `size` bytes, so both writes get the true + * remaining capacity. The previous code passed size + 1 here and + * size - i + 1 below, one byte more than existed in each case. + * + * i comes from strlen() rather than snprintf()'s return value: on + * truncation _vsnprintf_s returns -1, and buf + (-1) would be a wild + * pointer. After a truncating write the buffer is still + * null-terminated, so strlen() is always the real prefix length and + * always leaves size - i >= 1. */ - alloc_len = strlen(buf) + 1; + va_start(adx, fmt); + (void) snprintf(buf, size, "%s%s:%d:%s(): ", prefix, newfile, line, + func); + i = (int)strlen(buf); + (void) zfs_vsnprintf(buf + i, size - i, fmt, adx); + va_end(adx); /* * Get rid of trailing newline for dprintf logs. @@ -267,7 +285,7 @@ __dprintf(boolean_t dprint, const char *file, const char *func, /* Also emit string to log/console */ printBuffer("%s\n", buf); - kmem_free(buf, alloc_len); + kmem_free(buf, size); } #else