www.fabiankeil.de/gehacktes/electrobsd/zfs-arc-tuning/
ElectroBSD is commonly used on systems with 2 GB of RAM or less, it therefore uses the ZFS ARC patch written by Karl Denninger for FreeBSD to let the Adaptive Replacement Cache (ARC) actually adapt its size when the memory is needed elsewhere.
The Munin graphs below confirm that the patch has the intended effect, the system only starts paging after the ZFS ARC size is close to the minimum (in this case 300 MB):
What the graphs don't show is that the monitored system still behaved unsatisfactory while under memory pressure. Running "git checkout" or "git rebase" in /usr/ports while using Emacs, Claws-Mail and Firefox with a couple of open tabs was not a pleasant experience, especially if the ARC was still cold. Applications would frequently become unresponsive for a couple of seconds, despite not having an excuse like being partly paged out or waiting for data from the (busy) disk.
Obviously unresponsive applications are annoying, thus DTrace was used to track down the cause of the issue.
Stack fishing (not shown due to incomplete notes) indicated that memory pressure resulted in a surprising amount of stacks that included reap_arc_caches(). Investigating this lead further:
fk@r500 ~ $sudo ~/scripts/arc-reap-stats.d [...] 2015 Sep 3 16:55:36: reap_arc_caches() calls: ~5 arc_adjust 1 reap_arc_caches 5 reap_arc_caches entry 5 reap_arc_caches return 5 2015 Sep 3 16:55:37: reap_arc_caches() calls: ~12 arc_adjust 1 reap_arc_caches 12 reap_arc_caches entry 12 reap_arc_caches return 12 2015 Sep 3 16:55:42: reap_arc_caches() calls: ~59 arc_adjust 76 reap_arc_caches 119 reap_arc_caches entry 119 reap_arc_caches return 119 2015 Sep 3 16:55:43: reap_arc_caches() calls: ~1691 arc_adjust 1565 reap_arc_caches 1724 reap_arc_caches entry 1724 reap_arc_caches return 1724 2015 Sep 3 16:55:44: reap_arc_caches() calls: ~475 arc_adjust 347 reap_arc_caches 394 reap_arc_caches entry 394 reap_arc_caches return 394 2015 Sep 3 16:55:45: reap_arc_caches() calls: ~19 arc_adjust 1 reap_arc_caches 18 reap_arc_caches entry 18 reap_arc_caches return 18
The effect of all this ARC reaping was high latency for ZFS operations that use arc_get_data_buf(), which would frequently block while the ARC caches were being reaped. Sampling stacks that lead to arc_get_data_buf() showed that lots of ZFS operations rely on it, including various syscalls that can directly impact application latency:
arc_get_data_buf (skip to last stack)
zfs.ko`dnode_next_offset_level+0x227
zfs.ko`dnode_next_offset+0x262
zfs.ko`dmu_object_next+0x83
zfs.ko`dmu_object_alloc+0x20e
zfs.ko`zfs_mknode+0x38f
zfs.ko`zfs_create+0xab2
zfs.ko`zfs_freebsd_create+0x8b
kernel`VOP_CREATE_APV+0xa1
kernel`vn_open_cred+0x288
kernel`kern_openat+0x257
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
1
arc_get_data_buf
zfs.ko`arc_read+0x9e4
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dnode_next_offset_level+0x227
zfs.ko`dnode_next_offset+0x1e0
zfs.ko`dmu_object_next+0x83
zfs.ko`dmu_object_alloc+0x20e
zfs.ko`zfs_mknode+0x38f
zfs.ko`zfs_create+0xab2
zfs.ko`zfs_freebsd_create+0x8b
kernel`VOP_CREATE_APV+0xa1
kernel`vn_open_cred+0x288
kernel`kern_openat+0x257
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
1
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`arc_read+0x6b3
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dbuf_findbp+0x2a4
zfs.ko`dbuf_hold_impl+0x124
zfs.ko`dbuf_hold_level+0x59
zfs.ko`dbuf_hold+0x2c
zfs.ko`dmu_buf_hold_array_by_dnode+0x30b
zfs.ko`dmu_read+0x197
zfs.ko`zfs_getpages+0x6c8
zfs.ko`zfs_freebsd_getpages+0x2f
kernel`VOP_GETPAGES_APV+0xa7
kernel`vnode_pager_getpages+0xb8
kernel`vm_pager_get_pages+0x1f
kernel`vm_fault_hold+0xbe4
kernel`vm_fault+0x78
kernel`trap_pfault+0x223
kernel`trap+0x4f0
kernel`0xffffffff8084884a
2
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`arc_read+0x6b3
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_hold+0x96
zfs.ko`zap_lockdir+0x73
zfs.ko`zap_remove_norm+0x62
zfs.ko`zap_remove+0x34
zfs.ko`zfs_dropname+0x114
zfs.ko`zfs_link_destroy+0x234
zfs.ko`zfs_remove+0x882
zfs.ko`zfs_freebsd_remove+0x47
kernel`VOP_REMOVE_APV+0xa7
kernel`kern_unlinkat+0x208
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
2
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`arc_read+0x6b3
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_hold+0x96
zfs.ko`zap_lockdir+0x73
zfs.ko`zap_lookup_norm+0xa9
zfs.ko`zap_lookup+0x6d
zfs.ko`zfs_match_find+0x1ad
zfs.ko`zfs_dirent_lock+0xa71
zfs.ko`zfs_remove+0x1d6
zfs.ko`zfs_freebsd_remove+0x47
kernel`VOP_REMOVE_APV+0xa7
kernel`kern_unlinkat+0x208
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
2
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`arc_read+0x6b3
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_hold+0x96
zfs.ko`zap_lockdir+0x73
zfs.ko`zap_lookup_norm+0xa9
zfs.ko`zap_lookup+0x6d
zfs.ko`zfs_match_find+0x1ad
zfs.ko`zfs_dirent_lock+0xa71
zfs.ko`zfs_dirlook+0x44e
zfs.ko`zfs_lookup+0x7ef
zfs.ko`zfs_freebsd_lookup+0x10f
kernel`VOP_CACHEDLOOKUP_APV+0xa1
kernel`vfs_cache_lookup+0xd6
kernel`VOP_LOOKUP_APV+0xa1
kernel`lookup+0x5a5
kernel`namei+0x584
kernel`kern_statat+0xab
kernel`sys_lstat+0x30
2
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`arc_read+0x6b3
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_hold+0x96
zfs.ko`zap_lockdir+0x73
zfs.ko`zap_lookup_norm+0xa9
zfs.ko`zap_lookup+0x6d
zfs.ko`zfs_match_find+0x1ad
zfs.ko`zfs_dirent_lock+0xa71
zfs.ko`zfs_dirlook+0x44e
zfs.ko`zfs_lookup+0x7ef
zfs.ko`zfs_freebsd_lookup+0x10f
kernel`VOP_CACHEDLOOKUP_APV+0xa1
kernel`vfs_cache_lookup+0xd6
kernel`VOP_LOOKUP_APV+0xa1
kernel`lookup+0x5a5
kernel`namei+0x584
kernel`kern_unlinkat+0xa1
kernel`amd64_syscall+0x4eb
2
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`arc_read+0x6b3
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_tx_check_ioerr+0x134
zfs.ko`dmu_tx_hold_zap+0xef
zfs.ko`zfs_remove+0x498
zfs.ko`zfs_freebsd_remove+0x47
kernel`VOP_REMOVE_APV+0xa7
kernel`kern_unlinkat+0x208
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
2
arc_get_data_buf
zfs.ko`arc_read+0x9e4
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dbuf_findbp+0x2a4
zfs.ko`dbuf_hold_impl+0x124
zfs.ko`dbuf_hold_level+0x59
zfs.ko`dbuf_hold+0x2c
zfs.ko`dnode_hold_impl+0x396
zfs.ko`dnode_hold+0x3a
zfs.ko`dmu_tx_hold_object_impl+0x60
zfs.ko`dmu_tx_hold_zap+0x44
zfs.ko`dmu_tx_hold_sa_create+0xab
zfs.ko`zfs_create+0x8b3
zfs.ko`zfs_freebsd_create+0x8b
kernel`VOP_CREATE_APV+0xa1
kernel`vn_open_cred+0x288
kernel`kern_openat+0x257
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
2
arc_get_data_buf
zfs.ko`arc_read+0x9e4
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dbuf_findbp+0x2a4
zfs.ko`dbuf_hold_impl+0x124
zfs.ko`dbuf_hold_level+0x59
zfs.ko`dbuf_hold+0x2c
zfs.ko`dmu_buf_hold_noread+0x9f
zfs.ko`dmu_buf_hold+0x63
zfs.ko`zap_lockdir+0x73
zfs.ko`zap_cursor_retrieve+0xf5
zfs.ko`zfs_readdir+0x67d
zfs.ko`zfs_freebsd_readdir+0x41
kernel`VOP_READDIR_APV+0xa7
kernel`kern_getdirentries+0x210
kernel`sys_getdirentries+0x28
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
2
arc_get_data_buf
zfs.ko`arc_read+0x9e4
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_hold+0x96
zfs.ko`zap_get_leaf_byblk+0x76
zfs.ko`zap_deref_leaf+0xbd
zfs.ko`fzap_cursor_retrieve+0x16d
zfs.ko`zap_cursor_retrieve+0x20d
zfs.ko`zfs_readdir+0x67d
zfs.ko`zfs_freebsd_readdir+0x41
kernel`VOP_READDIR_APV+0xa7
kernel`kern_getdirentries+0x210
kernel`sys_getdirentries+0x28
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
2
arc_get_data_buf
zfs.ko`arc_read+0x9e4
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_hold+0x96
zfs.ko`zap_get_leaf_byblk+0x76
zfs.ko`zap_deref_leaf+0xbd
zfs.ko`fzap_lookup+0x98
zfs.ko`zap_lookup_norm+0x1b5
zfs.ko`zap_lookup+0x6d
zfs.ko`zfs_match_find+0x1ad
zfs.ko`zfs_dirent_lock+0xa71
zfs.ko`zfs_dirlook+0x44e
zfs.ko`zfs_lookup+0x7ef
zfs.ko`zfs_freebsd_lookup+0x10f
kernel`VOP_CACHEDLOOKUP_APV+0xa1
kernel`vfs_cache_lookup+0xd6
kernel`VOP_LOOKUP_APV+0xa1
kernel`lookup+0x5a5
kernel`namei+0x584
kernel`vn_open_cred+0xe3
2
arc_get_data_buf
zfs.ko`arc_read+0x9e4
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_hold+0x96
zfs.ko`zap_lockdir+0x73
zfs.ko`zap_lookup_norm+0xa9
zfs.ko`zap_lookup+0x6d
zfs.ko`zfs_fuid_overquota+0x124
zfs.ko`zfs_owner_overquota+0xc1
zfs.ko`zfs_write+0x8f1
zfs.ko`zfs_freebsd_write+0x59
kernel`VOP_WRITE_APV+0x134
kernel`vn_write+0x25a
kernel`vn_io_fault+0x10a
kernel`dofilewrite+0x89
kernel`kern_writev+0x68
kernel`sys_writev+0x36
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
2
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`dbuf_read_impl+0x2bb
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_will_dirty+0x89
zfs.ko`dmu_write+0x14c
zfs.ko`space_map_write+0x56b
zfs.ko`metaslab_sync+0x310
zfs.ko`vdev_sync+0x119
zfs.ko`spa_sync+0x5ac
zfs.ko`txg_sync_thread+0x403
kernel`fork_exit+0x9c
kernel`0xffffffff80848d7e
3
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`dbuf_read_impl+0x2bb
zfs.ko`dbuf_read+0x380
zfs.ko`dbuf_sync_indirect+0xa2
zfs.ko`dbuf_sync_list+0x103
zfs.ko`dnode_sync+0x73f
zfs.ko`dmu_objset_sync_dnodes+0x96
zfs.ko`dmu_objset_sync+0x3b1
zfs.ko`dsl_dataset_sync+0x5a
zfs.ko`dsl_pool_sync+0x107
zfs.ko`spa_sync+0x513
zfs.ko`txg_sync_thread+0x403
kernel`fork_exit+0x9c
kernel`0xffffffff80848d7e
3
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`dbuf_read_impl+0x2bb
zfs.ko`dbuf_read+0x380
zfs.ko`dnode_hold_impl+0x4b7
zfs.ko`dmu_object_alloc+0x1b7
zfs.ko`zfs_mknode+0x38f
zfs.ko`zfs_create+0xab2
zfs.ko`zfs_freebsd_create+0x8b
kernel`VOP_CREATE_APV+0xa1
kernel`vn_open_cred+0x288
kernel`kern_openat+0x257
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
3
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`arc_read+0x6b3
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_hold+0x96
zfs.ko`zap_lockdir+0x73
zfs.ko`zap_count_write+0xb4
zfs.ko`dmu_tx_hold_zap+0x29f
zfs.ko`zfs_create+0x905
zfs.ko`zfs_freebsd_create+0x8b
kernel`VOP_CREATE_APV+0xa1
kernel`vn_open_cred+0x288
kernel`kern_openat+0x257
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
3
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`arc_read+0x6b3
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_hold+0x96
zfs.ko`zap_lockdir+0x73
zfs.ko`zap_lookup_norm+0xa9
zfs.ko`zap_lookup+0x6d
zfs.ko`zfs_match_find+0x1ad
zfs.ko`zfs_dirent_lock+0xa71
zfs.ko`zfs_create+0x511
zfs.ko`zfs_freebsd_create+0x8b
kernel`VOP_CREATE_APV+0xa1
kernel`vn_open_cred+0x288
kernel`kern_openat+0x257
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
3
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`arc_read+0x6b3
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_hold+0x96
zfs.ko`zap_lockdir+0x73
zfs.ko`zap_lookup_norm+0xa9
zfs.ko`zap_lookup+0x6d
zfs.ko`zfs_match_find+0x1ad
zfs.ko`zfs_dirent_lock+0xa71
zfs.ko`zfs_dirlook+0x44e
zfs.ko`zfs_lookup+0x7ef
zfs.ko`zfs_freebsd_lookup+0x10f
kernel`VOP_CACHEDLOOKUP_APV+0xa1
kernel`vfs_cache_lookup+0xd6
kernel`VOP_LOOKUP_APV+0xa1
kernel`lookup+0x5a5
kernel`namei+0x584
kernel`kern_statat+0xab
kernel`sys_stat+0x2d
3
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`arc_read+0x6b3
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_hold+0x96
zfs.ko`zap_lockdir+0x73
zfs.ko`zap_add+0x7d
zfs.ko`zfs_link_create+0x901
zfs.ko`zfs_create+0xaf0
zfs.ko`zfs_freebsd_create+0x8b
kernel`VOP_CREATE_APV+0xa1
kernel`vn_open_cred+0x288
kernel`kern_openat+0x257
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
3
arc_get_data_buf
zfs.ko`arc_read+0x9e4
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dnode_hold_impl+0x4b7
zfs.ko`dnode_hold+0x3a
zfs.ko`dmu_tx_hold_object_impl+0x60
zfs.ko`dmu_tx_hold_zap+0x44
zfs.ko`dmu_tx_hold_sa+0x1c2
zfs.ko`zfs_setattr+0x22ef
zfs.ko`zfs_freebsd_setattr+0xa33
kernel`VOP_SETATTR_APV+0xa1
kernel`setfmode+0xb1
kernel`kern_fchmodat+0xe6
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
3
arc_get_data_buf
zfs.ko`arc_read+0x9e4
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_hold+0x96
zfs.ko`zap_get_leaf_byblk+0x76
zfs.ko`zap_deref_leaf+0xbd
zfs.ko`fzap_cursor_retrieve+0x16d
zfs.ko`zap_cursor_retrieve+0x20d
zfs.ko`dsl_prop_get_all_impl+0x9a
zfs.ko`dsl_prop_get_all_ds+0x261
zfs.ko`dsl_prop_get_all+0x27
zfs.ko`zfs_ioc_objset_stats_impl+0x55
zfs.ko`zfs_ioc_objset_stats+0x3d
zfs.ko`zfsdev_ioctl+0xc7d
kernel`devfs_ioctl_f+0x13b
kernel`kern_ioctl+0x414
kernel`sys_ioctl+0x153
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
4
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`dbuf_read_impl+0x2bb
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_will_dirty+0x89
zfs.ko`dmu_write+0x14c
zfs.ko`space_map_write+0x56b
zfs.ko`metaslab_sync+0x2e8
zfs.ko`vdev_sync+0x119
zfs.ko`spa_sync+0x5ac
zfs.ko`txg_sync_thread+0x403
kernel`fork_exit+0x9c
kernel`0xffffffff80848d7e
6
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`arc_read+0x6b3
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_hold+0x96
zfs.ko`zap_lockdir+0x73
zfs.ko`zap_lookup_norm+0xa9
zfs.ko`zap_lookup+0x6d
zfs.ko`zfs_match_find+0x1ad
zfs.ko`zfs_dirent_lock+0xa71
zfs.ko`zfs_dirlook+0x44e
zfs.ko`zfs_lookup+0x7ef
zfs.ko`zfs_freebsd_lookup+0x10f
kernel`VOP_CACHEDLOOKUP_APV+0xa1
kernel`vfs_cache_lookup+0xd6
kernel`VOP_LOOKUP_APV+0xa1
kernel`lookup+0x5a5
kernel`namei+0x584
kernel`vn_open_cred+0xe3
kernel`kern_openat+0x257
6
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`arc_read+0x6b3
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_hold+0x96
zfs.ko`zap_lockdir+0x73
zfs.ko`zap_add+0x7d
zfs.ko`zap_add_int+0x7e
zfs.ko`zfs_unlinked_add+0x44
zfs.ko`zfs_link_destroy+0xa19
zfs.ko`zfs_rename+0x1115
zfs.ko`zfs_freebsd_rename+0xd9
kernel`VOP_RENAME_APV+0xab
kernel`kern_renameat+0x4ac
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
6
arc_get_data_buf
zfs.ko`arc_read+0x9e4
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_hold+0x96
zfs.ko`zap_lockdir+0x73
zfs.ko`zap_cursor_retrieve+0xf5
zfs.ko`dsl_prop_get_all_impl+0x9a
zfs.ko`dsl_prop_get_all_ds+0x261
zfs.ko`dsl_prop_get_all+0x27
zfs.ko`zfs_ioc_objset_stats_impl+0x55
zfs.ko`zfs_ioc_objset_stats+0x3d
zfs.ko`zfsdev_ioctl+0xc7d
kernel`devfs_ioctl_f+0x13b
kernel`kern_ioctl+0x414
kernel`sys_ioctl+0x153
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
6
arc_get_data_buf
zfs.ko`arc_read+0x9e4
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_hold+0x96
zfs.ko`zap_lockdir+0x73
zfs.ko`zap_cursor_retrieve+0xf5
zfs.ko`spa_add_feature_stats+0x143
zfs.ko`spa_get_stats+0x1ff
zfs.ko`zfs_ioc_pool_stats+0x51
zfs.ko`zfsdev_ioctl+0xc7d
kernel`devfs_ioctl_f+0x13b
kernel`kern_ioctl+0x414
kernel`sys_ioctl+0x153
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
6
arc_get_data_buf
zfs.ko`arc_read+0x9e4
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_hold+0x96
zfs.ko`zap_lockdir+0x73
zfs.ko`zap_cursor_retrieve+0xf5
zfs.ko`spa_add_feature_stats+0x287
zfs.ko`spa_get_stats+0x1ff
zfs.ko`zfs_ioc_pool_stats+0x51
zfs.ko`zfsdev_ioctl+0xc7d
kernel`devfs_ioctl_f+0x13b
kernel`kern_ioctl+0x414
kernel`sys_ioctl+0x153
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
6
arc_get_data_buf
zfs.ko`arc_read+0x9e4
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_hold+0x96
zfs.ko`zap_lockdir+0x73
zfs.ko`zap_lookup_norm+0xa9
zfs.ko`zap_lookup+0x6d
zfs.ko`dsl_dir_hold+0x2aa
zfs.ko`dsl_dataset_hold+0x3e
zfs.ko`dmu_objset_hold+0x65
zfs.ko`zfs_ioc_objset_stats+0x20
zfs.ko`zfsdev_ioctl+0xc7d
kernel`devfs_ioctl_f+0x13b
kernel`kern_ioctl+0x414
kernel`sys_ioctl+0x153
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
6
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`arc_read+0x6b3
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_tx_check_ioerr+0x134
zfs.ko`dmu_tx_hold_zap+0xef
zfs.ko`zfs_rename+0xf44
zfs.ko`zfs_freebsd_rename+0xd9
kernel`VOP_RENAME_APV+0xab
kernel`kern_renameat+0x4ac
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
7
arc_get_data_buf
zfs.ko`arc_read+0x9e4
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dnode_hold_impl+0x4b7
zfs.ko`dnode_hold+0x3a
zfs.ko`dmu_tx_hold_object_impl+0x60
zfs.ko`dmu_tx_hold_zap+0x44
zfs.ko`dmu_tx_hold_sa_create+0xab
zfs.ko`zfs_create+0x8b3
zfs.ko`zfs_freebsd_create+0x8b
kernel`VOP_CREATE_APV+0xa1
kernel`vn_open_cred+0x288
kernel`kern_openat+0x257
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
7
arc_get_data_buf
zfs.ko`arc_read+0x9e4
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_hold+0x96
zfs.ko`zap_lockdir+0x73
zfs.ko`zap_lookup_norm+0xa9
zfs.ko`zap_lookup+0x6d
zfs.ko`zfs_match_find+0x1ad
zfs.ko`zfs_dirent_lock+0xa71
zfs.ko`zfs_dirlook+0x44e
zfs.ko`zfs_lookup+0x7ef
zfs.ko`zfs_freebsd_lookup+0x10f
kernel`VOP_CACHEDLOOKUP_APV+0xa1
kernel`vfs_cache_lookup+0xd6
kernel`VOP_LOOKUP_APV+0xa1
kernel`lookup+0x5a5
kernel`namei+0x584
kernel`kern_statat+0xab
kernel`sys_stat+0x2d
kernel`amd64_syscall+0x4eb
9
arc_get_data_buf
zfs.ko`arc_read+0x9e4
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dnode_hold_impl+0x4b7
zfs.ko`dmu_object_alloc+0x1b7
zfs.ko`zfs_mknode+0x38f
zfs.ko`zfs_create+0xab2
zfs.ko`zfs_freebsd_create+0x8b
kernel`VOP_CREATE_APV+0xa1
kernel`vn_open_cred+0x288
kernel`kern_openat+0x257
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
9
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`arc_read+0x6b3
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_will_dirty+0x89
zfs.ko`dmu_write+0x14c
zfs.ko`space_map_write+0x56b
zfs.ko`metaslab_sync+0x2e8
zfs.ko`vdev_sync+0x119
zfs.ko`spa_sync+0x5ac
zfs.ko`txg_sync_thread+0x403
kernel`fork_exit+0x9c
kernel`0xffffffff80848d7e
11
arc_get_data_buf
zfs.ko`arc_read+0x9e4
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_hold+0x96
zfs.ko`zap_lockdir+0x73
zfs.ko`zap_lookup_norm+0xa9
zfs.ko`zap_lookup+0x6d
zfs.ko`zfs_match_find+0x1ad
zfs.ko`zfs_dirent_lock+0xa71
zfs.ko`zfs_dirlook+0x44e
zfs.ko`zfs_lookup+0x7ef
zfs.ko`zfs_freebsd_lookup+0x10f
kernel`VOP_CACHEDLOOKUP_APV+0xa1
kernel`vfs_cache_lookup+0xd6
kernel`VOP_LOOKUP_APV+0xa1
kernel`lookup+0x5a5
kernel`namei+0x584
kernel`vn_open_cred+0xe3
kernel`kern_openat+0x257
kernel`amd64_syscall+0x4eb
11
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`arc_read+0x6b3
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_tx_check_ioerr+0x134
zfs.ko`dmu_tx_count_write+0x23b
zfs.ko`dmu_tx_hold_write+0x69
zfs.ko`zfs_write+0xc79
zfs.ko`zfs_freebsd_write+0x59
kernel`VOP_WRITE_APV+0x134
kernel`vn_write+0x25a
kernel`vn_io_fault+0x10a
kernel`dofilewrite+0x89
kernel`kern_writev+0x68
kernel`sys_write+0x63
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
13
arc_get_data_buf
zfs.ko`arc_read+0x9e4
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_hold+0x96
zfs.ko`zap_lockdir+0x73
zfs.ko`zap_cursor_retrieve+0xf5
zfs.ko`zfs_readdir+0x67d
zfs.ko`zfs_freebsd_readdir+0x41
kernel`VOP_READDIR_APV+0xa7
kernel`kern_getdirentries+0x210
kernel`sys_getdirentries+0x28
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
13
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`dbuf_noread+0xf5
zfs.ko`dmu_buf_will_fill+0x21
zfs.ko`dmu_write_uio_dnode+0x10e
zfs.ko`dmu_write_uio_dbuf+0x6c
zfs.ko`zfs_write+0xee7
zfs.ko`zfs_freebsd_write+0x59
kernel`VOP_WRITE_APV+0x134
kernel`vn_write+0x25a
kernel`vn_io_fault+0x10a
kernel`dofilewrite+0x89
kernel`kern_writev+0x68
kernel`sys_write+0x63
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
14
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`dbuf_new_size+0x80
zfs.ko`dnode_set_blksz+0x277
zfs.ko`dmu_object_set_blocksize+0x62
zfs.ko`zfs_grow_blocksize+0x92
zfs.ko`zfs_write+0xdea
zfs.ko`zfs_freebsd_write+0x59
kernel`VOP_WRITE_APV+0x134
kernel`vn_write+0x25a
kernel`vn_io_fault+0x10a
kernel`dofilewrite+0x89
kernel`kern_writev+0x68
kernel`sys_writev+0x36
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
14
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`dbuf_read_impl+0x2bb
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_will_dirty+0x89
zfs.ko`dmu_write+0x14c
zfs.ko`space_map_write+0x3c8
zfs.ko`metaslab_condense+0x2bb
zfs.ko`metaslab_sync+0x2c4
zfs.ko`vdev_sync+0x119
zfs.ko`spa_sync+0x5ac
zfs.ko`txg_sync_thread+0x403
kernel`fork_exit+0x9c
kernel`0xffffffff80848d7e
17
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`arc_read+0x6b3
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_hold+0x96
zfs.ko`zap_lockdir+0x73
zfs.ko`zap_add+0x7d
zfs.ko`zap_add_int+0x7e
zfs.ko`zfs_unlinked_add+0x44
zfs.ko`zfs_remove+0xb06
zfs.ko`zfs_freebsd_remove+0x47
kernel`VOP_REMOVE_APV+0xa7
kernel`kern_unlinkat+0x208
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
20
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`arc_read+0x6b3
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_tx_check_ioerr+0x134
zfs.ko`dmu_tx_hold_zap+0xef
zfs.ko`zfs_remove+0x73e
zfs.ko`zfs_freebsd_remove+0x47
kernel`VOP_REMOVE_APV+0xa7
kernel`kern_unlinkat+0x208
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
20
arc_get_data_buf
zfs.ko`arc_read+0x9e4
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dbuf_findbp+0x2a4
zfs.ko`dbuf_hold_impl+0x124
zfs.ko`dbuf_hold_level+0x59
zfs.ko`dbuf_hold+0x2c
zfs.ko`dmu_buf_hold_array_by_dnode+0x30b
zfs.ko`dmu_buf_hold_array+0x96
zfs.ko`dmu_write+0x69
zfs.ko`space_map_write+0x56b
zfs.ko`metaslab_sync+0x310
zfs.ko`vdev_sync+0x119
zfs.ko`spa_sync+0x5ac
zfs.ko`txg_sync_thread+0x403
kernel`fork_exit+0x9c
kernel`0xffffffff80848d7e
20
arc_get_data_buf
zfs.ko`arc_read+0x9e4
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_will_dirty+0x89
zfs.ko`dmu_write+0x14c
zfs.ko`space_map_write+0x56b
zfs.ko`metaslab_sync+0x310
zfs.ko`vdev_sync+0x119
zfs.ko`spa_sync+0x5ac
zfs.ko`txg_sync_thread+0x403
kernel`fork_exit+0x9c
kernel`0xffffffff80848d7e
20
arc_get_data_buf
zfs.ko`arc_read+0x9e4
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_hold_array_by_dnode+0x432
zfs.ko`dmu_read_uio_dnode+0x5d
zfs.ko`dmu_read_uio_dbuf+0x64
zfs.ko`zfs_read+0x473
zfs.ko`zfs_freebsd_read+0x59
kernel`VOP_READ_APV+0xa1
kernel`vn_read+0x16c
kernel`vn_io_fault+0x10a
kernel`dofileread+0x95
kernel`kern_readv+0x68
kernel`sys_read+0x63
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
20
arc_get_data_buf
zfs.ko`arc_read+0x9e4
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dbuf_findbp+0x2a4
zfs.ko`dbuf_hold_impl+0x124
zfs.ko`dbuf_hold_level+0x59
zfs.ko`dbuf_hold+0x2c
zfs.ko`dmu_buf_hold_array_by_dnode+0x30b
zfs.ko`dmu_read+0x197
zfs.ko`zfs_getpages+0x6c8
zfs.ko`zfs_freebsd_getpages+0x2f
kernel`VOP_GETPAGES_APV+0xa7
kernel`vnode_pager_getpages+0xb8
kernel`vm_pager_get_pages+0x1f
kernel`vm_fault_hold+0xbe4
kernel`vm_fault+0x78
kernel`trap_pfault+0x223
kernel`trap+0x4f0
kernel`0xffffffff8084884a
32
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`arc_read+0x6b3
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_hold+0x96
zfs.ko`zap_lockdir+0x73
zfs.ko`zap_update+0x80
zfs.ko`zap_increment+0x13f
zfs.ko`zap_increment_int+0x71
zfs.ko`do_userquota_update+0x99
zfs.ko`dmu_objset_do_userquota_updates+0x1b4
zfs.ko`dsl_pool_sync+0x1c1
zfs.ko`spa_sync+0x513
zfs.ko`txg_sync_thread+0x403
kernel`fork_exit+0x9c
kernel`0xffffffff80848d7e
43
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`arc_read+0x6b3
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_hold+0x96
zfs.ko`zap_lockdir+0x73
zfs.ko`zap_lookup_norm+0xa9
zfs.ko`zap_lookup+0x6d
zfs.ko`zap_increment+0x90
zfs.ko`zap_increment_int+0x71
zfs.ko`do_userquota_update+0x99
zfs.ko`dmu_objset_do_userquota_updates+0x1b4
zfs.ko`dsl_pool_sync+0x1c1
zfs.ko`spa_sync+0x513
zfs.ko`txg_sync_thread+0x403
kernel`fork_exit+0x9c
kernel`0xffffffff80848d7e
43
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`arc_read+0x6b3
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_hold+0x96
zfs.ko`zap_lockdir+0x73
zfs.ko`zap_update+0x80
zfs.ko`zap_increment+0x13f
zfs.ko`zap_increment_int+0x71
zfs.ko`do_userquota_update+0x111
zfs.ko`dmu_objset_do_userquota_updates+0x1b4
zfs.ko`dsl_pool_sync+0x1c1
zfs.ko`spa_sync+0x513
zfs.ko`txg_sync_thread+0x403
kernel`fork_exit+0x9c
kernel`0xffffffff80848d7e
53
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`arc_read+0x6b3
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_hold+0x96
zfs.ko`zap_lockdir+0x73
zfs.ko`zap_lookup_norm+0xa9
zfs.ko`zap_lookup+0x6d
zfs.ko`zap_increment+0x90
zfs.ko`zap_increment_int+0x71
zfs.ko`do_userquota_update+0x111
zfs.ko`dmu_objset_do_userquota_updates+0x1b4
zfs.ko`dsl_pool_sync+0x1c1
zfs.ko`spa_sync+0x513
zfs.ko`txg_sync_thread+0x403
kernel`fork_exit+0x9c
kernel`0xffffffff80848d7e
53
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`dbuf_sync_leaf+0x3d9
zfs.ko`dbuf_sync_list+0x115
zfs.ko`dbuf_sync_indirect+0x1c0
zfs.ko`dbuf_sync_list+0x103
zfs.ko`dnode_sync+0x73f
zfs.ko`dmu_objset_sync_dnodes+0x96
zfs.ko`dmu_objset_sync+0x3b1
zfs.ko`dsl_pool_sync_mos+0x5b
zfs.ko`dsl_pool_sync+0x4a3
zfs.ko`spa_sync+0x513
zfs.ko`txg_sync_thread+0x403
kernel`fork_exit+0x9c
kernel`0xffffffff80848d7e
60
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`arc_read+0x6b3
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_hold+0x96
zfs.ko`zap_lockdir+0x73
zfs.ko`zap_cursor_retrieve+0xf5
zfs.ko`dsl_prop_get_all_impl+0x9a
zfs.ko`dsl_prop_get_all_ds+0x261
zfs.ko`dsl_prop_get_all+0x27
zfs.ko`zfs_ioc_objset_stats_impl+0x55
zfs.ko`zfs_ioc_objset_stats+0x3d
zfs.ko`zfsdev_ioctl+0xc7d
kernel`devfs_ioctl_f+0x13b
kernel`kern_ioctl+0x414
kernel`sys_ioctl+0x153
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
78
arc_get_data_buf
zfs.ko`arc_read+0x9e4
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_hold_array_by_dnode+0x432
zfs.ko`dmu_read+0x197
zfs.ko`zfs_getpages+0x6c8
zfs.ko`zfs_freebsd_getpages+0x2f
kernel`VOP_GETPAGES_APV+0xa7
kernel`vnode_pager_getpages+0xb8
kernel`vm_pager_get_pages+0x1f
kernel`vm_fault_hold+0xbe4
kernel`vm_fault+0x78
kernel`trap_pfault+0x223
kernel`trap+0x4f0
kernel`0xffffffff8084884a
90
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`dbuf_new_size+0x80
zfs.ko`dnode_set_blksz+0x277
zfs.ko`dmu_object_set_blocksize+0x62
zfs.ko`zfs_grow_blocksize+0x92
zfs.ko`zfs_write+0xdea
zfs.ko`zfs_freebsd_write+0x59
kernel`VOP_WRITE_APV+0x134
kernel`vn_write+0x25a
kernel`vn_io_fault+0x10a
kernel`dofilewrite+0x89
kernel`kern_writev+0x68
kernel`sys_write+0x63
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
100
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`dbuf_read_impl+0x2bb
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_tx_check_ioerr+0x134
zfs.ko`dmu_tx_count_write+0x150
zfs.ko`dmu_tx_hold_write+0x69
zfs.ko`zfs_write+0xc79
zfs.ko`zfs_freebsd_write+0x59
kernel`VOP_WRITE_APV+0x134
kernel`vn_write+0x25a
kernel`vn_io_fault+0x10a
kernel`dofilewrite+0x89
kernel`kern_writev+0x68
kernel`sys_write+0x63
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
456
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`arc_read+0x6b3
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_hold_array_by_dnode+0x432
zfs.ko`dmu_read+0x197
zfs.ko`zfs_getpages+0x6c8
zfs.ko`zfs_freebsd_getpages+0x2f
kernel`VOP_GETPAGES_APV+0xa7
kernel`vnode_pager_getpages+0xb8
kernel`vm_pager_get_pages+0x1f
kernel`vm_fault_hold+0xbe4
kernel`vm_fault+0x78
kernel`trap_pfault+0x223
kernel`trap+0x4f0
kernel`0xffffffff8084884a
562
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`dbuf_read_impl+0x2bb
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_will_dirty+0x89
zfs.ko`dmu_write_uio_dnode+0x120
zfs.ko`dmu_write_uio_dbuf+0x6c
zfs.ko`zfs_write+0xee7
zfs.ko`zfs_freebsd_write+0x59
kernel`VOP_WRITE_APV+0x134
kernel`vn_write+0x25a
kernel`vn_io_fault+0x10a
kernel`dofilewrite+0x89
kernel`kern_writev+0x68
kernel`sys_write+0x63
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
570
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`arc_read+0x6b3
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_hold_array_by_dnode+0x432
zfs.ko`dmu_read_uio_dnode+0x5d
zfs.ko`dmu_read_uio_dbuf+0x64
zfs.ko`zfs_read+0x473
zfs.ko`zfs_freebsd_read+0x59
kernel`VOP_READ_APV+0xa1
kernel`vn_read+0x16c
kernel`vn_io_fault+0x10a
kernel`dofileread+0x95
kernel`kern_readv+0x68
kernel`sys_read+0x63
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
846
arc_get_data_buf
zfs.ko`arc_buf_alloc+0x108
zfs.ko`arc_read+0x6b3
zfs.ko`dbuf_read_impl+0x4ca
zfs.ko`dbuf_read+0x380
zfs.ko`dmu_buf_hold+0x96
zfs.ko`zap_lockdir+0x73
zfs.ko`zap_cursor_retrieve+0xf5
zfs.ko`zfs_readdir+0x67d
zfs.ko`zfs_freebsd_readdir+0x41
kernel`VOP_READDIR_APV+0xa7
kernel`kern_getdirentries+0x210
kernel`sys_getdirentries+0x28
kernel`amd64_syscall+0x4eb
kernel`0xffffffff80848b2b
2459
The rate limiting wasn't working as expected, among other things because the autoreap variable in the reclaim thread wasn't declared static.
Unfortunately the problem wasn't completely gone after declaring the variable static and modifying reap_arc_caches() to return early if another version was already running in a different thread. DTrace showed that there still was a correlation between the runtime distribution of reap_arc_caches() and arc_get_data_buf():
fk@r500 ~ $sudo ~/scripts/fbt-time.d reap_arc_caches
[...]
2015 Sep 3 21:08:03: Runtime for reap_arc_caches() in microseconds
Average 315
value ------------- Distribution ------------- count
2 | 0
3 | 175
4 | 374
5 | 116
6 | 160
7 | 268
8 | 95
9 | 8
10 | 32
20 | 8
30 | 3
40 | 6
50 | 3
60 | 2
70 | 4
80 | 1
90 | 0
100 | 2
200 |@@@@@@@@@@@@@@@@@@@@@@@@@ 25208
300 |@@@@@@@@@ 8808
400 |@@ 2243
500 |@ 1334
600 | 377
700 | 102
800 | 58
900 | 66
1000 | 306
2000 | 97
3000 | 113
4000 | 39
5000 | 9
6000 | 7
7000 | 8
8000 | 5
9000 | 1
10000 | 7
20000 | 0
30000 | 1
40000 | 1
50000 | 0
fk@r500 ~/scripts $sudo ~/scripts/fbt-time.d arc_get_data_buf
[...]
2015 Sep 3 21:08:05: Runtime for arc_get_data_buf() in microseconds
Average 31
value ------------- Distribution ------------- count
1 | 0
2 |@@@@@@@@@@@@@@@@@@@@@@@@@@@ 366218
3 |@@@@ 49931
4 |@ 8254
5 | 4618
6 |@@ 21227
7 |@ 12464
8 |@ 8324
9 |@ 7172
10 |@@ 26751
20 | 2714
30 | 1995
40 | 1265
50 | 456
60 | 429
70 | 717
80 | 337
90 | 262
100 | 1131
200 |@ 12946
300 |@ 8669
400 | 4639
500 | 1719
600 | 1420
700 | 1203
800 | 474
900 | 317
1000 | 1124
2000 | 195
3000 | 161
4000 | 66
5000 | 24
6000 | 10
7000 | 6
8000 | 6
9000 | 2
10000 | 8
20000 | 2
30000 | 1
40000 | 1
50000 | 0
consider_reaping_arc_caches() was added as a wrapper around reap_arc_caches(). It is executed at least once per second but more often when the ARC is under memory pressure. A time-based rate limit controlled by vfs.zfs.arc_reap_delay_min prevents the ARC reaper from hogging too much system resources.
While the perfect default value probably hasn't been found yet, DTrace confirms that arc_get_data_buf()'s latency has been significantly reduced:
2015 Sep 6 17:06:07: Runtime for consider_reaping_arc_caches() in microseconds
Average 819
value ------------- Distribution ------------- count
< 1 | 0
1 |@@@ 417
2 |@@@@@ 690
3 |@@@@@@@ 982
4 |@@@@@ 803
5 |@@ 339
6 |@ 172
7 |@ 135
8 | 34
9 | 13
10 | 35
20 | 1
30 | 1
40 | 2
50 | 0
60 | 0
70 | 0
80 | 0
90 | 0
100 | 0
200 | 0
300 | 28
400 | 40
500 | 19
600 | 32
700 | 48
800 | 38
900 |@ 75
1000 |@@@@@@ 915
2000 |@@@@@ 762
3000 |@ 203
4000 |@ 76
5000 | 32
6000 | 21
7000 | 7
8000 | 3
9000 | 1
10000 | 8
20000 | 0
30000 | 1
40000 | 0
2015 Sep 6 17:06:06: Runtime for reap_arc_caches() in microseconds
Average 1613
value ------------- Distribution ------------- count
200 | 0
300 |@ 37
400 |@ 68
500 |@ 40
600 |@@@ 155
700 |@@@ 199
800 |@@@ 175
900 |@@ 133
1000 |@@@@@@@@@@@@@@@@@@ 1013
2000 |@@@@@ 264
3000 |@@ 123
4000 |@ 38
5000 | 27
6000 | 8
7000 | 5
8000 | 1
9000 | 1
10000 | 7
20000 | 0
30000 | 1
40000 | 0
2015 Sep 6 17:06:06: Runtime for arc_get_data_buf() in microseconds
Average 8
value ------------- Distribution ------------- count
1 | 0
2 |@@@@@@@@@@@@@@@@@@@@@ 458295
3 |@@@@ 83927
4 |@@@ 56729
5 |@ 15070
6 |@@@@@ 105605
7 |@ 28636
8 |@ 17055
9 |@ 13698
10 |@@ 35016
20 |@ 11166
30 |@ 10912
40 | 3869
50 | 2405
60 | 5465
70 | 3552
80 | 3271
90 | 1902
100 | 6646
200 | 334
300 | 143
400 | 106
500 | 80
600 | 88
700 | 59
800 | 38
900 | 45
1000 | 173
2000 | 31
3000 | 37
4000 | 30
5000 | 10
6000 | 8
7000 | 9
8000 | 4
9000 | 4
10000 | 9
20000 | 5
30000 | 1
40000 | 0
50000 | 0
60000 | 1
70000 | 0
80000 | 0
90000 | 0
100000 | 2
200000 | 0
More importantly, the user experience under memory pressure has improved accordingly.
In case you are wondering: The cause of the outliers at the end has not yet been investigated and it's unknown if they also occur when DTrace isn't running.
This page was made from incomplete notes created while experimenting.
I did not (yet) investigate how vanilla FreeBSD would perform under similar circumstances and you should not draw any FreeBSD-specific conclusions from this page without DTracing the workload you care about yourself.
While an unpatched FreeBSD reaps the ARC caches from a potential hot path that can impact arc_get_data_buf() through a shared lock, it does it from a single thread so there should be no collisions and a lot less lock contention than with the ZFS ARC patch mentioned above.
If you want to experiment without waiting for the ElectroBSD release, feel free to try the zfs-arc-tuning.diff (experimental) which includes the fbt-time DTrace script and should apply more or less cleanly against vanilla FreeBSD 11-CURRENT once the ZFS ARC patch from the PR is applied.