search

openzfsonosx / openzfs

OpenZFS on Linux and FreeBSD, and, macOS. This is where development for macOS happens.
https://github.com/openzfs/zfs/wiki
Other
145 stars 12 forks source link

panic: zpool_wait_trim_flag #12

Open lundman opened 4 years ago

lundman commented 4 years ago

There are some mutex locks being held for unusually long times.

Here is tail end of the test running:

2020-10-05 17:57:09.777 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff803bb2e5e0) held for 246s by '../../../zfs/spa.c':7283
2020-10-05 17:57:09.778 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff80402e1860) held for 118s by '../../../zfs/vdev_trim.c':475
2020-10-05 17:57:09.778 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff803838ce00) held for 246s by '../../../zfs/zil.c':2453
2020-10-05 17:57:19.348 Df kernel.development[0:3f6d0] (zfs) <zfs`spl_mutex_exit (spl-mutex.c:361)> SPL: mutex (0xffffff80402e1860) finally released after 128s by '../../../zfs/vdev_trim.c':475
2020-10-05 17:57:19.776 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff803bb2e5e0) held for 256s by '../../../zfs/spa.c':7283
2020-10-05 17:57:19.777 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff803838ce00) held for 256s by '../../../zfs/zil.c':2453
2020-10-05 17:57:29.776 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff803bb2e5e0) held for 266s by '../../../zfs/spa.c':7283
2020-10-05 17:57:29.776 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff803838ce00) held for 266s by '../../../zfs/zil.c':2453
2020-10-05 17:57:39.776 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff803bb2e5e0) held for 276s by '../../../zfs/spa.c':7283
2020-10-05 17:57:39.776 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff803838ce00) held for 276s by '../../../zfs/zil.c':2453
2020-10-05 17:57:49.774 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff803bb2e5e0) held for 286s by '../../../zfs/spa.c':7283
2020-10-05 17:57:49.775 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff803838ce00) held for 286s by '../../../zfs/zil.c':2453
2020-10-05 17:57:59.774 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff803bb2e5e0) held for 296s by '../../../zfs/spa.c':7283
2020-10-05 17:57:59.775 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff803838ce00) held for 296s by '../../../zfs/zil.c':2453
2020-10-05 17:58:09.773 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff803bb2e5e0) held for 306s by '../../../zfs/spa.c':7283
2020-10-05 17:58:09.774 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff803838ce00) held for 306s by '../../../zfs/zil.c':2453
2020-10-05 17:58:19.773 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff803bb2e5e0) held for 316s by '../../../zfs/spa.c':7283
2020-10-05 17:58:19.774 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff80402e1860) held for 60s by '../../../zfs/vdev_trim.c':475
2020-10-05 17:58:19.774 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff803838ce00) held for 316s by '../../../zfs/zil.c':2453
2020-10-05 17:58:29.773 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff803bb2e5e0) held for 326s by '../../../zfs/spa.c':7283
2020-10-05 17:58:29.774 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff80402e1860) held for 70s by '../../../zfs/vdev_trim.c':475
2020-10-05 17:58:29.774 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff803838ce00) held for 326s by '../../../zfs/zil.c':2453
2020-10-05 17:58:39.772 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff803bb2e5e0) held for 336s by '../../../zfs/spa.c':7283
2020-10-05 17:58:39.773 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff80402e1860) held for 80s by '../../../zfs/vdev_trim.c':475
2020-10-05 17:58:39.773 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff803838ce00) held for 336s by '../../../zfs/zil.c':2453
2020-10-05 17:58:49.772 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff803bb2e5e0) held for 346s by '../../../zfs/spa.c':7283
2020-10-05 17:58:49.772 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff80402e1860) held for 90s by '../../../zfs/vdev_trim.c':475
2020-10-05 17:58:49.772 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff803838ce00) held for 346s by '../../../zfs/zil.c':2453
2020-10-05 17:58:59.771 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff803bb2e5e0) held for 356s by '../../../zfs/spa.c':7283
2020-10-05 17:58:59.772 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff80402e1860) held for 100s by '../../../zfs/vdev_trim.c':475
2020-10-05 17:58:59.772 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff803838ce00) held for 356s by '../../../zfs/zil.c':2453
2020-10-05 17:59:09.771 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff803bb2e5e0) held for 366s by '../../../zfs/spa.c':7283
2020-10-05 17:59:09.772 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff80402e1860) held for 110s by '../../../zfs/vdev_trim.c':475
2020-10-05 17:59:09.772 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff803838ce00) held for 366s by '../../../zfs/zil.c':2453
2020-10-05 17:59:19.770 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff803bb2e5e0) held for 376s by '../../../zfs/spa.c':7283
2020-10-05 17:59:19.771 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff80402e1860) held for 120s by '../../../zfs/vdev_trim.c':475
2020-10-05 17:59:19.771 Df kernel.development[0:b9a] (zfs) <zfs`spl_wdlist_check (spl-mutex.c:97)> SPL: mutex (0xffffff803838ce00) held for 376s by '../../../zfs/zil.c':2453
2020-10-05 17:59:27.342 Df kernel.development[0:3f6d0] (zfs) <zfs`spl_mutex_exit (spl-mutex.c:361)> SPL: mutex (0xffffff80402e1860) finally released after 128s by '../../../zfs/vdev_trim.c':475
2020-10-05 17:59:27.345 Df kernel.development[0:3f641] (zfs) <zfs`__dprintf (zfs_debug.c:250)> spa_history.c:309:spa_history_log_sync(): txg 13 trim vdev=/var/tmp/testdir/file_vdev2 activated
2020-10-05 17:59:27.356 Df kernel.development[0:3f258] (zfs) <zfs`spl_mutex_exit (spl-mutex.c:361)> SPL: mutex (0xffffff803838ce00) finally released after 384s by '../../../zfs/zil.c':2453
client_loop: send disconnect: Broken pipe

Unfortunately, crashed without starting debugger.

lundman commented 4 years ago

stacks from earlier run, before crash:

Process:          zpool [95693]
UUID:             D1D56798-B95B-34C2-9219-8AC6EF7B1B0C
Path:             /Users/lundman/src/zfs/openzfs/cmd/zpool/.libs/zpool
Architecture:     x86_64
Parent:           ksh [95650]
Responsible:      sshd [437]
UID:              0
Footprint:        936 KB
Start time:       2020-10-05 17:30:09 -0700
End time:         2020-10-05 17:30:19 -0700
Num samples:      1000 (1-1000)

  Thread 0x3fd68    DispatchQueue 140735782950848    1000 samples (1-1000)    priority 31 (base 31)
  1000  start + 1 (libdyld.dylib + 109769) [0x7fff73bb6cc9]
    1000  main + 810 (zpool_main.c:10290,9 in zpool + 12922) [0x10425227a]
      1000  zpool_do_trim + 1473 (zpool_main.c:7162,14 in zpool + 43281) [0x104259911]
        1000  zpool_trim + 277 (libzfs_pool.c:2346,8 in libzfs.2.dylib + 157861) [0x1042b08a5]
          1000  lzc_trim + 141 (libzfs_core.c:1546,10 in libzfs_core.1.dylib + 15309) [0x1045ecbcd]
            1000  lzc_ioctl + 602 (libzfs_core.c:213,9 in libzfs_core.1.dylib + 4714) [0x1045ea26a]
              1000  zfs_ioctl_fd + 64 (zutil_compat.c:86,8 in libzfs_core.1.dylib + 42288) [0x1045f3530]
                1000  zcmd_ioctl_compat + 101 (zutil_compat.c:44,9 in libzfs_core.1.dylib + 42453) [0x1045f35d5]
                  1000  __ioctl + 10 (libsystem_kernel.dylib + 17246) [0x7fff73cfb35e]
                   *1000  hndl_unix_scall64 + 22 (kernel.development + 1663494) [0xffffff8000396206]
                     *1000  unix_syscall64 + 698 (kernel.development + 9580346) [0xffffff8000b22f3a]
                       *1000  ioctl + 1344 (kernel.development + 8321792) [0xffffff80009efb00]
                         *1000  fo_ioctl + 123 (kernel.development + 7911979) [0xffffff800098ba2b]
                           *1000  vn_ioctl + 478 (kernel.development + 5046574) [0xffffff80006d012e]
                             *1000  VNOP_IOCTL + 240 (kernel.development + 5107232) [0xffffff80006dee20]
                               *1000  spec_ioctl + 178 (kernel.development + 5155794) [0xffffff80006eabd2]
                                 *1000  zfsdev_ioctl + 275 (zfs_ioctl_os.c:233,10 in zfs + 1540083) [0xffffff7f831a7ff3]
                                   *1000  zfsdev_ioctl_common + 1029 (zfs_ioctl.c:7506,11 in zfs + 1484325) [0xffffff7f8319a625]
                                     *1000  zfs_ioc_pool_trim + 439 (zfs_ioctl.c:4059,21 in zfs + 1506855) [0xffffff7f8319fe27]
                                       *1000  spa_vdev_trim + 422 (spa.c:7305,2 in zfs + 909430) [0xffffff7f8310e076]
                                         *1000  txg_wait_synced + 39 (txg.c:715,2 in zfs + 1048103) [0xffffff7f8312fe27]
                                           *1000  txg_wait_synced_impl + 488 (txg.c:705,4 in zfs + 1049848) [0xffffff7f831304f8]
                                             *1000  spl_cv_wait + 130 (spl-condvar.c:100,11 in zfs + 3187122) [0xffffff7f8333a1b2]
                                               *1000  _sleep + 585 (kernel.development + 8192297) [0xffffff80009d0129]
                                                 *1000  lck_mtx_sleep + 109 (kernel.development + 2164189) [0xffffff80004105dd]
                                                   *1000  thread_block_reason + 287 (kernel.development + 2234143) [0xffffff800042171f]
                                                     *1000  thread_invoke + 1258 (kernel.development + 2240202) [0xffffff8000422eca]
                                                       *1000  machine_switch_context + 246 (kernel.development + 3587510) [0xffffff800056bdb6]
Process:          zpool [95699]
UUID:             D1D56798-B95B-34C2-9219-8AC6EF7B1B0C
Path:             /Users/lundman/src/zfs/openzfs/cmd/zpool/.libs/zpool
Architecture:     x86_64
Parent:           ksh [95650]
Responsible:      sshd [437]
UID:              0
Footprint:        932 KB
Start time:       2020-10-05 17:30:09 -0700
End time:         2020-10-05 17:30:19 -0700
Num samples:      1000 (1-1000)

  Thread 0x3fd78    DispatchQueue 140735782950848    1000 samples (1-1000)    priority 31 (base 31)
  1000  start + 1 (libdyld.dylib + 109769) [0x7fff73bb6cc9]
    1000  main + 810 (zpool_main.c:10290,9 in zpool + 12922) [0x10473127a]
      1000  zpool_do_trim + 1473 (zpool_main.c:7162,14 in zpool + 43281) [0x104738911]
        1000  zpool_trim + 584 (libzfs_pool.c:2370,12 in libzfs.2.dylib + 158168) [0x10478f9d8]
          1000  zpool_trim_wait + 87 (libzfs_pool.c:2255,9 in libzfs.2.dylib + 159591) [0x10478ff67]
            1000  lzc_wait_tag + 48 (libzfs_core.c:1601,10 in libzfs_core.1.dylib + 15744) [0x104ad1d80]
              1000  wait_common + 114 (libzfs_core.c:1579,14 in libzfs_core.1.dylib + 15618) [0x104ad1d02]
                1000  lzc_ioctl + 602 (libzfs_core.c:213,9 in libzfs_core.1.dylib + 4714) [0x104acf26a]
                  1000  zfs_ioctl_fd + 64 (zutil_compat.c:86,8 in libzfs_core.1.dylib + 42288) [0x104ad8530]
                    1000  zcmd_ioctl_compat + 101 (zutil_compat.c:44,9 in libzfs_core.1.dylib + 42453) [0x104ad85d5]
                      1000  __ioctl + 10 (libsystem_kernel.dylib + 17246) [0x7fff73cfb35e]
                       *1000  hndl_unix_scall64 + 22 (kernel.development + 1663494) [0xffffff8000396206]
                         *1000  unix_syscall64 + 698 (kernel.development + 9580346) [0xffffff8000b22f3a]
                           *1000  ioctl + 1344 (kernel.development + 8321792) [0xffffff80009efb00]
                             *1000  fo_ioctl + 123 (kernel.development + 7911979) [0xffffff800098ba2b]
                               *1000  vn_ioctl + 478 (kernel.development + 5046574) [0xffffff80006d012e]
                                 *1000  VNOP_IOCTL + 240 (kernel.development + 5107232) [0xffffff80006dee20]
                                   *1000  spec_ioctl + 178 (kernel.development + 5155794) [0xffffff80006eabd2]
                                     *1000  zfsdev_ioctl + 275 (zfs_ioctl_os.c:233,10 in zfs + 1540083) [0xffffff7f831a7ff3]
                                       *1000  zfsdev_ioctl_common + 1029 (zfs_ioctl.c:7506,11 in zfs + 1484325) [0xffffff7f8319a625]
                                         *1000  zfs_ioc_wait + 110 (zfs_ioctl.c:4111,11 in zfs + 1507070) [0xffffff7f8319fefe]
                                           *1000  spa_wait_tag + 48 (spa.c:9647,10 in zfs + 923392) [0xffffff7f83111700]
                                             *1000  spa_wait_common + 341 (spa.c:9625,7 in zfs + 923749) [0xffffff7f83111865]
                                               *1000  spl_cv_wait + 130 (spl-condvar.c:100,11 in zfs + 3187122) [0xffffff7f8333a1b2]
                                                 *1000  _sleep + 585 (kernel.development + 8192297) [0xffffff80009d0129]
                                                   *1000  lck_mtx_sleep + 109 (kernel.development + 2164189) [0xffffff80004105dd]
                                                     *1000  thread_block_reason + 287 (kernel.development + 2234143) [0xffffff800042171f]
                                                       *1000  thread_invoke + 1258 (kernel.development + 2240202) [0xffffff8000422eca]
                                                         *1000  machine_switch_context + 246 (kernel.development + 3587510) [0xffffff800056bdb6]

Process:          zpool [95806]
UUID:             D1D56798-B95B-34C2-9219-8AC6EF7B1B0C
Path:             /Users/lundman/src/zfs/openzfs/cmd/zpool/.libs/zpool
Architecture:     x86_64
Parent:           ksh [95650]
Responsible:      sshd [437]
UID:              0
Footprint:        820 KB
Start time:       2020-10-05 17:30:09 -0700
End time:         2020-10-05 17:30:19 -0700
Num samples:      1000 (1-1000)

  Thread 0x3fe54    DispatchQueue 140735782950848    1000 samples (1-1000)    priority 31 (base 31)
  1000  start + 1 (libdyld.dylib + 109769) [0x7fff73bb6cc9]
    1000  main + 810 (zpool_main.c:10290,9 in zpool + 12922) [0x10439d27a]
      1000  zpool_do_trim + 1149 (zpool_main.c:7137,24 in zpool + 42957) [0x1043a47cd]
        1000  zpool_open + 29 (libzfs_pool.c:1121,13 in libzfs.2.dylib + 144445) [0x1043fc43d]
          1000  zpool_open_canfail + 206 (libzfs_pool.c:1065,6 in libzfs.2.dylib + 143918) [0x1043fc22e]
            1000  zpool_refresh_stats + 275 (libzfs_config.c:282,7 in libzfs.2.dylib + 14099) [0x1043dc713]
              1000  zfs_ioctl + 39 (libzfs_util_os.c:53,10 in libzfs.2.dylib + 297751) [0x104421b17]
                1000  zfs_ioctl_fd + 64 (zutil_compat.c:86,8 in libzfs.2.dylib + 427760) [0x1044416f0]
                  1000  zcmd_ioctl_compat + 101 (zutil_compat.c:44,9 in libzfs.2.dylib + 427925) [0x104441795]
                    1000  __ioctl + 10 (libsystem_kernel.dylib + 17246) [0x7fff73cfb35e]
                     *1000  hndl_unix_scall64 + 22 (kernel.development + 1663494) [0xffffff8000396206]
                       *1000  unix_syscall64 + 698 (kernel.development + 9580346) [0xffffff8000b22f3a]
                         *1000  ioctl + 1344 (kernel.development + 8321792) [0xffffff80009efb00]
                           *1000  fo_ioctl + 123 (kernel.development + 7911979) [0xffffff800098ba2b]
                             *1000  vn_ioctl + 478 (kernel.development + 5046574) [0xffffff80006d012e]
                               *1000  VNOP_IOCTL + 240 (kernel.development + 5107232) [0xffffff80006dee20]
                                 *1000  spec_ioctl + 178 (kernel.development + 5155794) [0xffffff80006eabd2]
                                   *1000  zfsdev_ioctl + 275 (zfs_ioctl_os.c:233,10 in zfs + 1540083) [0xffffff7f831a7ff3]
                                     *1000  zfsdev_ioctl_common + 1385 (zfs_ioctl.c:7547,11 in zfs + 1484681) [0xffffff7f8319a789]
                                       *1000  zfs_ioc_pool_stats + 50 (zfs_ioctl.c:1612,10 in zfs + 1512770) [0xffffff7f831a1542]
                                         *1000  spa_get_stats + 92 (spa.c:5388,10 in zfs + 881996) [0xffffff7f8310754c]
                                           *1000  spa_open_common + 111 (spa.c:5050,3 in zfs + 880495) [0xffffff7f83106f6f]
                                             *1000  spl_mutex_enter + 171 (spl-mutex.c:327,5 in zfs + 3265467) [0xffffff7f8334d3bb]
                                               *1000  lck_mtx_lock_contended + 59 (kernel.development + 3568379) [0xffffff80005672fb]
                                                 *1000  lck_mtx_lock_wait_x86 + 365 (kernel.development + 3571085) [0xffffff8000567d8d]
                                                   *1000  thread_block_reason + 287 (kernel.development + 2234143) [0xffffff800042171f]
                                                     *1000  thread_invoke + 1258 (kernel.development + 2240202) [0xffffff8000422eca]
                                                       *1000  machine_switch_context + 246 (kernel.development + 3587510) [0xffffff800056bdb6] (blocked by turnstile waiting for zpool [95693] thread 0x3fd68)

  Thread 0x3fd89    1000 samples (1-1000)    priority 95 (base 95)    cpu time 9.984s
 *1000  call_continuation + 46 (kernel.development + 1659198) [0xffffff800039513e]
   *1000  vdev_trim_thread + 901 (vdev_trim.c:895,11 in zfs + 1263221) [0xffffff7f83164675]
     *1000  vdev_trim_ranges + 452 (vdev_trim.c:591,12 in zfs + 1270884) [0xffffff7f83166464]
       *344  vdev_trim_range + 155 (vdev_trim.c:483,7 in zfs + 1275227) [0xffffff7f8316755b]
         *145  vdev_trim_calculate_rate + 33 (vdev_trim.c:461,7 in zfs + 1276433) [0xffffff7f83167a11]
           *70   _rtc_nanotime_read + 12 (kernel.development + 1659068) [0xffffff80003950bc] (running)
           *29   gethrtime + 50 (spl-time.c:95,10 in zfs + 3291858) [0xffffff7f83353ad2]
             *11   zfs_abs_to_nano + 285 (spl-time.c:86,1 in zfs + 3292157) [0xffffff7f83353bfd] (running)
             *5    zfs_abs_to_nano + 59 (spl-time.c:65,3 in zfs + 3291931) [0xffffff7f83353b1b] (running)
             *5    zfs_abs_to_nano + 12 (spl-time.c:51,26 in zfs + 3291884) [0xffffff7f83353aec] (running)
             *4    zfs_abs_to_nano + 63 (spl-time.c:65,3 in zfs + 3291935) [0xffffff7f83353b1f] (running)
             *4    zfs_abs_to_nano + 43 (spl-time.c:64,26 in zfs + 3291915) [0xffffff7f83353b0b] (running)
           *10   _rtc_nanotime_read + 10 (kernel.development + 1659066) [0xffffff80003950ba] (running)
           *9    _rtc_nanotime_read + 34 (kernel.development + 1659090) [0xffffff80003950d2] (running)
           *5    _rtc_nanotime_read + 28 (kernel.development + 1659084) [0xffffff80003950cc] (running)
           *5    gethrtime + 35 (spl-time.c:95,26 in zfs + 3291843) [0xffffff7f83353ac3]
             *5    mach_absolute_time + 11 (kernel.development + 3606443) [0xffffff80005707ab] (running)
           *4    zfs_abs_to_nano + 1 (spl-time.c:41 in zfs + 3291873) [0xffffff7f83353ae1] (running)
           *3    _rtc_nanotime_read + 7 (kernel.development + 1659063) [0xffffff80003950b7] (running)
           *2    _rtc_nanotime_read + 39 (kernel.development + 1659095) [0xffffff80003950d7] (running)
           *2    _rtc_nanotime_read + 16 (kernel.development + 1659072) [0xffffff80003950c0] (running)
           *1    mach_absolute_time + 0 (kernel.development + 3606432) [0xffffff80005707a0] (running)
           *1    _rtc_nanotime_read + 43 (kernel.development + 1659099) [0xffffff80003950db] (running)
           *1    _rtc_nanotime_read + 25 (kernel.development + 1659081) [0xffffff80003950c9] (running)
           *1    _rtc_nanotime_read + 22 (kernel.development + 1659078) [0xffffff80003950c6] (running)
           *1    gethrtime + 30 (spl-time.c:95,26 in zfs + 3291838) [0xffffff7f83353abe] (running)
           *1    gethrtime + 4 (spl-time.c:93,12 in zfs + 3291812) [0xffffff7f83353aa4] (running)
         *91   vdev_trim_calculate_rate + 51 (vdev_trim.c:461,52 in zfs + 1276451) [0xffffff7f83167a23] (running)
         *86   vdev_trim_calculate_rate + 77 (vdev_trim.c:460,2 in zfs + 1276477) [0xffffff7f83167a3d] (running)
         *5    vdev_trim_calculate_rate + 55 (vdev_trim.c:461,52 in zfs + 1276455) [0xffffff7f83167a27] (running)
         *4    vdev_trim_calculate_rate + 74 (vdev_trim.c:460,37 in zfs + 1276474) [0xffffff7f83167a3a] (running)
         *4    vdev_trim_calculate_rate + 41 (vdev_trim.c:461,7 in zfs + 1276441) [0xffffff7f83167a19] (running)
         *3    vdev_trim_calculate_rate + 8 (vdev_trim.c:459 in zfs + 1276408) [0xffffff7f831679f8] (running)
         *2    vdev_trim_calculate_rate + 68 (vdev_trim.c:460,37 in zfs + 1276468) [0xffffff7f83167a34] (running)
         *2    vdev_trim_calculate_rate + 28 (vdev_trim.c:461,7 in zfs + 1276428) [0xffffff7f83167a0c] (running)
         *1    vdev_trim_calculate_rate + 43 (vdev_trim.c:461,7 in zfs + 1276443) [0xffffff7f83167a1b] (running)
         *1    vdev_trim_calculate_rate + 24 (vdev_trim.c:460,30 in zfs + 1276424) [0xffffff7f83167a08] (running)
       *270  vdev_trim_range + 222 (vdev_trim.c:484,4 in zfs + 1275294) [0xffffff7f8316759e]
         *141  zfs_lbolt + 17 (timer.h:40,2 in zfs + 1276513) [0xffffff7f83167a61]
           *62   _rtc_nanotime_read + 12 (kernel.development + 1659068) [0xffffff80003950bc] (running)
           *11   _rtc_nanotime_read + 10 (kernel.development + 1659066) [0xffffff80003950ba] (running)
           *10   microuptime + 62 (kernel.development + 8282286) [0xffffff80009e60ae] (running)
           *9    microuptime + 52 (kernel.development + 8282276) [0xffffff80009e60a4] (running)
           *7    _rtc_nanotime_read + 0 (kernel.development + 1659056) [0xffffff80003950b0] (running)
           *6    microuptime + 72 (kernel.development + 8282296) [0xffffff80009e60b8] (running)
           *6    microuptime + 41 (kernel.development + 8282265) [0xffffff80009e6099] (running)
           *4    _rtc_nanotime_read + 34 (kernel.development + 1659090) [0xffffff80003950d2] (running)
           *4    _rtc_nanotime_read + 22 (kernel.development + 1659078) [0xffffff80003950c6] (running)
           *3    microuptime + 66 (kernel.development + 8282290) [0xffffff80009e60b2] (running)
           *3    microuptime + 45 (kernel.development + 8282269) [0xffffff80009e609d] (running)
           *3    _rtc_nanotime_read + 39 (kernel.development + 1659095) [0xffffff80003950d7] (running)
           *3    _rtc_nanotime_read + 28 (kernel.development + 1659084) [0xffffff80003950cc] (running)
           *2    microuptime + 28 (kernel.development + 8282252) [0xffffff80009e608c] (running)
           *2    microuptime + 6 (kernel.development + 8282230) [0xffffff80009e6076] (running)
           *2    _rtc_nanotime_read + 43 (kernel.development + 1659099) [0xffffff80003950db] (running)
           *2    _rtc_nanotime_read + 25 (kernel.development + 1659081) [0xffffff80003950c9] (running)
           *1    microuptime + 55 (kernel.development + 8282279) [0xffffff80009e60a7] (running)
           *1    _rtc_nanotime_read + 16 (kernel.development + 1659072) [0xffffff80003950c0] (running)
         *87   zfs_lbolt + 47 (timer.h:41,11 in zfs + 1276543) [0xffffff7f83167a7f] (running)
         *16   zfs_lbolt + 55 (timer.h:42,2 in zfs + 1276551) [0xffffff7f83167a87] (running)
         *7    zfs_lbolt + 44 (timer.h:41,63 in zfs + 1276540) [0xffffff7f83167a7c] (running)
         *6    zfs_lbolt + 29 (timer.h:41,49 in zfs + 1276525) [0xffffff7f83167a6d] (running)
         *5    microuptime + 1 (kernel.development + 8282225) [0xffffff80009e6071] (running)
         *4    microuptime + 78 (kernel.development + 8282302) [0xffffff80009e60be] (running)
         *1    zfs_lbolt + 51 (timer.h:42,10 in zfs + 1276547) [0xffffff7f83167a83] (running)
         *1    zfs_lbolt + 32 (timer.h:41,63 in zfs + 1276528) [0xffffff7f83167a70] (running)
         *1    zfs_lbolt + 25 (timer.h:41,51 in zfs + 1276521) [0xffffff7f83167a69] (running)
         *1    zfs_lbolt + 8 (timer.h:40,2 in zfs + 1276504) [0xffffff7f83167a58] (running)
       *246  vdev_trim_range + 254 (vdev_trim.c:484,4 in zfs + 1275326) [0xffffff7f831675be]
         *212  spl_cv_timedwait + 71 (spl-condvar.c:130,20 in zfs + 3187271) [0xffffff7f8333a247]
           *123  zfs_lbolt + 17 (timer.h:40,2 in zfs + 3187633) [0xffffff7f8333a3b1]
             *60   _rtc_nanotime_read + 12 (kernel.development + 1659068) [0xffffff80003950bc] (running)
             *16   _rtc_nanotime_read + 10 (kernel.development + 1659066) [0xffffff80003950ba] (running)
             *11   microuptime + 62 (kernel.development + 8282286) [0xffffff80009e60ae] (running)
             *7    microuptime + 41 (kernel.development + 8282265) [0xffffff80009e6099] (running)
             *3    _rtc_nanotime_read + 39 (kernel.development + 1659095) [0xffffff80003950d7] (running)
             *3    _rtc_nanotime_read + 25 (kernel.development + 1659081) [0xffffff80003950c9] (running)
             *3    _rtc_nanotime_read + 22 (kernel.development + 1659078) [0xffffff80003950c6] (running)
             *3    _rtc_nanotime_read + 3 (kernel.development + 1659059) [0xffffff80003950b3] (running)
             *2    microuptime + 72 (kernel.development + 8282296) [0xffffff80009e60b8] (running)
             *2    microuptime + 52 (kernel.development + 8282276) [0xffffff80009e60a4] (running)
             *2    microuptime + 45 (kernel.development + 8282269) [0xffffff80009e609d] (running)
             *2    microuptime + 9 (kernel.development + 8282233) [0xffffff80009e6079] (running)
             *2    _rtc_nanotime_read + 28 (kernel.development + 1659084) [0xffffff80003950cc] (running)
             *2    _rtc_nanotime_read + 16 (kernel.development + 1659072) [0xffffff80003950c0] (running)
             *1    microuptime + 28 (kernel.development + 8282252) [0xffffff80009e608c] (running)
             *1    microuptime + 4 (kernel.development + 8282228) [0xffffff80009e6074] (running)
             *1    _rtc_nanotime_read + 43 (kernel.development + 1659099) [0xffffff80003950db] (running)
             *1    _rtc_nanotime_read + 34 (kernel.development + 1659090) [0xffffff80003950d2] (running)
             *1    _rtc_nanotime_read + 7 (kernel.development + 1659063) [0xffffff80003950b7] (running)
           *64   zfs_lbolt + 47 (timer.h:41,11 in zfs + 3187663) [0xffffff7f8333a3cf] (running)
           *12   zfs_lbolt + 55 (timer.h:42,2 in zfs + 3187671) [0xffffff7f8333a3d7] (running)
           *6    zfs_lbolt + 29 (timer.h:41,49 in zfs + 3187645) [0xffffff7f8333a3bd] (running)
           *3    zfs_lbolt + 44 (timer.h:41,63 in zfs + 3187660) [0xffffff7f8333a3cc] (running)
           *2    zfs_lbolt + 51 (timer.h:42,10 in zfs + 3187667) [0xffffff7f8333a3d3] (running)
           *2    zfs_lbolt + 12 (timer.h:40,2 in zfs + 3187628) [0xffffff7f8333a3ac] (running)
         *10   spl_cv_timedwait + 79 (spl-condvar.c:133,14 in zfs + 3187279) [0xffffff7f8333a24f] (running)
         *6    spl_cv_timedwait + 62 (spl-condvar.c:128,3 in zfs + 3187262) [0xffffff7f8333a23e] (running)
         *4    spl_cv_timedwait + 405 (spl-condvar.c:170,1 in zfs + 3187605) [0xffffff7f8333a395] (running)
         *4    spl_cv_timedwait + 89 (spl-condvar.c:134,3 in zfs + 3187289) [0xffffff7f8333a259] (running)
         *3    zfs_lbolt + 1 (timer.h:37 in zfs + 3187617) [0xffffff7f8333a3a1] (running)
         *2    spl_cv_timedwait + 42 (spl-condvar.c:127,21 in zfs + 3187242) [0xffffff7f8333a22a] (running)
         *2    spl_cv_timedwait + 23 (spl-condvar.c:123 in zfs + 3187223) [0xffffff7f8333a217] (running)
         *1    spl_cv_timedwait + 75 (spl-condvar.c:133,6 in zfs + 3187275) [0xffffff7f8333a24b] (running)
         *1    spl_cv_timedwait + 71 (spl-condvar.c:130,10 in zfs + 3187271) [0xffffff7f8333a247] (running)
         *1    spl_cv_timedwait + 8 (spl-condvar.c:123 in zfs + 3187208) [0xffffff7f8333a208] (running)
       *89   vdev_trim_range + 130 (vdev_trim.c:482,38 in zfs + 1275202) [0xffffff7f83167542]
         *56   vdev_trim_should_stop + 43 (vdev_trim.c:169,40 in zfs + 1276315) [0xffffff7f8316799b]
           *15   vdev_writeable + 70 (vdev.c:3945,6 in zfs + 1079046) [0xffffff7f83137706]
             *5    vdev_is_concrete + 41 (vdev.c in zfs + 1083785) [0xffffff7f83138989] (running)
             *4    vdev_is_concrete + 8 (vdev.c:4850 in zfs + 1083752) [0xffffff7f83138968] (running)
             *2    vdev_is_concrete + 58 (vdev.c in zfs + 1083802) [0xffffff7f8313899a] (running)
             *2    vdev_is_concrete + 27 (vdev.c:4851,14 in zfs + 1083771) [0xffffff7f8313897b] (running)
             *1    vdev_is_concrete + 114 (vdev.c:4858,1 in zfs + 1083858) [0xffffff7f831389d2] (running)
             *1    vdev_is_concrete + 23 (vdev.c:4851,24 in zfs + 1083767) [0xffffff7f83138977] (running)
           *13   vdev_writeable + 21 (vdev.c:3944,11 in zfs + 1078997) [0xffffff7f831376d5]
             *3    vdev_is_dead + 79 (vdev.c in zfs + 1092543) [0xffffff7f8313abbf] (running)
             *3    vdev_is_dead + 26 (vdev.c:3930,47 in zfs + 1092490) [0xffffff7f8313ab8a] (running)
             *3    vdev_is_dead + 12 (vdev.c:3930,10 in zfs + 1092476) [0xffffff7f8313ab7c] (running)
             *2    vdev_is_dead + 65 (vdev.c:3932,6 in zfs + 1092529) [0xffffff7f8313abb1] (running)
             *1    vdev_is_dead + 82 (vdev.c:3931,37 in zfs + 1092546) [0xffffff7f8313abc2] (running)
             *1    vdev_is_dead + 47 (vdev.c:3931,37 in zfs + 1092511) [0xffffff7f8313ab9f] (running)
           *4    vdev_is_dead + 1 (vdev.c:3922 in zfs + 1092465) [0xffffff7f8313ab71] (running)
           *4    vdev_writeable + 91 (vdev.c:3944,2 in zfs + 1079067) [0xffffff7f8313771b] (running)
           *4    vdev_writeable + 79 (vdev.c in zfs + 1079055) [0xffffff7f8313770f] (running)
           *4    vdev_writeable + 55 (vdev.c:3944,52 in zfs + 1079031) [0xffffff7f831376f7] (running)
           *4    vdev_writeable + 12 (vdev.c:3944,24 in zfs + 1078988) [0xffffff7f831376cc] (running)
           *2    vdev_writeable + 82 (vdev.c:3944,52 in zfs + 1079058) [0xffffff7f83137712] (running)
           *2    vdev_writeable + 39 (vdev.c in zfs + 1079015) [0xffffff7f831376e7] (running)
           *2    vdev_writeable + 25 (vdev.c:3944,11 in zfs + 1079001) [0xffffff7f831376d9] (running)
           *1    vdev_is_concrete + 0 (vdev.c:4850 in zfs + 1083744) [0xffffff7f83138960] (running)
           *1    vdev_writeable + 87 (vdev.c:3944,2 in zfs + 1079063) [0xffffff7f83137717] (running)
         *9    vdev_trim_should_stop + 104 (vdev_trim.c:170,24 in zfs + 1276376) [0xffffff7f831679d8] (running)
         *3    vdev_trim_should_stop + 109 (vdev_trim.c:169,2 in zfs + 1276381) [0xffffff7f831679dd] (running)
         *3    vdev_trim_should_stop + 61 (vdev_trim.c:170,6 in zfs + 1276333) [0xffffff7f831679ad] (running)
         *2    vdev_trim_should_stop + 98 (vdev_trim.c:170,24 in zfs + 1276370) [0xffffff7f831679d2] (running)
         *2    vdev_trim_should_stop + 95 (vdev_trim.c:170,24 in zfs + 1276367) [0xffffff7f831679cf] (running)
         *2    vdev_trim_should_stop + 79 (vdev_trim.c:170,27 in zfs + 1276351) [0xffffff7f831679bf] (running)
         *2    vdev_trim_should_stop + 46 (vdev_trim.c:169,59 in zfs + 1276318) [0xffffff7f8316799e] (running)
         *2    vdev_trim_should_stop + 34 (vdev_trim.c:169,55 in zfs + 1276306) [0xffffff7f83167992] (running)
         *2    vdev_trim_should_stop + 16 (vdev_trim.c:169,10 in zfs + 1276288) [0xffffff7f83167980] (running)
         *1    vdev_trim_should_stop + 106 (vdev_trim.c:170,24 in zfs + 1276378) [0xffffff7f831679da] (running)
         *1    vdev_trim_should_stop + 68 (vdev_trim.c:170,24 in zfs + 1276340) [0xffffff7f831679b4] (running)
         *1    vdev_trim_should_stop + 38 (vdev_trim.c:169,40 in zfs + 1276310) [0xffffff7f83167996] (running)
         *1    vdev_trim_should_stop + 23 (vdev_trim.c:169,36 in zfs + 1276295) [0xffffff7f83167987] (running)
         *1    vdev_trim_should_stop + 4 (vdev_trim.c:168 in zfs + 1276276) [0xffffff7f83167974] (running)
         *1    vdev_writeable + 1 (vdev.c:3943 in zfs + 1078977) [0xffffff7f831376c1] (running)
       *15   vdev_trim_range + 175 (vdev_trim.c:482,3 in zfs + 1275247) [0xffffff7f8316756f] (running)
       *6    spl_cv_timedwait + 0 (spl-condvar.c:123 in zfs + 3187200) [0xffffff7f8333a200] (running)
       *5    vdev_trim_range + 169 (vdev_trim.c:483,36 in zfs + 1275241) [0xffffff7f83167569] (running)
       *3    vdev_trim_range + 172 (vdev_trim.c in zfs + 1275244) [0xffffff7f8316756c] (running)
       *3    vdev_trim_range + 140 (vdev_trim.c:482,64 in zfs + 1275212) [0xffffff7f8316754c] (running)
       *3    vdev_trim_range + 104 (vdev_trim.c:482,29 in zfs + 1275176) [0xffffff7f83167528] (running)
       *2    vdev_trim_calculate_rate + 82 (vdev_trim.c:460,2 in zfs + 1276482) [0xffffff7f83167a42] (running)
       *2    vdev_trim_calculate_rate + 0 (vdev_trim.c:459 in zfs + 1276400) [0xffffff7f831679f0] (running)
       *2    vdev_trim_range + 237 (vdev_trim.c:484,4 in zfs + 1275309) [0xffffff7f831675ad] (running)
       *2    vdev_trim_range + 222 (vdev_trim.c:484,4 in zfs + 1275294) [0xffffff7f8316759e] (running)
       *2    vdev_trim_range + 188 (vdev_trim.c:484,4 in zfs + 1275260) [0xffffff7f8316757c] (running)
       *2    vdev_trim_range + 130 (vdev_trim.c:482,38 in zfs + 1275202) [0xffffff7f83167542] (running)
       *1    zfs_lbolt + 0 (timer.h:37 in zfs + 1276496) [0xffffff7f83167a50] (running)
       *1    vdev_trim_range + 257 (vdev_trim.c:482,3 in zfs + 1275329) [0xffffff7f831675c1] (running)
       *1    vdev_trim_range + 209 (vdev_trim.c:484,4 in zfs + 1275281) [0xffffff7f83167591] (running)
       *1    vdev_trim_range + 125 (vdev_trim.c:482,38 in zfs + 1275197) [0xffffff7f8316753d] (running)
  Thread 0x3fd8b    1000 samples (1-1000)    priority 95 (base 95)
 *1000  call_continuation + 46 (kernel.development + 1659198) [0xffffff800039513e]
   *1000  vdev_trim_thread + 67 (vdev_trim.c:830,2 in zfs + 1262387) [0xffffff7f83164333]
     *1000  txg_wait_synced + 39 (txg.c:715,2 in zfs + 1048103) [0xffffff7f8312fe27]
       *1000  txg_wait_synced_impl + 488 (txg.c:705,4 in zfs + 1049848) [0xffffff7f831304f8]
         *1000  spl_cv_wait + 130 (spl-condvar.c:100,11 in zfs + 3187122) [0xffffff7f8333a1b2]
           *1000  _sleep + 585 (kernel.development + 8192297) [0xffffff80009d0129]
             *1000  lck_mtx_sleep + 109 (kernel.development + 2164189) [0xffffff80004105dd]
               *1000  thread_block_reason + 287 (kernel.development + 2234143) [0xffffff800042171f]
                 *1000  thread_invoke + 1258 (kernel.development + 2240202) [0xffffff8000422eca]
                   *1000  machine_switch_context + 246 (kernel.development + 3587510) [0xffffff800056bdb6]

  Thread 0x3fd8c    1000 samples (1-1000)    priority 95 (base 95)
 *1000  call_continuation + 46 (kernel.development + 1659198) [0xffffff800039513e]
   *1000  vdev_trim_thread + 67 (vdev_trim.c:830,2 in zfs + 1262387) [0xffffff7f83164333]
     *1000  txg_wait_synced + 39 (txg.c:715,2 in zfs + 1048103) [0xffffff7f8312fe27]
       *1000  txg_wait_synced_impl + 488 (txg.c:705,4 in zfs + 1049848) [0xffffff7f831304f8]
         *1000  spl_cv_wait + 130 (spl-condvar.c:100,11 in zfs + 3187122) [0xffffff7f8333a1b2]
           *1000  _sleep + 585 (kernel.development + 8192297) [0xffffff80009d0129]
             *1000  lck_mtx_sleep + 109 (kernel.development + 2164189) [0xffffff80004105dd]
               *1000  thread_block_reason + 287 (kernel.development + 2234143) [0xffffff800042171f]
                 *1000  thread_invoke + 1258 (kernel.development + 2240202) [0xffffff8000422eca]
                   *1000  machine_switch_context + 246 (kernel.development + 3587510) [0xffffff800056bdb6]

  Thread 0x3ff2a    1000 samples (1-1000)    priority 81 (base 81)    cpu time <0.001s
 *1000  call_continuation + 46 (kernel.development + 1659198) [0xffffff800039513e]
   *1000  tx_flush_thread + 619 (apfs + 913707) [0xffffff7f81a1312b]
     *1000  _sleep + 223 (kernel.development + 8191935) [0xffffff80009cffbf]
       *1000  lck_mtx_sleep_deadline + 112 (kernel.development + 2164720) [0xffffff80004107f0]
         *1000  thread_block_reason + 287 (kernel.development + 2234143) [0xffffff800042171f]
           *1000  thread_invoke + 1258 (kernel.development + 2240202) [0xffffff8000422eca]
             *1000  machine_switch_context + 246 (kernel.development + 3587510) [0xffffff800056bdb6]