"internal error: out of memory" with parallel zpool import

[asomers]

System information

Type	Version/Name
Distribution Name	FreeBSD
Distribution Version	FreeBSD 14.1, with parallel zpool import backported
Kernel Version	14.1, with parallel zpool import backported
Architecture	amd64
OpenZFS Version	zfs-2.2.4-FreeBSD_g256659204 zfs-kmod-2.2.4-FreeBSD_g256659204

Describe the problem you're observing

When I try to import multiple large encrypted zpools, I sometimes see the error "internal error: out of memory" and some pools don't get imported.

Describe how to reproduce the problem

Create 4 zpools each composed of a number of 4-disk raidz2 groups, totalling about 200 disks. Use these options: zpool create -o autoreplace=on -O atime=off -O setuid=off -O checksum=fletcher4 -O secondarycache=metadata -o cachefile=/var/cache/zpool.cache -O encryption=aes-256-gcm -O keyformat=passphrase -O pbkdf2iters=100000.
Then import them with a command like this: yes <PASSWORD> | zpool import -al.

Include any warning/errors/backtraces from the system logs

None

Analysis

By patching the source, I've determined that the error message is incorrect. This bug has nothing to do with memory. The actual problem is that nvlist_unpack returns EOPNOTSUP from zcmd_read_dst_nvlist in a stack like this:

#0  thr_kill () at thr_kill.S:4
#1  0x00001660657c3404 in __raise (s=s@entry=6) at /usr/src/lib/libc/gen/raise.c:50
#2  0x00001660658769d9 in abort () at /usr/src/lib/libc/stdlib/abort.c:64
#3  0x000016606015ae84 in libzfs_error_description (hdl=0x5879c) at /usr/src/sys/contrib/openzfs/lib/libzfs/libzfs_util.c:92
#4  0x000016606015b08f in zfs_verror (hdl=<optimized out>, error=2000, fmt=<optimized out>, ap=ap@entry=0x16607d4342b0)
    at /usr/src/sys/contrib/openzfs/lib/libzfs/libzfs_util.c:358
#5  0x000016606015b006 in zfs_error_fmt (hdl=0x5879c, hdl@entry=0x32f7cc03e000, error=6, error@entry=2000, fmt=0x0)
    at /usr/src/sys/contrib/openzfs/lib/libzfs/libzfs_util.c:386
#6  0x000016606015c863 in zfs_error (hdl=0x32f7cc03e000, error=2000, msg=0x16606584a0ea <thr_self+10> "\017\202x\341\377\377\303", '\314' <repeats 14 times>, "̸\261\001")
    at /usr/src/sys/contrib/openzfs/lib/libzfs/libzfs_util.c:376
#7  no_memory (hdl=0x32f7cc03e000) at /usr/src/sys/contrib/openzfs/lib/libzfs/libzfs_util.c:788
#8  zcmd_read_dst_nvlist (hdl=hdl@entry=0x32f7cc03e000, zc=zc@entry=0x16607d434c60, nvlp=nvlp@entry=0x16607d434338)
    at /usr/src/sys/contrib/openzfs/lib/libzfs/libzfs_util.c:1255
#9  0x0000166060149981 in zpool_import_props (hdl=0x32f7cc03e000, config=config@entry=0x32f7cc1a6660, newname=newname@entry=0x0, props=<optimized out>, props@entry=0x32f7cc053000, 
    flags=flags@entry=64) at /usr/src/sys/contrib/openzfs/lib/libzfs/libzfs_pool.c:2160
#10 0x000016583d99c88b in do_import (config=0x32f7cc1a6660, newname=newname@entry=0x0, mntopts=0x0, props=0x32f7cc053000, flags=64, mntthreads=128)
    at /usr/src/sys/contrib/openzfs/cmd/zpool/zpool_main.c:3427
#11 0x000016583d99bdc3 in do_import_task (arg=0x32f7cc01a180) at /usr/src/sys/contrib/openzfs/cmd/zpool/zpool_main.c:3473
#12 0x00001660635400d3 in tpool_worker (arg=0x32f7cc01a180) at /usr/src/sys/contrib/openzfs/lib/libtpool/thread_pool.c:199
#13 0x000016606502bb05 in thread_start (curthread=0x32f7cc071400) at /usr/src/lib/libthr/thread/thr_create.c:289
#14 0x0000000000000000 in ?? ()
Backtrace stopped: Cannot access memory at address 0x16607d436000

My theory is that the packed nvlist returned by the kernel is getting corrupted somehow. I plan to continue debugging the problem.

[asomers]

Progress update:

• I've discovered that using the -o cachefile=/var/cache/zpool.cache is essential to triggering this bug
• The zpool command's nvlist_unpack function fails because the kernel never initialized the output nvlist in the first place. It's just a bunch of zeros.
• The ioctl syscall fails with EFAULT. But that error code isn't really appropriate, either.
• The real problem is that unpacking the input nvlist within the kernel fails because it's corrupted. Specifically, the /var/cache/zpool.cache contains one or more embedded NULs. The first one, if any, is always in the position of a /. I've seen variants that look like this:
  • /var\0cache/zpool.cache
  • /var/cache\0zpool.cache
  • /var\0cache\0\0\0\0\0\0'\0\0\0\0\0\0
  • /var\0cache\0\0\0\0\0\0\0\0\0\0\0\0\0

The stack trace at the point where the corruption is detected looks like this:

              zfs.ko`nvlist_common+0x17c
              zfs.ko`nvlist_xunpack+0xc5
              zfs.ko`get_nvlist+0xd1
              zfs.ko`zfsdev_ioctl_common+0x116
              zfs.ko`zfsdev_ioctl+0x147
              kernel`devfs_ioctl+0xcb
              kernel`VOP_IOCTL_APV+0x35
              kernel`vn_ioctl+0x1ce
              kernel`devfs_ioctl_f+0x1e
              kernel`kern_ioctl+0x255
              kernel`sys_ioctl+0xff
              kernel`amd64_syscall+0x67b
              kernel`0xffffffff80ffc55b

[asomers]

I've found the root cause. It's at

zfs/lib/libzfs/libzfs_pool.c

Line 798 in 8d4ad5a

*(char *)slash = '\0';

. This line modifies the cachefile property in the course of validating it, then changes it back to the original value. That logic worked fine when zpools were imported one at a time. But with parallel zpool imports, one thread could be validating the property while another thread is serializing the properties list. Another bug is that zpool_import_props frees the property list, even though other threads might be using it.

Commit d1807f1 introduced a few other const-removing casts, and those are all potential sources of similar bugs. They should be audited.

I'm currently testing a patch, and it's working so far.