Panic: Uninitialized Cond Var 'spl_free_thread_cv' used during Driver Initialize.

[datacore-rm]

Panic during driver install/initialize on a VM (with 32GB RAM). The new memory allocation failed in _vmemxalloc() for _spl_defaultarena. Then while trying to set the memory pressure, the condition variable _spl_free_threadcv was attempted to be used (which was not yet initialized) and this caused panic.

_vmem_init() => vmem_xalloc(spl_default_arena, size=1GB, align_arg=1GB, phase=0, nocross=0, minaddr=NULL, maxaddr=NULL, vmflag=VM_SLEEP) =>spl_free_set_pressure(0); //Similarly spl_free_set_and_wait_pressure() called next line also uses uninitialized mutex // spl_free_thread_lock =>cv_broadcast(&spl_free_thread_cv); =>panic("%s: not cvinitialised", func);

The _spl_free_threadcv is initialized later in the code flow. _spl_start()=>spl_kmem_thread_init()=>cv_init(&spl_free_threadcv)

3: kd> k
 # Child-SP          RetAddr           Call Site
00 ffff9603`64979018 fffff807`0923ee7c nt!KeBugCheckEx
01 ffff9603`64979020 fffff807`091ddc5f nt!PspSystemThreadStartup$filt$0+0x44
02 ffff9603`64979060 fffff807`0922a7df nt!_C_specific_handler+0x9f
03 ffff9603`649790d0 fffff807`0904fc31 nt!RtlpExecuteHandlerForException+0xf
04 ffff9603`64979100 fffff807`09054234 nt!RtlDispatchException+0x301
05 ffff9603`64979850 fffff807`0923498e nt!KiDispatchException+0x304
06 ffff9603`64979f30 fffff807`0922d451 nt!KiExceptionDispatch+0x10e
07 ffff9603`6497a110 fffff807`e4b89e11 nt!KiBreakpointTrap+0x311
08 ffff9603`6497a2a0 fffff807`e4b7d9f4 ZFSin!panic+0x21 [C:\BuildAgent\work\9f5ca3432854b81\module\os\windows\spl\spl-debug.c @ 33] 
09 ffff9603`6497a2d0 fffff807`e4b789e8 ZFSin!spl_cv_broadcast+0x24 [C:\BuildAgent\work\9f5ca3432854b81\module\os\windows\spl\spl-condvar.c @ 91] 
0a ffff9603`6497a300 fffff807`e4b7f36c ZFSin!spl_free_set_pressure+0x38 [C:\BuildAgent\work\9f5ca3432854b81\module\os\windows\spl\spl-kmem.c @ 4305] 
0b ffff9603`6497a330 fffff807`e4b822c7 ZFSin!vmem_xalloc+0xa7c [C:\BuildAgent\work\9f5ca3432854b81\module\os\windows\spl\spl-vmem.c @ 1633] 
0c ffff9603`6497a4a0 fffff807`e4b8a1d3 ZFSin!vmem_init+0x647 [C:\BuildAgent\work\9f5ca3432854b81\module\os\windows\spl\spl-vmem.c @ 3443] 
0d ffff9603`6497a580 fffff807`e4b78d3c ZFSin!kernelheap_init+0x33 [C:\BuildAgent\work\9f5ca3432854b81\module\os\windows\spl\spl-seg_kmem.c @ 166] 
0e ffff9603`6497a5c0 fffff807`e4b740ef ZFSin!spl_kmem_init+0x10c [C:\BuildAgent\work\9f5ca3432854b81\module\os\windows\spl\spl-kmem.c @ 5098] 
0f ffff9603`6497a640 fffff807`e4e66659 ZFSin!spl_start+0x24f [C:\BuildAgent\work\9f5ca3432854b81\module\os\windows\spl\spl-windows.c @ 524] 
10 ffff9603`6497a6f0 fffff807`e6294020 ZFSin!DriverEntry+0x29 [C:\BuildAgent\work\9f5ca3432854b81\module\os\windows\driver.c @ 119] 
11 ffff9603`6497a720 fffff807`09545020 ZFSin!GsDriverEntry+0x20 [minkernel\tools\gs_support\kmode\gs_support.c @ 117] 
12 ffff9603`6497a750 fffff807`09548870 nt!PnpCallDriverEntry+0x4c
13 ffff9603`6497a7b0 fffff807`0944cd37 nt!IopLoadDriver+0x8b4
14 ffff9603`6497a960 fffff807`090dbd01 nt!IopLoadUnloadDriver+0x57
15 ffff9603`6497a9a0 fffff807`09169f15 nt!ExpWorkerThread+0x161
16 ffff9603`6497abb0 fffff807`09224488 nt!PspSystemThreadStartup+0x55
17 ffff9603`6497ac00 00000000`00000000 nt!KiStartSystemThread+0x28

3: kd> .frame 0n11;dv /t /v
0b ffff9603`6497a330 fffff807`e4b822c7 ZFSin!vmem_xalloc+0xa7c [C:\BuildAgent\work\9f5ca3432854b81\module\os\windows\spl\spl-vmem.c @ 1633] 
<unavailable>     int64 target_pressure = <value unavailable>
<unavailable>     int64 delivered_pressure = <value unavailable>
@r12              struct vmem * vmp = 0xfffff807`e60c9f10
@r13              unsigned int64 size = 0x40000000
<unavailable>     unsigned int64 align_arg = <value unavailable>
ffff9603`6497a3b0 unsigned int64 phase = 0
ffff9603`6497a4c0 unsigned int64 nocross = 0
ffff9603`6497a4c8 void * minaddr = 0x00000000`00000000
ffff9603`6497a4d0 void * maxaddr = 0x00000000`00000000
ffff9603`6497a4d8 int vmflag = 0n0
<unavailable>     struct vmem_seg * vbest = <value unavailable>
<unavailable>     unsigned int64 align = <value unavailable>
ffff9603`6497a3d0 void * xvaddr = 0x00000000`00000000
<unavailable>     unsigned int mtbf = <value unavailable>
ffff9603`6497a3f8 unsigned int64 addr = 0
ffff9603`6497a408 unsigned int64 xsize = 0xfffff807`e50c8000
<unavailable>     int hb = <value unavailable>
<unavailable>     int flist = <value unavailable>
<unavailable>     struct vmem_seg * vsp = <value unavailable>
<unavailable>     unsigned int64 taddr = <value unavailable>
<unavailable>     unsigned int64 start = <value unavailable>
<unavailable>     unsigned int64 end = <value unavailable>
<unavailable>     int resv = <value unavailable>
<unavailable>     void * vaddr = <value unavailable>
<unavailable>     unsigned int64 aphase = <value unavailable>
<unavailable>     unsigned int64 aquantum = <value unavailable>
<unavailable>     unsigned int64 aneeded = <value unavailable>
<unavailable>     unsigned int64 asize = <value unavailable>

3: kd> dt zfsin!real_total_memory
0n34358632448

3: kd> dt zfsin!segkmem_total_mem_allocated
0

3: kd> dt zfsin!stat_osif_malloc_success
0

[EchterAgo]

Is this for the old port called ZFSin ? Seems like that would belong in https://github.com/openzfsonwindows/ZFSin , but I don't think that is actually still being developed, last commit was more than a year ago.

[andrewc12]

it's an error from their own repository and they still use the old name https://github.com/DataCoreSoftware/openzfs

[datacore-rm]

One option, the DriverEntry() routine can be failed with STATUS_INSUFFICIENT_RESOURCES if it cannot proceed without allocating the required resources. But then we have to also do the roll back part (of the already allocated resources)?

[lundman]

Hmm that is peculiar that spl_free_set_pressure() is called so very early, but if it already has waiters it looks like it can. We can just make spl_free_set_pressure() skip the

mutex_enter(&spl_free_thread_lock);
        cv_signal(&spl_free_thread_cv);
        mutex_exit(&spl_free_thread_lock);

part until it is up and running. Could start the free thread earlier, but I suspect that will be more complicated.

[datacore-rm]

If I understand correctly, we are thinking to do continuous retry till allocation succeeds? Then we also have to skip cv_wait(&vmp->vm_cv, &vmp->vm_lock); where the thread will otherwise infinitely wait.

e.g

if(spl free thread running)
{
    spl_free_set_pressure(0);
    spl_free_set_and_wait_pressure(...)
    cv_wait(&vmp->vm_cv, &vmp->vm_lock);
}

[lundman]

Oh are we looking at two problems perhaps? The panic above is relatively easy to fix, since it is setting that it wants pressure, then tries to wake the "free thread". The "free thread" is not running, so it panics. Skipping the wake up should be fine, as there is no thread, and when it is started, it will see the pressure.

During init there shouldn't really be any reason for alloc to fail (on 32G system) so that is curious. There was a bug with large (12G+) systems would crash, due to settings in abd_os.c - in particular, had to be KM_NOTOUCH.

[datacore-rm]

Thanks. I shall test this change.

This is a VM in Hyper-v. The configured RAM is dynamic (not reserved) and currently assigned is only ~2.5GB.

  Current:   5242880 Kb  Free Space:   5022708 Kb
  Minimum:   5242880 Kb  Maximum:     13025020 Kb

Physical Memory:           645874 (    2583496 Kb)
Available Pages:            63893 (     255572 Kb)
ResAvail Pages:            450296 (    1801184 Kb)
Locked IO Pages:                0 (          0 Kb)
Free System PTEs:      4295016119 (17180064476 Kb)```

[datacore-rm]

Thanks. One related query. In the above call stack, vmem_xalloc(spl_default_arena, size=1GB, align_arg=1GB, phase=0, nocross=0, minaddr=NULL, maxaddr=NULL, vmflag=VM_SLEEP) is called with allocation size=1GB. But as (align > aquantum), it actually tries to allocate (2*size-quantum=2GB-4k) !

[lundman]

Oh ah thanks for reminding me - rottegift sat down and cleaned up the init, to figure out why we needed NOTOUCH suddenly. I will add it.

https://github.com/openzfsonosx/openzfs-fork/commit/98ea04b2a4d22187e89f0e8e6d6ceaa7e3447151

[lundman]

9111a17

[lundman]

This is OK to close?

[datacore-rm]

yes, Thanks so much.