Slow `tar cf /usr/include` on warm cache, 3x slower than XFS #5564

Open
haasn opened this Issue Jan 6, 2017 · 7 comments

Projects

None yet

5 participants

@haasn
haasn commented Jan 6, 2017 edited

System information

Type Version/Name
Distribution Name Gentoo Linux
Distribution Version hardened/linux/amd64 profile
Linux Kernel 4.9.0-gentoo #1 SMP PREEMPT
Architecture x86_64
ZFS Version 0.7.0-rc2_59_ga3fd9d9e
SPL Version 0.7.0-rc2_2_gcbba714

Describe the problem you're observing

tar cf - /usr/include | pv >/dev/null is much slower (3x) on ZFS than on XFS.

Describe how to reproduce the problem

ZFS:

λ time tar cf - /usr/include | pv >/dev/null
 370MiB 0:00:01 [ 344MiB/s]
tar cf - /usr/include  0.14s user 0.94s system 99% cpu 1.080 total

λ time tar cf - /usr/include | pv >/dev/null
 370MiB 0:00:01 [ 347MiB/s]
tar cf - /usr/include  0.12s user 0.95s system 99% cpu 1.071 total

λ time tar cf - /usr/include | pv >/dev/null
 370MiB 0:00:01 [ 366MiB/s]
tar cf - /usr/include  0.11s user 0.90s system 99% cpu 1.013 total

λ time tar cf - /usr/include | pv >/dev/null
 370MiB 0:00:01 [ 338MiB/s]
tar cf - /usr/include  0.12s user 0.97s system 99% cpu 1.096 total

λ time tar cf - /usr/include | pv >/dev/null
 370MiB 0:00:01 [ 362MiB/s]
tar cf - /usr/include  0.12s user 0.90s system 99% cpu 1.026 total

λ time tar cf - /usr/include | pv >/dev/null
 370MiB 0:00:01 [ 343MiB/s]
tar cf - /usr/include  0.12s user 0.96s system 99% cpu 1.082 total

λ time tar cf - /usr/include | pv >/dev/null
 370MiB 0:00:01 [ 339MiB/s]
tar cf - /usr/include  0.12s user 0.97s system 99% cpu 1.096 total

XFS:

λ cp -a /usr/include /mnt/xfs/test
λ time tar cf - /mnt/xfs/test | pv >/dev/null
 370MiB 0:00:00 [1.03GiB/s]
tar cf - /mnt/xfs/test  0.09s user 0.26s system 98% cpu 0.353 total

λ time tar cf - /mnt/xfs/test | pv >/dev/null
 370MiB 0:00:00 [1.01GiB/s]
tar cf - /mnt/xfs/test  0.10s user 0.26s system 98% cpu 0.362 total

λ time tar cf - /mnt/xfs/test | pv >/dev/null
 370MiB 0:00:00 [ 989MiB/s]
tar cf - /mnt/xfs/test  0.10s user 0.27s system 98% cpu 0.378 total

λ time tar cf - /mnt/xfs/test | pv >/dev/null
 370MiB 0:00:00 [1.04GiB/s]
tar cf - /mnt/xfs/test  0.09s user 0.26s system 98% cpu 0.349 total

λ time tar cf - /mnt/xfs/test | pv >/dev/null
 370MiB 0:00:00 [1015MiB/s]
tar cf - /mnt/xfs/test  0.10s user 0.26s system 98% cpu 0.368 total

λ time tar cf - /mnt/xfs/test | pv >/dev/null
 370MiB 0:00:00 [1.05GiB/s]
tar cf - /mnt/xfs/test  0.08s user 0.26s system 98% cpu 0.346 total

λ time tar cf - /mnt/xfs/test | pv >/dev/null
 370MiB 0:00:00 [1007MiB/s]
tar cf - /mnt/xfs/test  0.10s user 0.26s system 98% cpu 0.370 total

/proc/spl/kstat/zfs/arcstats:

12 1 0x01 92 4416 5899462154 338894250281483
name                            type data
hits                            4    120314146
misses                          4    68121353
demand_data_hits                4    48026360
demand_data_misses              4    4866968
demand_metadata_hits            4    12143604
demand_metadata_misses          4    62848557
prefetch_data_hits              4    56557200
prefetch_data_misses            4    214734
prefetch_metadata_hits          4    3586982
prefetch_metadata_misses        4    191094
mru_hits                        4    2742603
mru_ghost_hits                  4    25801
mfu_hits                        4    113606816
mfu_ghost_hits                  4    7178
deleted                         4    474
mutex_miss                      4    7
evict_skip                      4    66
evict_not_enough                4    0
evict_l2_cached                 4    7305033728
evict_l2_eligible               4    9319424
evict_l2_ineligible             4    1692262400
evict_l2_skip                   4    0
hash_elements                   4    1607230
hash_elements_max               4    1613089
hash_collisions                 4    1681251
hash_chains                     4    136685
hash_chain_max                  4    6
p                               4    4148043371
c                               4    33235345504
c_min                           4    33554432
c_max                           4    33760978944
size                            4    33188643336
compressed_size                 4    28503348736
uncompressed_size               4    50285766144
overhead_size                   4    1892703744
hdr_size                        4    536009552
data_size                       4    28083202560
metadata_size                   4    2316496384
dbuf_size                       4    369417456
dnode_size                      4    964986120
bonus_size                      4    918531264
anon_size                       4    9827328
anon_evictable_data             4    0
anon_evictable_metadata         4    0
mru_size                        4    3766229504
mru_evictable_data              4    2151516672
mru_evictable_metadata          4    32300544
mru_ghost_size                  4    7056995328
mru_ghost_evictable_data        4    5589318144
mru_ghost_evictable_metadata    4    1467677184
mfu_size                        4    26619995648
mfu_evictable_data              4    25784523264
mfu_evictable_metadata          4    272871936
mfu_ghost_size                  4    442086912
mfu_ghost_evictable_data        4    439613440
mfu_ghost_evictable_metadata    4    2473472
l2_hits                         4    16344
l2_misses                       4    68104967
l2_feeds                        4    331613
l2_rw_clash                     4    0
l2_read_bytes                   4    119560192
l2_write_bytes                  4    23792261632
l2_writes_sent                  4    88378
l2_writes_done                  4    88378
l2_writes_error                 4    0
l2_writes_lock_retry            4    3
l2_evict_lock_retry             4    0
l2_evict_reading                4    0
l2_evict_l1cached               4    0
l2_free_on_write                4    800
l2_abort_lowmem                 4    0
l2_cksum_bad                    4    0
l2_io_error                     4    0
l2_size                         4    41245586944
l2_asize                        4    21932707328
l2_hdr_size                     4    0
memory_throttle_count           4    0
memory_direct_count             4    6
memory_indirect_count           4    1758
arc_no_grow                     4    0
arc_tempreserve                 4    0
arc_loaned_bytes                4    0
arc_prune                       4    0
arc_meta_used                   4    5105440776
arc_meta_limit                  4    25320734208
arc_dnode_limit                 4    2532073420
arc_meta_max                    4    5803545480
arc_meta_min                    4    16777216
sync_wait_for_async             4    18058
demand_hit_predictive_prefetch  4    85901
arc_need_free                   4    0
arc_sys_free                    4    1055030592

arc_summary.py:

------------------------------------------------------------------------
ZFS Subsystem Report				Fri Jan 06 07:00:22 2017
ARC Summary: (HEALTHY)
	Memory Throttle Count:			0

ARC Misc:
	Deleted:				474
	Mutex Misses:				7
	Evict Skips:				7

ARC Size:				99.00%	31.13	GiB
	Target Size: (Adaptive)		99.29%	31.22	GiB
	Min Size (Hard Limit):		0.10%	32.00	MiB
	Max Size (High Water):		1006:1	31.44	GiB

ARC Size Breakdown:
	Recently Used Cache Size:	12.90%	4.03	GiB
	Frequently Used Cache Size:	87.10%	27.19	GiB

ARC Hash Breakdown:
	Elements Max:				1.61m
	Elements Current:		99.75%	1.61m
	Collisions:				1.68m
	Chain Max:				6
	Chains:					136.96k

ARC Total accesses:					188.61m
	Cache Hit Ratio:		63.81%	120.35m
	Cache Miss Ratio:		36.19%	68.27m
	Actual Hit Ratio:		61.70%	116.38m

	Data Demand Efficiency:		90.80%	52.91m
	Data Prefetch Efficiency:	99.62%	56.77m

	CACHE HITS BY CACHE LIST:
	  Anonymously Used:		3.27%	3.93m
	  Most Recently Used:		2.28%	2.74m
	  Most Frequently Used:		94.42%	113.63m
	  Most Recently Used Ghost:	0.02%	25.81k
	  Most Frequently Used Ghost:	0.01%	7.18k

	CACHE HITS BY DATA TYPE:
	  Demand Data:			39.92%	48.04m
	  Prefetch Data:		47.00%	56.56m
	  Demand Metadata:		10.10%	12.16m
	  Prefetch Metadata:		2.98%	3.59m

	CACHE MISSES BY DATA TYPE:
	  Demand Data:			7.13%	4.87m
	  Prefetch Data:		0.31%	214.74k
	  Demand Metadata:		92.28%	62.99m
	  Prefetch Metadata:		0.28%	191.10k

L2 ARC Summary: (HEALTHY)
	Low Memory Aborts:			0
	Free on Write:				800
	R/W Clashes:				0
	Bad Checksums:				0
	IO Errors:				0

L2 ARC Size: (Adaptive)				38.39	GiB
	Compressed:			53.20%	20.43	GiB
	Header Size:			0.00%	0	Bytes

L2 ARC Evicts:
	Lock Retries:				0
	Upon Reading:				0

L2 ARC Breakdown:				68.27m
	Hit Ratio:			0.02%	16.34k
	Miss Ratio:			99.98%	68.25m
	Feeds:					331.65k

L2 ARC Writes:
	Writes Sent:			100.00%	88.40k

DMU Prefetch Efficiency:					629.61m
	Hit Ratio:			10.12%	63.75m
	Miss Ratio:			89.88%	565.86m



ZFS Tunable:
	l2arc_headroom                                    2
	dbuf_cache_max_shift                              5
	zfs_free_leak_on_eio                              0
	zfs_free_max_blocks                               100000
	zfs_read_chunk_size                               1048576
	metaslab_preload_enabled                          1
	zfs_dedup_prefetch                                0
	zfs_txg_history                                   0
	zfs_scrub_delay                                   4
	zfs_vdev_async_read_max_active                    3
	zfs_read_history                                  0
	zfs_arc_sys_free                                  0
	l2arc_write_max                                   8388608
	zfs_dbuf_state_index                              0
	metaslab_debug_unload                             0
	zvol_inhibit_dev                                  0
	zfs_abd_scatter_enabled                           1
	zfetch_max_streams                                8
	zfs_recover                                       0
	metaslab_fragmentation_factor_enabled             1
	zfs_sync_pass_rewrite                             2
	zfs_object_mutex_size                             64
	zfs_arc_min_prefetch_lifespan                     0
	zfs_arc_meta_prune                                10000
	zfs_read_history_hits                             0
	zfetch_max_distance                               8388608
	l2arc_norw                                        0
	zfs_dirty_data_max_percent                        10
	zfs_arc_meta_min                                  0
	metaslabs_per_vdev                                200
	zfs_arc_meta_adjust_restarts                      4096
	zil_slog_limit                                    1048576
	spa_load_verify_maxinflight                       10000
	spa_load_verify_metadata                          1
	zfs_send_corrupt_data                             0
	zfs_delay_min_dirty_percent                       60
	zfs_vdev_sync_read_max_active                     10
	zfs_dbgmsg_enable                                 0
	zio_requeue_io_start_cut_in_line                  1
	l2arc_headroom_boost                              200
	zfs_zevent_cols                                   80
	spa_config_path                                   /etc/zfs/zpool.cache
	zfs_vdev_cache_size                               0
	dbuf_cache_hiwater_pct                            10
	zio_dva_throttle_enabled                          0
	zfs_vdev_sync_write_min_active                    10
	zfs_vdev_scrub_max_active                         2
	ignore_hole_birth                                 1
	zvol_major                                        230
	zil_replay_disable                                0
	zfs_dirty_data_max_max_percent                    25
	zfs_expire_snapshot                               300
	zfs_sync_pass_deferred_free                       2
	spa_asize_inflation                               24
	zfs_vdev_mirror_rotating_seek_offset              1048576
	l2arc_feed_secs                                   1
	zfs_autoimport_disable                            1
	zfs_arc_p_aggressive_disable                      1
	zfs_zevent_len_max                                512
	zfs_arc_meta_limit_percent                        75
	l2arc_noprefetch                                  1
	zfs_vdev_raidz_impl                               [fastest] original scalar sse2 ssse3
	zfs_arc_meta_limit                                0
	zfs_flags                                         0
	zfs_dirty_data_max_max                            16880489472
	zfs_arc_average_blocksize                         8192
	zfs_vdev_cache_bshift                             16
	zfs_vdev_async_read_min_active                    1
	zfs_arc_dnode_reduce_percent                      10
	zfs_free_bpobj_enabled                            1
	zfs_arc_num_sublists_per_state                    32
	zfs_arc_grow_retry                                0
	zfs_vdev_mirror_rotating_inc                      0
	l2arc_feed_again                                  1
	zfs_vdev_mirror_non_rotating_inc                  0
	zfs_arc_lotsfree_percent                          10
	zfs_zevent_console                                0
	zvol_prefetch_bytes                               131072
	zfs_free_min_time_ms                              1000
	zfs_arc_dnode_limit_percent                       10
	zio_taskq_batch_pct                               75
	dbuf_cache_max_bytes                              104857600
	spa_load_verify_data                              1
	zfs_delete_blocks                                 20480
	zfs_vdev_mirror_non_rotating_seek_inc             1
	zfs_dirty_data_max                                6752195788
	zfs_vdev_async_write_max_active                   10
	zfs_dbgmsg_maxsize                                4194304
	zfs_nocacheflush                                  0
	zfetch_array_rd_sz                                1048576
	zfs_arc_meta_strategy                             1
	zfs_dirty_data_sync                               67108864
	zvol_max_discard_blocks                           16384
	zfs_vdev_async_write_active_max_dirty_percent     60
	zfs_arc_p_dampener_disable                        1
	zfs_txg_timeout                                   5
	metaslab_aliquot                                  524288
	zfs_mdcomp_disable                                0
	zfs_vdev_sync_read_min_active                     10
	zfs_arc_dnode_limit                               0
	dbuf_cache_lowater_pct                            10
	zfs_abd_scatter_max_order                         10
	metaslab_debug_load                               0
	zfs_vdev_aggregation_limit                        131072
	metaslab_lba_weighting_enabled                    1
	zfs_vdev_scheduler                                noop
	zfs_vdev_scrub_min_active                         1
	zfs_no_scrub_io                                   0
	zfs_vdev_cache_max                                16384
	zfs_scan_idle                                     50
	zfs_arc_shrink_shift                              0
	spa_slop_shift                                    5
	zfs_vdev_mirror_rotating_seek_inc                 5
	zfs_deadman_synctime_ms                           1000000
	send_holes_without_birth_time                     1
	metaslab_bias_enabled                             1
	zfs_admin_snapshot                                1
	zfs_no_scrub_prefetch                             0
	zfs_metaslab_fragmentation_threshold              70
	zfs_max_recordsize                                1048576
	zfs_arc_min                                       0
	zfs_nopwrite_enabled                              1
	zfs_arc_p_min_shift                               0
	zfs_vdev_queue_depth_pct                          1000
	zfs_mg_fragmentation_threshold                    85
	l2arc_write_boost                                 8388608
	zfs_prefetch_disable                              0
	l2arc_feed_min_ms                                 200
	zio_delay_max                                     30000
	zfs_vdev_write_gap_limit                          4096
	zfs_pd_bytes_max                                  52428800
	zfs_scan_min_time_ms                              1000
	zfs_resilver_min_time_ms                          3000
	zfs_delay_scale                                   500000
	zfs_vdev_async_write_active_min_dirty_percent     30
	zfs_vdev_sync_write_max_active                    10
	zfs_mg_noalloc_threshold                          0
	zfs_deadman_enabled                               1
	zfs_resilver_delay                                2
	zfs_arc_max                                       0
	zfs_top_maxinflight                               32
	zfetch_min_sec_reap                               2
	zfs_immediate_write_sz                            32768
	zfs_vdev_async_write_min_active                   1
	zfs_sync_pass_dont_compress                       5
	zfs_vdev_read_gap_limit                           32768
	zfs_compressed_arc_enabled                        1
	zfs_vdev_max_active                               1000

perf record tar cf /dev/stdout /usr/include 2>/dev/null | cat>/dev/null:
(test repeated a few times, this is the report of the last invocation)

# To display the perf.data header info, please use --header/--header-only options.
#
#
# Total Lost Samples: 0
#
# Samples: 4K of event 'cycles:pp'
# Event count (approx.): 3461844774
#
# Overhead  Command  Shared Object     Symbol                             
# ........  .......  ................  ...................................
#
     4.87%  tar      [kernel.vmlinux]  [k] mutex_lock                     
     4.03%  tar      [kernel.vmlinux]  [k] copy_user_generic_string       
     2.78%  tar      [kernel.vmlinux]  [k] _raw_spin_lock                 
     2.75%  tar      [zfs]             [k] 0x0000000000045b74             
     2.58%  tar      [zfs]             [k] 0x0000000000045c09             
     2.36%  tar      [kernel.vmlinux]  [k] mutex_unlock                   
     2.30%  tar      [zfs]             [k] dmu_object_size_from_db        
     1.66%  tar      [kernel.vmlinux]  [k] kmem_cache_alloc               
     1.64%  tar      [kernel.vmlinux]  [k] __list_del_entry               
     1.60%  tar      [kernel.vmlinux]  [k] __d_lookup_rcu                 
     1.59%  tar      [zfs]             [k] 0x0000000000045b28             
     1.58%  tar      [zfs]             [k] 0x0000000000045c14             
     1.26%  tar      [kernel.vmlinux]  [k] __memcpy                       
     1.13%  tar      [zfs]             [k] 0x0000000000045bed             
     1.12%  tar      [kernel.vmlinux]  [k] preempt_count_add              
     1.12%  tar      tar               [.] simple_finish_header           
     1.10%  tar      [zfs]             [k] 0x0000000000045b1d             
     1.07%  tar      [zfs]             [k] zrl_add                        
     1.01%  tar      [kernel.vmlinux]  [k] kmem_cache_alloc_node          
     0.99%  tar      [zfs]             [k] 0x0000000000045b7b             
     0.79%  tar      [kernel.vmlinux]  [k] do_dentry_open                 
     0.77%  tar      tar               [.] dump_file                      
     0.73%  tar      [spl]             [k] __cv_broadcast                 
     0.72%  tar      [zfs]             [k] 0x0000000000045b17             
     0.68%  tar      [zfs]             [k] 0x0000000000045b48             
     0.66%  tar      [zfs]             [k] 0x0000000000045c69             
     0.64%  tar      [zfs]             [k] dbuf_find                      
     0.63%  tar      [kernel.vmlinux]  [k] entry_SYSCALL_64_fastpath      
     0.61%  tar      [zfs]             [k] 0x0000000000045b60             
     0.57%  tar      [kernel.vmlinux]  [k] kfree                          
     0.55%  tar      [kernel.vmlinux]  [k] __check_object_size            
     0.54%  tar      [kernel.vmlinux]  [k] ___cache_free                  
     0.53%  tar      [zfs]             [k] 0x0000000000045ce2             
     0.53%  tar      [zfs]             [k] dnode_block_freed              
     0.52%  tar      [kernel.vmlinux]  [k] __memset                       
     0.52%  tar      [zfs]             [k] 0x0000000000045b42             
     0.52%  tar      [zfs]             [k] 0x00000000000b45e4             
     0.52%  tar      [zavl]            [k] avl_add                        
     0.50%  tar      [spl]             [k] spl_kmem_cache_alloc           
     0.50%  tar      [zfs]             [k] 0x0000000000045b9e             
     0.48%  tar      tar               [.] start_header                   
     0.48%  tar      [zfs]             [k] 0x0000000000045c07             
     0.48%  tar      [zfs]             [k] 0x0000000000001fe3             
     0.48%  tar      [zfs]             [k] 0x0000000000045b37             
     0.48%  tar      [zfs]             [k] 0x0000000000045b3a             
     0.46%  tar      [zfs]             [k] 0x0000000000045aed             
     0.46%  tar      [kernel.vmlinux]  [k] entry_SYSCALL_64               
     0.44%  tar      [kernel.vmlinux]  [k] check_preemption_disabled      
     0.44%  tar      [kernel.vmlinux]  [k] enqueue_task_fair              
     0.42%  tar      [kernel.vmlinux]  [k] down_read                      
     0.42%  tar      [kernel.vmlinux]  [k] fsnotify                       
     0.42%  tar      [kernel.vmlinux]  [k] in_lock_functions              
     0.42%  tar      [zfs]             [k] 0x0000000000045afb             
     0.41%  tar      [zfs]             [k] 0x0000000000001f51             
     0.40%  tar      [zfs]             [k] 0x0000000000045c1d             
     0.40%  tar      [zfs]             [k] lz4_decompress_zfs             
     0.39%  tar      [kernel.vmlinux]  [k] _raw_spin_lock_irqsave         
     0.39%  tar      libc-2.23.so      [.] strlen                         
     0.39%  tar      [kernel.vmlinux]  [k] __virt_addr_valid              
     0.39%  tar      libc-2.23.so      [.] _int_free                      
     0.37%  tar      [zfs]             [k] dbuf_rele_and_unlock           
     0.37%  tar      [zfs]             [k] zfs_read                       
     0.35%  tar      libc-2.23.so      [.] __strcpy_sse2_unaligned        
     0.35%  tar      [kernel.vmlinux]  [k] __fget_light                   
     0.35%  tar      [kernel.vmlinux]  [k] preempt_count_sub              
     0.35%  tar      [zfs]             [k] arc_space_consume              
     0.35%  tar      tar               [.] safer_name_suffix              
     0.33%  tar      [zfs]             [k] 0x0000000000001fc9             
     0.33%  tar      tar               [.] write_short_name.isra.0        
     0.31%  tar      [zfs]             [k] zrl_remove                     
     0.30%  tar      [zfs]             [k] zio_wait                       
     0.29%  tar      [kernel.vmlinux]  [k] select_task_rq_fair            
     0.29%  tar      [kernel.vmlinux]  [k] alloc_pages_current            
     0.28%  tar      [zfs]             [k] arc_state_multilist_index_func 
     0.28%  tar      [zfs]             [k] 0x0000000000045af5             
     0.28%  tar      [spl]             [k] spl_kmem_alloc                 
     0.28%  tar      [zfs]             [k] 0x0000000000045c10             
     0.28%  tar      [spl]             [k] __cv_destroy                   
     0.26%  tar      libc-2.23.so      [.] malloc                         
     0.26%  tar      tar               [.] dump_regular_file              
     0.26%  tar      [zfs]             [k] 0x000000000000e189             
     0.26%  tar      [zfs]             [k] 0x0000000000045ae3             
     0.26%  tar      [zfs]             [k] 0x000000000000ca7a             
     0.26%  tar      [kernel.vmlinux]  [k] get_page_from_freelist         
     0.26%  tar      [zfs]             [k] 0x0000000000045aea             
     0.24%  tar      [kernel.vmlinux]  [k] filldir                        
     0.24%  tar      [kernel.vmlinux]  [k] vfs_getattr_nosec              
     0.24%  tar      tar               [.] to_chars                       
     0.24%  tar      libc-2.23.so      [.] _int_malloc                    
     0.24%  tar      libc-2.23.so      [.] __memcpy_sse2_unaligned        
     0.24%  tar      [kernel.vmlinux]  [k] __call_rcu.constprop.71        
     0.24%  tar      [zfs]             [k] 0x0000000000045b0a             
     0.22%  tar      [kernel.vmlinux]  [k] lockref_get_not_dead           
     0.22%  tar      [kernel.vmlinux]  [k] path_init                      
     0.22%  tar      tar               [.] tar_stat_destroy               
     0.22%  tar      [kernel.vmlinux]  [k] pipe_write                     
     0.22%  tar      [zcommon]         [k] uiomove                        
     0.22%  tar      [zfs]             [k] 0x0000000000045af0             
     0.22%  tar      [kernel.vmlinux]  [k] __alloc_pages_nodemask         
     0.20%  tar      tar               [.] safe_read                      
     0.20%  tar      [zfs]             [k] 0x0000000000045ae7             
     0.20%  tar      [zfs]             [k] 0x0000000000045c78             
     0.20%  tar      tar               [.] _init                          
     0.20%  tar      tar               [.] _flush_write                   
     0.20%  tar      [zfs]             [k] 0x0000000000004706             
     0.20%  tar      [kernel.vmlinux]  [k] kmem_cache_free                
     0.20%  tar      [zfs]             [k] 0x0000000000045cb5             
     0.20%  tar      [zfs]             [k] dmu_zfetch                     
     0.20%  tar      tar               [.] excluded_name                  
     0.20%  tar      [zfs]             [k] 0x0000000000004a30             
     0.19%  tar      [kernel.vmlinux]  [k] exit_to_usermode_loop          
     0.18%  tar      tar               [.] uid_to_uname                   
     0.18%  tar      tar               [.] xattrs_selinux_get             
     0.18%  tar      [zfs]             [k] rrw_exit                       
     0.18%  tar      [kernel.vmlinux]  [k] link_path_walk                 
     0.18%  tar      [kernel.vmlinux]  [k] idle_cpu                       
     0.17%  tar      [kernel.vmlinux]  [k] _raw_write_unlock              
     0.17%  tar      [kernel.vmlinux]  [k] lookup_fast                    
     0.17%  tar      [kernel.vmlinux]  [k] getrawmonotonic64              
     0.17%  tar      [zfs]             [k] sa_object_size                 
     0.17%  tar      tar               [.] group_map_translate            
     0.17%  tar      [zfs]             [k] zfs_getattr_fast               
     0.17%  tar      [kernel.vmlinux]  [k] sg_next                        
     0.16%  tar      [zfs]             [k] 0x00000000000049e7             
     0.15%  tar      [zfs]             [k] 0x0000000000001ff9             
     0.15%  tar      [kernel.vmlinux]  [k] lockref_put_return             
     0.15%  tar      [kernel.vmlinux]  [k] path_lookupat                  
     0.15%  tar      [zfs]             [k] multilist_insert               
     0.15%  tar      [kernel.vmlinux]  [k] resched_curr                   
     0.15%  tar      [zfs]             [k] dbuf_cache_multilist_index_func
     0.15%  tar      [kernel.vmlinux]  [k] strncpy_from_user              
     0.15%  tar      [zfs]             [k] 0x000000000000f300             
     0.15%  tar      [spl]             [k] crfree                         
     0.15%  tar      libc-2.23.so      [.] free                           
     0.15%  tar      [kernel.vmlinux]  [k] read_tsc                       
     0.15%  tar      tar               [.] flush_archive                  
     0.15%  tar      tar               [.] blocking_read                  
     0.15%  tar      [spl]             [k] taskq_init_ent                 
     0.15%  tar      [kernel.vmlinux]  [k] security_file_permission       
     0.15%  tar      [zfs]             [k] dbuf_add_ref                   
     0.15%  tar      [kernel.vmlinux]  [k] do_sys_open                    
     0.15%  tar      [zfs]             [k] 0x0000000000045c3b             
     0.15%  tar      [zfs]             [k] 0x0000000000045b6e             
     0.15%  tar      [kernel.vmlinux]  [k] getname_flags                  
     0.15%  tar      [kernel.vmlinux]  [k] __percpu_counter_add           
     0.13%  tar      libc-2.23.so      [.] __strcmp_sse2_unaligned        
     0.13%  tar      [kernel.vmlinux]  [k] __check_heap_object            
     0.13%  tar      tar               [.] finish_header                  
     0.13%  tar      tar               [.] gnu_flush_write                
     0.13%  tar      [zfs]             [k] 0x000000000000f535             
     0.13%  tar      [zunicode]        [k] 0x00000000000023a9             
     0.13%  tar      [zfs]             [k] dbuf_hold_impl                 
     0.13%  tar      [zfs]             [k] 0x0000000000045c6f             
     0.13%  tar      [kernel.vmlinux]  [k] copy_page_from_iter            
     0.13%  tar      [zfs]             [k] 0x000000000002751d             
     0.13%  tar      [zfs]             [k] 0x0000000000045b5c             
     0.13%  tar      [kernel.vmlinux]  [k] list_del                       
     0.13%  tar      [zfs]             [k] vdev_stat_update               
     0.13%  tar      [zfs]             [k] arc_released                   
     0.13%  tar      [kernel.vmlinux]  [k] path_openat                    
     0.13%  tar      libc-2.23.so      [.] __GI___libc_write              
     0.13%  tar      [zfs]             [k] 0x000000000000c66f             
     0.13%  tar      [kernel.vmlinux]  [k] __list_add                     
     0.11%  tar      [zfs]             [k] zfs_range_lock                 
     0.11%  tar      [zfs]             [k] dbuf_hold                      
     0.11%  tar      [kernel.vmlinux]  [k] __rcu_read_unlock              
     0.11%  tar      tar               [.] tar_stat_close                 
     0.11%  tar      [zavl]            [k] avl_find                       
     0.11%  tar      [zfs]             [k] 0x0000000000045ba9             
     0.11%  tar      [zfs]             [k] 0x0000000000045cc8             
     0.11%  tar      [zfs]             [k] zio_decompress_data            
     0.11%  tar      [kernel.vmlinux]  [k] filename_lookup                
     0.11%  tar      [zfs]             [k] 0x000000000000f7d8             
     0.11%  tar      libc-2.23.so      [.] __GI___openat64                
     0.11%  tar      [kernel.vmlinux]  [k] get_task_policy.part.27        
     0.11%  tar      [zfs]             [k] dbuf_whichblock                
     0.11%  tar      [zfs]             [k] 0x0000000000045c1f             
     0.11%  tar      tar               [.] xattrs_xattrs_get              
     0.11%  tar      [kernel.vmlinux]  [k] strcpy                         
     0.11%  tar      [kernel.vmlinux]  [k] mutex_spin_on_owner.isra.4     
     0.11%  tar      libc-2.23.so      [.] __fxstat64                     
     0.11%  tar      [zfs]             [k] 0x000000000000441b             
     0.11%  tar      [kernel.vmlinux]  [k] is_vmalloc_or_module_addr      
     0.11%  tar      tar               [.] xmemdup                        
     0.11%  tar      [kernel.vmlinux]  [k] task_work_run                  
     0.11%  tar      [kernel.vmlinux]  [k] __wake_up_common               
     0.11%  tar      [kernel.vmlinux]  [k] terminate_walk                 
     0.11%  tar      [kernel.vmlinux]  [k] policy_zonelist                
     0.11%  tar      [kernel.vmlinux]  [k] __vfs_write                    
     0.11%  tar      [kernel.vmlinux]  [k] mutex_optimistic_spin          
     0.11%  tar      [kernel.vmlinux]  [k] __rmqueue                      
     0.11%  tar      [kernel.vmlinux]  [k] __alloc_fd                     
     0.11%  tar      [zfs]             [k] arc_read                       
     0.11%  tar      tar               [.] xattrs_acls_get                
     0.11%  tar      libc-2.23.so      [.] realloc                        
     0.11%  tar      libc-2.23.so      [.] _int_realloc                   
     0.11%  tar      [zfs]             [k] abd_return_buf                 
     0.09%  tar      [zfs]             [k] multilist_remove               
     0.09%  tar      [zfs]             [k] 0x0000000000045b01             
     0.09%  tar      [kernel.vmlinux]  [k] task_work_add                  
     0.09%  tar      libc-2.23.so      [.] __GI___libc_close              
     0.09%  tar      [zfs]             [k] 0x000000000007ad5c             
     0.09%  tar      [kernel.vmlinux]  [k] generic_fillattr               
     0.09%  tar      [kernel.vmlinux]  [k] update_wall_time               
     0.09%  tar      [kernel.vmlinux]  [k] vfs_write                      
     0.09%  tar      [kernel.vmlinux]  [k] dput                           
     0.09%  tar      [kernel.vmlinux]  [k] __rcu_read_lock                
     0.09%  tar      [kernel.vmlinux]  [k] __inode_permission             
     0.09%  tar      [zfs]             [k] 0x0000000000045b82             
     0.09%  tar      [kernel.vmlinux]  [k] __atime_needs_update           
     0.09%  tar      [kernel.vmlinux]  [k] __sb_start_write               
     0.09%  tar      tar               [.] tar_stat_init                  
     0.09%  tar      [kernel.vmlinux]  [k] activate_task                  
     0.09%  tar      [zfs]             [k] decode_embedded_bp_compressed  
     0.09%  tar      [kernel.vmlinux]  [k] strlen                         
     0.09%  tar      [zfs]             [k] 0x0000000000045b31             
     0.09%  tar      tar               [.] sys_write_archive_buffer       
     0.09%  tar      [kernel.vmlinux]  [k] _raw_spin_unlock               
     0.09%  tar      [kernel.vmlinux]  [k] security_inode_getattr         
     0.09%  tar      [kernel.vmlinux]  [k] __fput                         
     0.09%  tar      [kernel.vmlinux]  [k] lockref_get                    
     0.09%  tar      tar               [.] sys_file_is_archive            
     0.09%  tar      [zfs]             [k] zfs_readdir                    
     0.09%  tar      [kernel.vmlinux]  [k] debug_smp_processor_id         
     0.09%  tar      [spl]             [k] crhold                         
     0.09%  tar      tar               [.] safe_hasher                    
     0.09%  tar      [zfs]             [k] 0x00000000000a9c50             
     0.09%  tar      [zavl]            [k] avl_insert                     
     0.09%  tar      [kernel.vmlinux]  [k] unlazy_walk                    
     0.09%  tar      [kernel.vmlinux]  [k] place_entity                   
     0.09%  tar      [zfs]             [k] rrm_exit                       
     0.09%  tar      [zfs]             [k] 0x000000000000f59b             
     0.09%  tar      [kernel.vmlinux]  [k] get_empty_filp                 
     0.09%  tar      [zfs]             [k] zap_cursor_retrieve            
     0.09%  tar      [zfs]             [k] dnode_hold_impl                
     0.09%  tar      [kernel.vmlinux]  [k] vfs_read                       
     0.09%  tar      [zfs]             [k] 0x0000000000045b67             
     0.07%  tar      tar               [.] xmalloc                        
     0.07%  tar      [zfs]             [k] zfs_range_unlock               
     0.07%  tar      [kernel.vmlinux]  [k] rcu_check_callbacks            
     0.07%  tar      [kernel.vmlinux]  [k] expand_files                   
     0.07%  tar      tar               [.] streamsavedir                  
     0.07%  tar      [zfs]             [k] abd_borrow_buf                 
     0.07%  tar      tar               [.] full_write                     
     0.07%  tar      tar               [.] checkpoint_run                 
     0.07%  tar      [zfs]             [k] __dmu_object_info_from_dnode   
     0.07%  tar      [kernel.vmlinux]  [k] may_open                       
     0.07%  tar      [zfs]             [k] 0x000000000007abb1             
     0.07%  tar      tar               [.] transform_name                 
     0.07%  tar      [kernel.vmlinux]  [k] __init_waitqueue_head          
     0.07%  tar      [zavl]            [k] avl_walk                       
     0.07%  tar      [zfs]             [k] zio_nowait                     
     0.07%  tar      [zfs]             [k] sa_attr_op                     
     0.07%  tar      [zfs]             [k] 0x00000000000036b1             
     0.07%  tar      [kernel.vmlinux]  [k] file_free_rcu                  
     0.07%  tar      [kernel.vmlinux]  [k] _copy_to_user                  
     0.07%  tar      [zfs]             [k] 0x00000000000ac3b4             
     0.07%  tar      [zfs]             [k] 0x000000000007abbb             
     0.07%  tar      [kernel.vmlinux]  [k] timespec_trunc                 
     0.07%  tar      [zfs]             [k] 0x0000000000003c44             
     0.07%  tar      [kernel.vmlinux]  [k] __fdget_pos                    
     0.07%  tar      [kernel.vmlinux]  [k] dnotify_flush                  
     0.07%  tar      tar               [.] info_free_exclist              
     0.07%  tar      [zfs]             [k] 0x000000000007b090             
     0.07%  tar      [kernel.vmlinux]  [k] __mutex_init                   
     0.07%  tar      [zfs]             [k] 0x000000000000c68c             
     0.07%  tar      [zfs]             [k] zio_null                       
     0.07%  tar      [zfs]             [k] 0x00000000000a9ca5             
     0.07%  tar      [zfs]             [k] 0x0000000000045c1b             
     0.07%  tar      [kernel.vmlinux]  [k] security_inode_permission      
     0.07%  tar      [zfs]             [k] 0x000000000000f85d             
     0.07%  tar      libc-2.23.so      [.] malloc_consolidate             
     0.07%  tar      [kernel.vmlinux]  [k] kmalloc_slab                   
     0.07%  tar      tar               [.] owner_map_translate            
     0.07%  tar      [kernel.vmlinux]  [k] try_to_wake_up                 
     0.07%  tar      tar               [.] transform_name_fp              
     0.07%  tar      [spl]             [k] spl_kmem_cache_free            
     0.07%  tar      [zfs]             [k] dmu_read_uio_dbuf              
     0.07%  tar      [zfs]             [k] zap_name_alloc                 
     0.07%  tar      [zavl]            [k] avl_remove                     
     0.07%  tar      [kernel.vmlinux]  [k] up_read                        
     0.07%  tar      [zunicode]        [k] 0x000000000000248e             
     0.07%  tar      [kernel.vmlinux]  [k] syscall_return_slowpath        
     0.07%  tar      [zfs]             [k] multilist_link_active          
     0.07%  tar      tar               [.] hash_find_entry                
     0.07%  tar      tar               [.] excluded_file_name             
     0.06%  tar      [zfs]             [k] 0x0000000000001fed             
     0.06%  tar      [kernel.vmlinux]  [k] locks_remove_file              
     0.06%  tar      [zfs]             [k] 0x0000000000001f30             
     0.06%  tar      [kernel.vmlinux]  [k] cp_new_stat                    
     0.06%  tar      libc-2.23.so      [.] __GI___libc_read               
     0.06%  tar      [zfs]             [k] 0x0000000000045c0c             
     0.05%  tar      [zfs]             [k] arc_get_compression            
     0.04%  tar      [zfs]             [k] 0x0000000000003fed             
     0.04%  tar      [zfs]             [k] 0x0000000000001f6f             
     0.04%  tar      libc-2.23.so      [.] __readdir64                    
     0.04%  tar      [kernel.vmlinux]  [k] rcu_process_callbacks          
     0.04%  tar      [kernel.vmlinux]  [k] __vfs_read                     
     0.04%  tar      [kernel.vmlinux]  [k] _raw_write_unlock_irqrestore   
     0.04%  tar      [kernel.vmlinux]  [k] perf_event_task_tick           
     0.04%  tar      [zfs]             [k] zfs_close                      
     0.04%  tar      tar               [.] gid_to_gname                   
     0.04%  tar      [zfs]             [k] abd_alloc_linear               
     0.04%  tar      [kernel.vmlinux]  [k] file_update_time               
     0.04%  tar      libc-2.23.so      [.] __getdents64                   
     0.04%  tar      [zfs]             [k] 0x000000000000c64b             
     0.04%  tar      [zfs]             [k] 0x0000000000045c95             
     0.04%  tar      libc-2.23.so      [.] __memmove_sse2                 
     0.04%  tar      [zfs]             [k] dbuf_destroy                   
     0.04%  tar      [zfs]             [k] 0x0000000000045b24             
     0.04%  tar      tar               [.] mode_to_chars.constprop.5      
     0.04%  tar      tar               [.] available_space_after          
     0.04%  tar      [zfs]             [k] 0x0000000000016e51             
     0.04%  tar      [kernel.vmlinux]  [k] policy_nodemask                
     0.04%  tar      [kernel.vmlinux]  [k] follow_managed                 
     0.04%  tar      tar               [.] xstrdup                        
     0.04%  tar      [kernel.vmlinux]  [k] note_gp_changes                
     0.04%  tar      [kernel.vmlinux]  [k] task_tick_fair                 
     0.04%  tar      tar               [.] set_next_block_after           
     0.04%  tar      [zfs]             [k] 0x00000000000ac33a             
     0.04%  tar      [kernel.vmlinux]  [k] rw_verify_area                 
     0.04%  tar      [zfs]             [k] 0x000000000000f2f5             
     0.04%  tar      [kernel.vmlinux]  [k] get_unused_fd_flags            
     0.04%  tar      [kernel.vmlinux]  [k] rcu_accelerate_cbs             
     0.04%  tar      [kernel.vmlinux]  [k] from_kgid_munged               
     0.04%  tar      [zfs]             [k] 0x00000000000b00b0             
     0.04%  tar      [zfs]             [k] spa_feature_is_enabled         
     0.04%  tar      [zfs]             [k] 0x0000000000045a68             
     0.04%  tar      [zfs]             [k] arc_buf_destroy                
     0.04%  tar      tar               [.] hash_string_hasher             
     0.04%  tar      [kernel.vmlinux]  [k] __sb_end_write                 
     0.04%  tar      [zfs]             [k] 0x00000000000af68b             
     0.04%  tar      libc-2.23.so      [.] __fxstatat64                   
     0.04%  tar      [zfs]             [k] zio_push_transform             
     0.04%  tar      [zfs]             [k] 0x000000000000f710             
     0.04%  tar      [zunicode]        [k] 0x0000000000002364             
     0.04%  tar      [kernel.vmlinux]  [k] cpu_needs_another_gp           
     0.04%  tar      [kernel.vmlinux]  [k] touch_atime                    
     0.04%  tar      [zfs]             [k] 0x00000000000ac6a2             
     0.04%  tar      [kernel.vmlinux]  [k] ret_from_intr                  
     0.04%  tar      [kernel.vmlinux]  [k] generic_permission             
     0.04%  tar      [kernel.vmlinux]  [k] mntput_no_expire               
     0.04%  tar      [kernel.vmlinux]  [k] sys_read                       
     0.04%  tar      [zfs]             [k] 0x00000000000022bf             
     0.04%  tar      [zfs]             [k] 0x000000000004b6d5             
     0.04%  tar      [kernel.vmlinux]  [k] kill_fasync                    
     0.04%  tar      [zfs]             [k] 0x0000000000045a20             
     0.04%  tar      [kernel.vmlinux]  [k] check_preempt_curr             
     0.04%  tar      [zfs]             [k] 0x00000000000b01f6             
     0.04%  tar      [zfs]             [k] abd_borrow_buf_copy            
     0.04%  tar      [zfs]             [k] 0x00000000000ac267             
     0.04%  tar      [kernel.vmlinux]  [k] vfs_getattr                    
     0.04%  tar      [zfs]             [k] 0x000000000007b09a             
     0.04%  tar      [zfs]             [k] 0x00000000000b4580             
     0.04%  tar      [zfs]             [k] 0x00000000000a9c74             
     0.04%  tar      [kernel.vmlinux]  [k] file_ra_state_init             
     0.04%  tar      [zfs]             [k] 0x000000000000401b             
     0.04%  tar      [kernel.vmlinux]  [k] do_filp_open                   
     0.04%  tar      [kernel.vmlinux]  [k] smp_trace_apic_timer_interrupt 
     0.04%  tar      [kernel.vmlinux]  [k] from_kuid_munged               
     0.04%  tar      [kernel.vmlinux]  [k] _find_next_bit.part.0          
     0.04%  tar      [kernel.vmlinux]  [k] vfs_fstat                      
     0.04%  tar      [zunicode]        [k] 0x0000000000002368             
     0.04%  tar      [kernel.vmlinux]  [k] __close_fd                     
     0.04%  tar      tar               [.] find_next_block                
     0.04%  tar      [kernel.vmlinux]  [k] SYSC_newfstat                  
     0.04%  tar      [zfs]             [k] 0x000000000000c62f             
     0.04%  tar      [zfs]             [k] 0x000000000007b837             
     0.04%  tar      [kernel.vmlinux]  [k] __inc_zone_state               
     0.04%  tar      [kernel.vmlinux]  [k] syscall_return_via_sysret      
     0.04%  tar      [spl]             [k] spl_kmem_zalloc                
     0.04%  tar      [zfs]             [k] 0x000000000004b6eb             
     0.04%  tar      [spl]             [k] tsd_get                        
     0.02%  tar      [kernel.vmlinux]  [k] vfs_fstatat                    
     0.02%  tar      [zfs]             [k] 0x00000000000ac509             
     0.02%  tar      [zfs]             [k] 0x0000000000045a23             
     0.02%  tar      [zfs]             [k] 0x0000000000016d28             
     0.02%  tar      [zfs]             [k] 0x000000000004b750             
     0.02%  tar      [zfs]             [k] 0x00000000000b305c             
     0.02%  tar      [zavl]            [k] 0x0000000000000368             
     0.02%  tar      [zfs]             [k] 0x0000000000004a24             
     0.02%  tar      [zfs]             [k] 0x00000000000b3b91             
     0.02%  tar      [kernel.vmlinux]  [k] ttwu_do_wakeup                 
     0.02%  tar      [zfs]             [k] 0x0000000000016d07             
     0.02%  tar      [zfs]             [k] 0x00000000000ac2e6             
     0.02%  tar      [kernel.vmlinux]  [k] perf_pmu_disable               
     0.02%  tar      [zfs]             [k] 0x00000000000b0291             
     0.02%  tar      [zfs]             [k] 0x00000000000af9c7             
     0.02%  tar      [zfs]             [k] spa_load_guid                  
     0.02%  tar      [zfs]             [k] 0x00000000000035e2             
     0.02%  tar      [kernel.vmlinux]  [k] mntput                         
     0.02%  tar      [kernel.vmlinux]  [k] walk_component                 
     0.02%  tar      [zfs]             [k] 0x000000000000c680             
     0.02%  tar      [zunicode]        [k] 0x00000000000023c7             
     0.02%  tar      [zfs]             [k] 0x00000000000ac29d             
     0.02%  tar      [kernel.vmlinux]  [k] native_irq_return_iret         
     0.02%  tar      [spl]             [k] __cv_init                      
     0.02%  tar      tar               [.] restore_parent_fd              
     0.02%  tar      [kernel.vmlinux]  [k] security_file_free             
     0.02%  tar      [zfs]             [k] zio_read                       
     0.02%  tar      [zfs]             [k] dbuf_rele                      
     0.02%  tar      [zfs]             [k] 0x00000000000ac531             
     0.02%  tar      [zfs]             [k] 0x0000000000001f7c             
     0.02%  tar      [kernel.vmlinux]  [k] __mark_inode_dirty             
     0.02%  tar      [zfs]             [k] 0x0000000000045ccd             
     0.02%  tar      tar               [.] mv_begin_write                 
     0.02%  tar      [zavl]            [k] 0x000000000000041a             
     0.02%  tar      [zfs]             [k] 0x000000000007bbf1             
     0.02%  tar      [zfs]             [k] 0x0000000000016ab0             
     0.02%  tar      [zfs]             [k] 0x000000000007b0ab             
     0.02%  tar      [kernel.vmlinux]  [k] __intel_pmu_enable_all         
     0.02%  tar      [kernel.vmlinux]  [k] iterate_dir                    
     0.02%  tar      [zfs]             [k] 0x0000000000045c8f             
     0.02%  tar      [kernel.vmlinux]  [k] complete_walk                  
     0.02%  tar      [zfs]             [k] 0x000000000007ab43             
     0.02%  tar      [zfs]             [k] 0x00000000000040d5             
     0.02%  tar      [zfs]             [k] 0x0000000000017185             
     0.02%  tar      [kernel.vmlinux]  [k] fput                           
     0.02%  tar      [zfs]             [k] 0x000000000000c697             
     0.02%  tar      [zfs]             [k] 0x000000000000f5ab             
     0.02%  tar      [kernel.vmlinux]  [k] update_curr                    
     0.02%  tar      [zunicode]        [k] 0x0000000000002488             
     0.02%  tar      [zfs]             [k] zio_data_buf_alloc             
     0.02%  tar      [zavl]            [k] avl_nearest                    
     0.02%  tar      [zfs]             [k] 0x0000000000045b88             
     0.02%  tar      [kernel.vmlinux]  [k] filp_close                     
     0.02%  tar      [zfs]             [k] 0x00000000000af7e1             
     0.02%  tar      [kernel.vmlinux]  [k] __zone_watermark_ok            
     0.02%  tar      tar               [.] hash_string                    
     0.02%  tar      [zfs]             [k] 0x00000000000af808             
     0.02%  tar      [zfs]             [k] 0x00000000000af6ae             
     0.02%  tar      [kernel.vmlinux]  [k] flush_tlb_mm_range             
     0.02%  tar      [zfs]             [k] 0x000000000007b55d             
     0.02%  tar      [zfs]             [k] 0x00000000000046d7             
     0.02%  tar      [zfs]             [k] 0x000000000007ad3a             
     0.02%  tar      tar               [.] safe_write                     
     0.02%  tar      [zfs]             [k] 0x000000000004b7cd             
     0.02%  tar      [kernel.vmlinux]  [k] SYSC_newfstatat                
     0.02%  tar      [kernel.vmlinux]  [k] cpus_share_cache               
     0.02%  tar      [zfs]             [k] 0x00000000000045dc             
     0.02%  tar      [kernel.vmlinux]  [k] transfer_objects               
     0.02%  tar      [zfs]             [k] 0x000000000000e7b5             
     0.02%  tar      [zavl]            [k] avl_numnodes                   
     0.02%  tar      [zfs]             [k] 0x000000000007b0a0             
     0.02%  tar      [zavl]            [k] 0x000000000000046f             
     0.02%  tar      [kernel.vmlinux]  [k] perf_pmu_sched_task            
     0.02%  tar      [zfs]             [k] 0x0000000000045cd0             
     0.02%  tar      [zfs]             [k] 0x00000000000b3612             
     0.02%  tar      [zfs]             [k] 0x000000000000ca60             
     0.02%  tar      tar               [.] hash_insert_if_absent          
     0.02%  tar      [zfs]             [k] dmu_objset_spa                 
     0.02%  tar      [kernel.vmlinux]  [k] __kmalloc_node                 
     0.02%  tar      [zfs]             [k] 0x00000000000b45a3             
     0.02%  tar      [kernel.vmlinux]  [k] native_sched_clock             
     0.02%  tar      [zfs]             [k] 0x0000000000001ff3             
     0.02%  tar      [zfs]             [k] 0x000000000000f2db             
     0.02%  tar      [zfs]             [k] 0x0000000000016b2e             
     0.02%  tar      [zfs]             [k] 0x00000000000a9cb6             
     0.02%  tar      [zunicode]        [k] 0x000000000000235a             
     0.02%  tar      [zfs]             [k] 0x0000000000016c2c             
     0.02%  tar      [kernel.vmlinux]  [k] user_path_at_empty             
     0.02%  tar      [zfs]             [k] 0x00000000000b3f79             
     0.02%  tar      [zfs]             [k] 0x0000000000016e43             
     0.02%  tar      [zfs]             [k] 0x0000000000001fb3             
     0.02%  tar      [kernel.vmlinux]  [k] ktime_get_update_offsets_now   
     0.02%  tar      [zfs]             [k] 0x000000000000f50d             
     0.02%  tar      [zfs]             [k] 0x00000000000af3c8             
     0.02%  tar      [kernel.vmlinux]  [k] timerqueue_del                 
     0.02%  tar      [zfs]             [k] 0x00000000000aaa70             
     0.02%  tar      [zfs]             [k] 0x000000000000368e             
     0.02%  tar      [zfs]             [k] 0x00000000000b3bce             
     0.02%  tar      [zfs]             [k] 0x000000000000f34f             
     0.02%  tar      [zfs]             [k] abd_to_buf                     
     0.02%  tar      [zfs]             [k] 0x0000000000001f8a             
     0.02%  tar      [zfs]             [k] zio_buf_free                   
     0.02%  tar      [zfs]             [k] zap_cursor_init_serialized     
     0.02%  tar      [zfs]             [k] 0x0000000000001f87             
     0.02%  tar      [zfs]             [k] rrm_enter_read                 
     0.02%  tar      [zfs]             [k] 0x000000000000447b             
     0.02%  tar      [zfs]             [k] 0x00000000000af36e             
     0.02%  tar      tar               [.] info_attach_exclist            
     0.02%  tar      [zfs]             [k] 0x00000000000af980             
     0.02%  tar      [zfs]             [k] 0x0000000000045c27             
     0.02%  tar      [zfs]             [k] 0x0000000000045b7e             
     0.02%  tar      [zunicode]        [k] 0x0000000000002318             
     0.02%  tar      [zfs]             [k] abd_alloc_sametype             
     0.02%  tar      [zunicode]        [k] 0x000000000000237b             
     0.02%  tar      [zfs]             [k] 0x00000000000a9c59             
     0.02%  tar      [kernel.vmlinux]  [k] timerqueue_add                 
     0.02%  tar      [zfs]             [k] sa_get_db                      
     0.02%  tar      [kernel.vmlinux]  [k] _raw_spin_lock_irq             
     0.02%  tar      [zfs]             [k] 0x00000000000ac60f             
     0.02%  tar      [zavl]            [k] 0x0000000000000332             
     0.02%  tar      [zfs]             [k] abd_free                       
     0.02%  tar      [zfs]             [k] 0x0000000000003afe             
     0.02%  tar      [zfs]             [k] 0x000000000007abaa             
     0.02%  tar      [zfs]             [k] 0x000000000000c69d             
     0.02%  tar      tar               [.] hash_insert                    
     0.02%  tar      [zfs]             [k] 0x00000000000047c3             
     0.02%  tar      [zavl]            [k] 0x0000000000000322             
     0.02%  tar      [zfs]             [k] 0x0000000000003c4b             
     0.02%  tar      [zfs]             [k] 0x0000000000016b1d             
     0.02%  tar      [zfs]             [k] 0x0000000000003b12             
     0.02%  tar      [zfs]             [k] 0x00000000000b00be             
     0.02%  tar      [zfs]             [k] 0x0000000000045c7f             
     0.02%  tar      [zfs]             [k] 0x00000000000afa93             
     0.02%  tar      [zfs]             [k] 0x000000000007bd77             
     0.02%  tar      [zfs]             [k] 0x0000000000045af3             
     0.02%  tar      [zfs]             [k] 0x0000000000004613             
     0.02%  tar      [kernel.vmlinux]  [k] cache_grow_begin               
     0.02%  tar      [zfs]             [k] 0x0000000000017160             
     0.02%  tar      [zfs]             [k] 0x0000000000045b20             
     0.02%  tar      [zfs]             [k] 0x00000000000ac57c             
     0.02%  tar      [zfs]             [k] 0x00000000000b00f3             
     0.02%  tar      [zfs]             [k] 0x0000000000045c40             
     0.02%  tar      libc-2.23.so      [.] 0x000000000001f738             
     0.02%  tar      [zfs]             [k] 0x000000000000f88b             
     0.02%  tar      [kernel.vmlinux]  [k] ktime_get                      
     0.02%  tar      [zfs]             [k] 0x0000000000016e2d             
     0.02%  tar      [zfs]             [k] 0x0000000000016a92             
     0.02%  tar      [kernel.vmlinux]  [k] rb_next                        
     0.02%  tar      [zfs]             [k] arc_buf_freeze                 
     0.02%  tar      [zfs]             [k] 0x0000000000016e91             
     0.02%  tar      tar               [.] xheader_destroy                
     0.02%  tar      [zfs]             [k] 0x00000000000ac4ea             
     0.02%  tar      [zunicode]        [k] 0x00000000000025db             
     0.02%  tar      [zfs]             [k] 0x0000000000004784             
     0.02%  tar      [kernel.vmlinux]  [k] init_timer_key                 
     0.02%  tar      [kernel.vmlinux]  [k] __fd_install                   
     0.02%  tar      [zfs]             [k] 0x000000000000c6a1             
     0.02%  tar      [zfs]             [k] 0x0000000000016af0             
     0.02%  tar      [kernel.vmlinux]  [k] __schedule                     
     0.02%  tar      [zfs]             [k] 0x00000000000a9f18             
     0.02%  tar      ld-2.23.so        [.] _dl_lookup_symbol_x            
     0.02%  tar      [kernel.vmlinux]  [k] ____fput                       
     0.02%  tar      [zfs]             [k] 0x0000000000004960             
     0.02%  tar      [zfs]             [k] dmu_buf_get_user               
     0.02%  tar      [kernel.vmlinux]  [k] tick_sched_timer               
     0.02%  tar      [kernel.vmlinux]  [k] vfs_open                       
     0.02%  tar      [kernel.vmlinux]  [k] __hrtimer_get_next_event       
     0.02%  tar      libc-2.23.so      [.] __GI___libc_fcntl              
     0.02%  tar      [zfs]             [k] multilist_link_init            
     0.02%  tar      [zfs]             [k] 0x000000000000f712             
     0.02%  tar      [zfs]             [k] 0x0000000000005bf6             
     0.02%  tar      [kernel.vmlinux]  [k] mem_cgroup_handle_over_high    
     0.02%  tar      [zunicode]        [k] 0x00000000000022b0             
     0.02%  tar      [kernel.vmlinux]  [k] up_write                       
     0.02%  tar      [zfs]             [k] 0x00000000000b3596             
     0.02%  tar      [zfs]             [k] 0x0000000000045c31             
     0.02%  tar      [zfs]             [k] 0x0000000000045cba             
     0.02%  tar      [zfs]             [k] spa_get_dsl                    
     0.02%  tar      [zfs]             [k] 0x000000000007abae             
     0.02%  tar      [zfs]             [k] 0x00000000000ac2f1             
     0.02%  tar      [kernel.vmlinux]  [k] ttwu_do_activate               
     0.02%  tar      [zfs]             [k] 0x0000000000000070             
     0.02%  tar      [kernel.vmlinux]  [k] sys_newfstatat                 
     0.02%  tar      [kernel.vmlinux]  [k] current_kernel_time64          
     0.02%  tar      [zfs]             [k] 0x00000000000ac26e             
     0.02%  tar      [kernel.vmlinux]  [k] security_file_fcntl            
     0.02%  tar      [zfs]             [k] dnode_rele_and_unlock          
     0.02%  tar      [zfs]             [k] 0x0000000000016bb5             
     0.02%  tar      [kernel.vmlinux]  [k] hrtimer_forward                
     0.02%  tar      [zfs]             [k] 0x000000000007b0aa             
     0.02%  tar      [zfs]             [k] 0x00000000000171af             
     0.02%  tar      [zfs]             [k] 0x00000000000af37f             
     0.02%  tar      [kernel.vmlinux]  [k] putname                        
     0.02%  tar      [zfs]             [k] 0x0000000000004c47             
     0.02%  tar      [zfs]             [k] dbuf_read                      
     0.02%  tar      [zfs]             [k] 0x00000000000af531             
     0.02%  tar      [zavl]            [k] 0x00000000000004c7             
     0.02%  tar      [kernel.vmlinux]  [k] sys_close                      
     0.02%  tar      [zfs]             [k] spa_read_history_add           
     0.02%  tar      [zfs]             [k] 0x000000000000e600             
     0.02%  tar      [kernel.vmlinux]  [k] release_pages                  
     0.02%  tar      [zfs]             [k] 0x000000000000f55f             
     0.02%  tar      [zfs]             [k] 0x00000000000b4585             
     0.02%  tar      [zfs]             [k] 0x00000000000049b1             
     0.02%  tar      [zfs]             [k] 0x0000000000003ec0             
     0.02%  tar      [zfs]             [k] 0x00000000000b3545             
     0.02%  tar      [zfs]             [k] 0x00000000000af397             
     0.02%  tar      [zfs]             [k] arc_space_return               
     0.02%  tar      [zfs]             [k] 0x00000000000171bd             
     0.02%  tar      [zfs]             [k] 0x0000000000004b01             
     0.02%  tar      [zfs]             [k] 0x0000000000004d4d             
     0.02%  tar      [zfs]             [k] 0x000000000000e3b7             
     0.02%  tar      [zfs]             [k] 0x000000000000c6c2             
     0.02%  tar      [zfs]             [k] 0x00000000000002ef             
     0.02%  tar      [zfs]             [k] 0x0000000000004a1c             
     0.02%  tar      [kernel.vmlinux]  [k] current_time                   
     0.02%  tar      [kernel.vmlinux]  [k] __wake_up_sync_key             
     0.02%  tar      [zfs]             [k] 0x00000000000af662             
     0.02%  tar      [zfs]             [k] 0x000000000004b6dc             
     0.02%  tar      [zfs]             [k] 0x00000000000b35f6             
     0.02%  tar      [zfs]             [k] zfs_blkptr_verify              
     0.02%  tar      [kernel.vmlinux]  [k] sys_write                      
     0.02%  tar      [zfs]             [k] 0x000000000000ca70             
     0.02%  tar      [zfs]             [k] 0x000000000000e097             
     0.02%  tar      [kernel.vmlinux]  [k] sys_fcntl                      
     0.02%  tar      tar               [.] subfile_open                   
     0.02%  tar      [kernel.vmlinux]  [k] path_get                       
     0.02%  tar      [zfs]             [k] 0x00000000000ac4f6             
     0.02%  tar      [zfs]             [k] 0x0000000000045cde             
     0.02%  tar      [spl]             [k] spl_kmem_free                  
     0.02%  tar      [zfs]             [k] 0x00000000000af3a9             
     0.02%  tar      [zfs]             [k] 0x0000000000045d05             
     0.02%  tar      [zfs]             [k] 0x000000000000f592             
     0.02%  tar      [kernel.vmlinux]  [k] return_from_SYSCALL_64         
     0.02%  tar      [zfs]             [k] 0x0000000000045c37             
     0.02%  tar      [zfs]             [k] 0x000000000000f2e3             
     0.02%  tar      [kernel.vmlinux]  [k] rb_insert_color                
     0.02%  tar      [zfs]             [k] 0x00000000000b00fc             
     0.02%  tar      [zfs]             [k] 0x0000000000045d23             
     0.02%  tar      [zfs]             [k] 0x0000000000004c0b             
     0.02%  tar      [zfs]             [k] 0x000000000007bc2a             
     0.02%  tar      [zfs]             [k] 0x000000000000f81b             
     0.02%  tar      [zfs]             [k] 0x00000000000b0255             
     0.02%  tar      [zfs]             [k] 0x000000000007b72f             
     0.02%  tar      [kernel.vmlinux]  [k] handle_mm_fault                
     0.01%  perf     [kernel.vmlinux]  [k] perf_event_addr_filters_exec   
     0.00%  perf     [kernel.vmlinux]  [k] arch_apei_flush_tlb_one        
     0.00%  perf     [kernel.vmlinux]  [k] check_preemption_disabled      
     0.00%  perf     [kernel.vmlinux]  [k] __intel_pmu_enable_all         


#
# (For a higher level overview, try: perf report --sort comm,dso)
#

perf record tar cf /dev/stdout /mnt/xfs/test 2>/dev/null | cat>/dev/null:

# To display the perf.data header info, please use --header/--header-only options.
#
#
# Total Lost Samples: 0
#
# Samples: 1K of event 'cycles:pp'
# Event count (approx.): 1149690768
#
# Overhead  Command  Shared Object     Symbol                             
# ........  .......  ................  ...................................
#
    19.27%  tar      [kernel.vmlinux]  [k] copy_user_generic_string       
     3.63%  tar      tar               [.] simple_finish_header           
     3.29%  tar      [kernel.vmlinux]  [k] __d_lookup_rcu                 
     2.65%  tar      [kernel.vmlinux]  [k] find_get_entry                 
     1.85%  tar      [kernel.vmlinux]  [k] down_read                      
     1.65%  tar      [kernel.vmlinux]  [k] mutex_spin_on_owner.isra.4     
     1.58%  tar      [kernel.vmlinux]  [k] entry_SYSCALL_64_fastpath      
     1.57%  tar      tar               [.] dump_file                      
     1.25%  tar      [kernel.vmlinux]  [k] kmem_cache_alloc               
     1.25%  tar      [kernel.vmlinux]  [k] __list_del_entry               
     1.25%  tar      [kernel.vmlinux]  [k] __check_object_size            
     1.13%  tar      [kernel.vmlinux]  [k] __radix_tree_lookup            
     1.13%  tar      [kernel.vmlinux]  [k] do_dentry_open                 
     0.99%  tar      tar               [.] safer_name_suffix              
     0.99%  tar      [kernel.vmlinux]  [k] enqueue_task_fair              
     0.99%  tar      tar               [.] to_chars                       
     0.98%  tar      [kernel.vmlinux]  [k] mutex_unlock                   
     0.92%  tar      [kernel.vmlinux]  [k] get_page_from_freelist         
     0.87%  tar      libc-2.23.so      [.] _int_malloc                    
     0.86%  tar      tar               [.] write_short_name.isra.0        
     0.80%  tar      [kernel.vmlinux]  [k] __virt_addr_valid              
     0.79%  tar      [kernel.vmlinux]  [k] try_to_wake_up                 
     0.79%  tar      [kernel.vmlinux]  [k] __fget_light                   
     0.79%  tar      [kernel.vmlinux]  [k] entry_SYSCALL_64               
     0.79%  tar      [kernel.vmlinux]  [k] security_inode_getattr         
     0.79%  tar      [kernel.vmlinux]  [k] fsnotify                       
     0.74%  tar      [xfs]             [k] xfs_can_free_eofblocks         
     0.73%  tar      libc-2.23.so      [.] _int_free                      
     0.73%  tar      [kernel.vmlinux]  [k] mutex_lock                     
     0.73%  tar      [kernel.vmlinux]  [k] preempt_count_add              
     0.73%  tar      tar               [.] dump_regular_file              
     0.72%  tar      [kernel.vmlinux]  [k] _raw_spin_lock                 
     0.72%  tar      [kernel.vmlinux]  [k] vfs_read                       
     0.67%  tar      [kernel.vmlinux]  [k] link_path_walk                 
     0.66%  tar      libc-2.23.so      [.] __strcpy_sse2_unaligned        
     0.66%  tar      [kernel.vmlinux]  [k] resched_curr                   
     0.66%  tar      [kernel.vmlinux]  [k] get_empty_filp                 
     0.66%  tar      [kernel.vmlinux]  [k] check_preemption_disabled      
     0.66%  tar      libc-2.23.so      [.] malloc                         
     0.66%  tar      [kernel.vmlinux]  [k] task_work_run                  
     0.60%  tar      tar               [.] start_header                   
     0.59%  tar      tar               [.] excluded_name                  
     0.59%  tar      [kernel.vmlinux]  [k] pipe_write                     
     0.59%  tar      libc-2.23.so      [.] strlen                         
     0.59%  tar      [xfs]             [k] xfs_vn_getattr                 
     0.53%  tar      [kernel.vmlinux]  [k] preempt_count_sub              
     0.53%  tar      [kernel.vmlinux]  [k] do_sys_open                    
     0.52%  tar      [kernel.vmlinux]  [k] _raw_spin_lock_irqsave         
     0.52%  tar      [kernel.vmlinux]  [k] path_openat                    
     0.47%  tar      [kernel.vmlinux]  [k] generic_file_read_iter         
     0.47%  tar      libc-2.23.so      [.] free                           
     0.47%  tar      [kernel.vmlinux]  [k] __call_rcu.constprop.71        
     0.46%  tar      libc-2.23.so      [.] __GI___libc_write              
     0.46%  tar      libc-2.23.so      [.] __readdir64                    
     0.46%  tar      [kernel.vmlinux]  [k] __alloc_pages_nodemask         
     0.46%  tar      [kernel.vmlinux]  [k] __fsnotify_parent              
     0.46%  tar      libc-2.23.so      [.] __fxstat64                     
     0.46%  tar      [kernel.vmlinux]  [k] kmem_cache_free                
     0.46%  tar      [kernel.vmlinux]  [k] cp_new_stat                    
     0.46%  tar      [kernel.vmlinux]  [k] __fput                         
     0.40%  tar      [kernel.vmlinux]  [k] path_init                      
     0.40%  tar      tar               [.] tar_stat_destroy               
     0.40%  tar      [kernel.vmlinux]  [k] select_task_rq_fair            
     0.40%  tar      [kernel.vmlinux]  [k] vfs_write                      
     0.39%  tar      tar               [.] tar_stat_init                  
     0.38%  tar      tar               [.] _init                          
     0.33%  tar      [kernel.vmlinux]  [k] lockref_put_return             
     0.33%  tar      [kernel.vmlinux]  [k] path_lookupat                  
     0.33%  tar      [kernel.vmlinux]  [k] task_work_add                  
     0.33%  tar      libc-2.23.so      [.] __openat_2                     
     0.33%  tar      [kernel.vmlinux]  [k] unlazy_walk                    
     0.33%  tar      [kernel.vmlinux]  [k] __wake_up_common               
     0.33%  tar      tar               [.] excluded_file_name             
     0.33%  tar      [xfs]             [k] xfs_release                    
     0.33%  tar      [kernel.vmlinux]  [k] place_entity                   
     0.33%  tar      libc-2.23.so      [.] __memcpy_sse2_unaligned        
     0.33%  tar      tar               [.] info_free_exclist              
     0.33%  tar      [kernel.vmlinux]  [k] __percpu_counter_add           
     0.33%  tar      tar               [.] hash_string                    
     0.33%  tar      [kernel.vmlinux]  [k] copy_page_from_iter            
     0.33%  tar      tar               [.] xmemdup                        
     0.27%  tar      [kernel.vmlinux]  [k] lookup_fast                    
     0.27%  tar      [kernel.vmlinux]  [k] __check_heap_object            
     0.27%  tar      [kernel.vmlinux]  [k] fput                           
     0.27%  tar      [kernel.vmlinux]  [k] __wake_up_sync_key             
     0.26%  tar      [kernel.vmlinux]  [k] restore_nameidata              
     0.26%  tar      [kernel.vmlinux]  [k] __memset                       
     0.26%  tar      tar               [.] assign_string                  
     0.26%  tar      [kernel.vmlinux]  [k] lockref_get_not_dead           
     0.26%  tar      libc-2.23.so      [.] malloc_consolidate             
     0.26%  tar      [kernel.vmlinux]  [k] copy_page_to_iter              
     0.26%  tar      [kernel.vmlinux]  [k] check_preempt_curr             
     0.26%  tar      [kernel.vmlinux]  [k] dput                           
     0.20%  tar      [kernel.vmlinux]  [k] osq_unlock                     
     0.20%  tar      libc-2.23.so      [.] __GI___libc_read               
     0.20%  tar      [kernel.vmlinux]  [k] touch_atime                    
     0.20%  tar      tar               [.] gnu_flush_write                
     0.20%  tar      [kernel.vmlinux]  [k] strncpy_from_user              
     0.20%  tar      [kernel.vmlinux]  [k] __sb_start_write               
     0.20%  tar      [kernel.vmlinux]  [k] generic_permission             
     0.20%  tar      [kernel.vmlinux]  [k] _raw_write_unlock_irqrestore   
     0.20%  tar      libc-2.23.so      [.] __fxstatat64                   
     0.20%  tar      [kernel.vmlinux]  [k] check_stack_object             
     0.20%  tar      tar               [.] streamsavedir                  
     0.20%  tar      [kernel.vmlinux]  [k] filename_lookup                
     0.20%  tar      [kernel.vmlinux]  [k] __vfs_read                     
     0.20%  tar      [kernel.vmlinux]  [k] kill_fasync                    
     0.20%  tar      [kernel.vmlinux]  [k] getname_flags                  
     0.20%  tar      tar               [.] _flush_write                   
     0.20%  tar      [kernel.vmlinux]  [k] __sb_end_write                 
     0.20%  tar      [kernel.vmlinux]  [k] do_filp_open                   
     0.20%  tar      libc-2.23.so      [.] __memmove_sse2                 
     0.20%  tar      tar               [.] xattrs_selinux_get             
     0.20%  tar      [kernel.vmlinux]  [k] __fd_install                   
     0.20%  tar      [xfs]             [k] xfs_file_read_iter             
     0.20%  tar      [xfs]             [k] xfs_file_buffered_aio_read     
     0.20%  tar      libc-2.23.so      [.] __GI___openat64                
     0.20%  tar      [kernel.vmlinux]  [k] is_vmalloc_or_module_addr      
     0.20%  tar      [kernel.vmlinux]  [k] put_pid                        
     0.20%  tar      [kernel.vmlinux]  [k] __list_add                     
     0.20%  tar      [kernel.vmlinux]  [k] from_kgid_munged               
     0.20%  tar      [kernel.vmlinux]  [k] mutex_optimistic_spin          
     0.19%  tar      tar               [.] mode_to_chars.constprop.5      
     0.19%  tar      tar               [.] xmalloc                        
     0.15%  tar      [kernel.vmlinux]  [k] clear_page                     
     0.14%  tar      tar               [.] sys_write_archive_buffer       
     0.14%  tar      [kernel.vmlinux]  [k] ___cache_free                  
     0.14%  tar      [kernel.vmlinux]  [k] alloc_pages_current            
     0.13%  tar      [kernel.vmlinux]  [k] _copy_to_user                  
     0.13%  tar      [kernel.vmlinux]  [k] __rcu_read_unlock              
     0.13%  tar      [kernel.vmlinux]  [k] _raw_write_unlock              
     0.13%  tar      tar               [.] xheader_destroy                
     0.13%  tar      [kernel.vmlinux]  [k] __rcu_read_lock                
     0.13%  tar      [kernel.vmlinux]  [k] __atime_needs_update           
     0.13%  tar      [xfs]             [k] xfs_file_release               
     0.13%  tar      [kernel.vmlinux]  [k] filldir                        
     0.13%  tar      tar               [.] tar_stat_close                 
     0.13%  tar      [kernel.vmlinux]  [k] file_free_rcu                  
     0.13%  tar      tar               [.] current_block_ordinal          
     0.13%  tar      [kernel.vmlinux]  [k] vfs_fstat                      
     0.13%  tar      tar               [.] owner_map_translate            
     0.13%  tar      [kernel.vmlinux]  [k] pagecache_get_page             
     0.13%  tar      tar               [.] set_next_block_after           
     0.13%  tar      [kernel.vmlinux]  [k] terminate_walk                 
     0.13%  tar      tar               [.] gid_to_gname                   
     0.13%  tar      tar               [.] available_space_after          
     0.13%  tar      tar               [.] group_map_translate            
     0.13%  tar      [xfs]             [k] xfs_dir2_block_getdents.isra.10
     0.13%  tar      [kernel.vmlinux]  [k] rb_insert_color                
     0.13%  tar      [kernel.vmlinux]  [k] __inode_permission             
     0.13%  tar      tar               [.] hash_insert                    
     0.13%  tar      [kernel.vmlinux]  [k] file_ra_state_init             
     0.13%  tar      [kernel.vmlinux]  [k] filp_close                     
     0.13%  tar      tar               [.] safe_hasher                    
     0.13%  tar      [kernel.vmlinux]  [k] module_put                     
     0.13%  tar      [kernel.vmlinux]  [k] vfs_getattr_nosec              
     0.13%  tar      [kernel.vmlinux]  [k] expand_files                   
     0.13%  tar      tar               [.] flush_archive                  
     0.13%  tar      tar               [.] safe_write                     
     0.13%  tar      tar               [.] uid_to_uname                   
     0.13%  tar      [kernel.vmlinux]  [k] syscall_return_via_sysret      
     0.13%  tar      libc-2.23.so      [.] __GI___libc_close              
     0.13%  tar      tar               [.] finish_header                  
     0.13%  tar      [kernel.vmlinux]  [k] up_read                        
     0.07%  tar      libc-2.23.so      [.] _dl_addr                       
     0.07%  tar      libc-2.23.so      [.] __GI___strcasecmp_l            
     0.07%  tar      [kernel.vmlinux]  [k] current_kernel_time64          
     0.07%  tar      [kernel.vmlinux]  [k] vfs_getattr                    
     0.07%  tar      [kernel.vmlinux]  [k] get_unused_fd_flags            
     0.07%  tar      tar               [.] transform_name                 
     0.07%  tar      [kernel.vmlinux]  [k] policy_nodemask                
     0.07%  tar      [kernel.vmlinux]  [k] _find_next_bit.part.0          
     0.07%  tar      [kernel.vmlinux]  [k] hrtick_update                  
     0.07%  tar      tar               [.] mv_begin_write                 
     0.07%  tar      libc-2.23.so      [.] __strcmp_sse2_unaligned        
     0.07%  tar      libc-2.23.so      [.] _int_realloc                   
     0.07%  tar      [kernel.vmlinux]  [k] security_file_fcntl            
     0.07%  tar      [xfs]             [k] xfs_perag_get                  
     0.07%  tar      [xfs]             [k] xfs_ilock                      
     0.07%  tar      tar               [.] xattrs_acls_get                
     0.07%  tar      [kernel.vmlinux]  [k] mntput_no_expire               
     0.07%  tar      [kernel.vmlinux]  [k] iterate_dir                    
     0.07%  tar      [kernel.vmlinux]  [k] update_rq_clock.part.64        
     0.07%  tar      [kernel.vmlinux]  [k] policy_zonelist                
     0.07%  tar      [kernel.vmlinux]  [k] open_check_o_direct            
     0.07%  tar      tar               [.] full_write                     
     0.07%  tar      [kernel.vmlinux]  [k] mntget                         
     0.07%  tar      libc-2.23.so      [.] 0x000000000001f738             
     0.07%  tar      [xfs]             [k] xfs_bmapi_read                 
     0.07%  tar      [kernel.vmlinux]  [k] __fdget_pos                    
     0.07%  tar      [xfs]             [k] _xfs_buf_find                  
     0.07%  tar      [kernel.vmlinux]  [k] __alloc_fd                     
     0.07%  tar      tar               [.] xheader_xattr_free             
     0.07%  tar      [kernel.vmlinux]  [k] ttwu_do_activate               
     0.07%  tar      tar               [.] checkpoint_run                 
     0.07%  tar      libc-2.23.so      [.] _wordcopy_bwd_dest_aligned     
     0.07%  tar      [kernel.vmlinux]  [k] in_lock_functions              
     0.07%  tar      [kernel.vmlinux]  [k] __put_user_8                   
     0.07%  tar      libc-2.23.so      [.] __getdents64                   
     0.07%  tar      [kernel.vmlinux]  [k] SYSC_newfstat                  
     0.07%  tar      tar               [.] info_attach_exclist            
     0.07%  tar      [kernel.vmlinux]  [k] rcu_accelerate_cbs             
     0.07%  tar      [xfs]             [k] xfs_dir2_sf_getdents.isra.9    
     0.07%  tar      [kernel.vmlinux]  [k] kick_process                   
     0.07%  tar      [xfs]             [k] xfs_dir2_leaf_readbuf          
     0.07%  tar      [kernel.vmlinux]  [k] exit_to_usermode_loop          
     0.07%  tar      [xfs]             [k] xfs_dir3_data_get_ftype        
     0.07%  tar      [kernel.vmlinux]  [k] rcu_is_watching                
     0.07%  tar      tar               [.] xstrdup                        
     0.07%  tar      [kernel.vmlinux]  [k] _raw_spin_unlock               
     0.07%  tar      [kernel.vmlinux]  [k] sys_getdents                   
     0.07%  tar      [kernel.vmlinux]  [k] timespec_trunc                 
     0.07%  tar      tar               [.] find_next_block                
     0.07%  tar      [kernel.vmlinux]  [k] radix_tree_lookup_slot         
     0.07%  tar      [kernel.vmlinux]  [k] unmap_page_range               
     0.07%  tar      [kernel.vmlinux]  [k] lapic_next_deadline            
     0.07%  tar      [kernel.vmlinux]  [k] get_task_policy.part.27        
     0.07%  tar      [kernel.vmlinux]  [k] sched_clock_cpu                
     0.07%  tar      [kernel.vmlinux]  [k] putname                        
     0.07%  tar      [kernel.vmlinux]  [k] may_open                       
     0.07%  tar      [kernel.vmlinux]  [k] __rmqueue                      
     0.07%  tar      [kernel.vmlinux]  [k] file_update_time               
     0.07%  tar      [kernel.vmlinux]  [k] __mod_zone_page_state          
     0.07%  tar      [kernel.vmlinux]  [k] sys_fcntl                      
     0.07%  tar      [kernel.vmlinux]  [k] vfs_fstatat                    
     0.07%  tar      tar               [.] subfile_open                   
     0.06%  tar      [kernel.vmlinux]  [k] debug_smp_processor_id         
     0.06%  tar      [kernel.vmlinux]  [k] iov_iter_init                  
     0.06%  tar      [kernel.vmlinux]  [k] find_vma                       
     0.06%  tar      tar               [.] xrealloc                       
     0.06%  tar      [xfs]             [k] xfs_dir3_get_dtype             
     0.06%  tar      [kernel.vmlinux]  [k] legitimize_mnt                 
     0.06%  tar      [kernel.vmlinux]  [k] mntput                         
     0.06%  tar      [kernel.vmlinux]  [k] update_curr                    
     0.06%  tar      [kernel.vmlinux]  [k] native_sched_clock             
     0.06%  tar      [kernel.vmlinux]  [k] from_kuid_munged               
     0.06%  tar      [kernel.vmlinux]  [k] sys_close                      
     0.06%  tar      [kernel.vmlinux]  [k] security_file_free             
     0.06%  tar      [kernel.vmlinux]  [k] activate_task                  
     0.06%  tar      [xfs]             [k] xfs_dir2_leaf_getdents         
     0.06%  tar      [kernel.vmlinux]  [k] sys_write                      
     0.06%  tar      tar               [.] sys_file_is_archive            
     0.06%  tar      tar               [.] safe_read                      
     0.05%  tar      [kernel.vmlinux]  [k] vmacache_find                  
     0.01%  tar      [kernel.vmlinux]  [k] flush_signal_handlers          
     0.00%  perf     [kernel.vmlinux]  [k] native_irq_return_iret         
     0.00%  perf     [kernel.vmlinux]  [k] nmi_cpu_backtrace_handler      
     0.00%  perf     [kernel.vmlinux]  [k] __intel_pmu_enable_all         


#
# (For a higher level overview, try: perf report --sort comm,dso)
#
@haasn
haasn commented Jan 6, 2017

Monitoring ionice while the ZFS command is running confirms essentially no disk activity (except the occasional write spike, probably because of ZFS syncing asynchronously written data to disk every few seconds).

@haasn
haasn commented Jan 6, 2017

Some more info:

λ cd /sys/module/zfs/parameters; for x in *; do echo -n $x=; cat $x; done
dbuf_cache_hiwater_pct=10
dbuf_cache_lowater_pct=10
dbuf_cache_max_bytes=104857600
dbuf_cache_max_shift=5
ignore_hole_birth=1
l2arc_feed_again=1
l2arc_feed_min_ms=200
l2arc_feed_secs=1
l2arc_headroom=2
l2arc_headroom_boost=200
l2arc_noprefetch=1
l2arc_norw=0
l2arc_write_boost=8388608
l2arc_write_max=8388608
metaslab_aliquot=524288
metaslab_bias_enabled=1
metaslab_debug_load=0
metaslab_debug_unload=0
metaslab_fragmentation_factor_enabled=1
metaslab_lba_weighting_enabled=1
metaslab_preload_enabled=1
metaslabs_per_vdev=200
send_holes_without_birth_time=1
spa_asize_inflation=24
spa_config_path=/etc/zfs/zpool.cache
spa_load_verify_data=1
spa_load_verify_maxinflight=10000
spa_load_verify_metadata=1
spa_slop_shift=5
zfetch_array_rd_sz=1048576
zfetch_max_distance=8388608
zfetch_max_streams=8
zfetch_min_sec_reap=2
zfs_abd_scatter_enabled=1
zfs_abd_scatter_max_order=10
zfs_admin_snapshot=1
zfs_arc_average_blocksize=8192
zfs_arc_dnode_limit=0
zfs_arc_dnode_limit_percent=10
zfs_arc_dnode_reduce_percent=10
zfs_arc_grow_retry=0
zfs_arc_lotsfree_percent=10
zfs_arc_max=0
zfs_arc_meta_adjust_restarts=4096
zfs_arc_meta_limit=0
zfs_arc_meta_limit_percent=75
zfs_arc_meta_min=0
zfs_arc_meta_prune=10000
zfs_arc_meta_strategy=1
zfs_arc_min=0
zfs_arc_min_prefetch_lifespan=0
zfs_arc_num_sublists_per_state=32
zfs_arc_p_aggressive_disable=1
zfs_arc_p_dampener_disable=1
zfs_arc_p_min_shift=0
zfs_arc_shrink_shift=0
zfs_arc_sys_free=0
zfs_autoimport_disable=1
zfs_compressed_arc_enabled=1
zfs_dbgmsg_enable=0
zfs_dbgmsg_maxsize=4194304
zfs_dbuf_state_index=0
zfs_deadman_enabled=1
zfs_deadman_synctime_ms=1000000
zfs_dedup_prefetch=0
zfs_delay_min_dirty_percent=60
zfs_delay_scale=500000
zfs_delete_blocks=20480
zfs_dirty_data_max=6752195788
zfs_dirty_data_max_max=16880489472
zfs_dirty_data_max_max_percent=25
zfs_dirty_data_max_percent=10
zfs_dirty_data_sync=67108864
zfs_expire_snapshot=300
zfs_flags=0
zfs_free_bpobj_enabled=1
zfs_free_leak_on_eio=0
zfs_free_max_blocks=100000
zfs_free_min_time_ms=1000
zfs_immediate_write_sz=32768
zfs_max_recordsize=1048576
zfs_mdcomp_disable=0
zfs_metaslab_fragmentation_threshold=70
zfs_mg_fragmentation_threshold=85
zfs_mg_noalloc_threshold=0
zfs_nocacheflush=0
zfs_nopwrite_enabled=1
zfs_no_scrub_io=0
zfs_no_scrub_prefetch=0
zfs_object_mutex_size=64
zfs_pd_bytes_max=52428800
zfs_prefetch_disable=0
zfs_read_chunk_size=1048576
zfs_read_history=0
zfs_read_history_hits=0
zfs_recover=0
zfs_resilver_delay=2
zfs_resilver_min_time_ms=3000
zfs_scan_idle=50
zfs_scan_min_time_ms=1000
zfs_scrub_delay=4
zfs_send_corrupt_data=0
zfs_sync_pass_deferred_free=2
zfs_sync_pass_dont_compress=5
zfs_sync_pass_rewrite=2
zfs_top_maxinflight=32
zfs_txg_history=0
zfs_txg_timeout=5
zfs_vdev_aggregation_limit=131072
zfs_vdev_async_read_max_active=3
zfs_vdev_async_read_min_active=1
zfs_vdev_async_write_active_max_dirty_percent=60
zfs_vdev_async_write_active_min_dirty_percent=30
zfs_vdev_async_write_max_active=10
zfs_vdev_async_write_min_active=1
zfs_vdev_cache_bshift=16
zfs_vdev_cache_max=16384
zfs_vdev_cache_size=0
zfs_vdev_max_active=1000
zfs_vdev_mirror_non_rotating_inc=0
zfs_vdev_mirror_non_rotating_seek_inc=1
zfs_vdev_mirror_rotating_inc=0
zfs_vdev_mirror_rotating_seek_inc=5
zfs_vdev_mirror_rotating_seek_offset=1048576
zfs_vdev_queue_depth_pct=1000
zfs_vdev_raidz_impl=[fastest] original scalar sse2 ssse3 
zfs_vdev_read_gap_limit=32768
zfs_vdev_scheduler=noop
zfs_vdev_scrub_max_active=2
zfs_vdev_scrub_min_active=1
zfs_vdev_sync_read_max_active=10
zfs_vdev_sync_read_min_active=10
zfs_vdev_sync_write_max_active=10
zfs_vdev_sync_write_min_active=10
zfs_vdev_write_gap_limit=4096
zfs_zevent_cols=80
zfs_zevent_console=0
zfs_zevent_len_max=512
zil_replay_disable=0
zil_slog_limit=1048576
zio_delay_max=30000
zio_dva_throttle_enabled=0
zio_requeue_io_start_cut_in_line=1
zio_taskq_batch_pct=75
zvol_inhibit_dev=0
zvol_major=230
zvol_max_discard_blocks=16384
zvol_prefetch_bytes=131072
λ zpool get all zarathustra
NAME         PROPERTY                    VALUE                       SOURCE
zarathustra  size                        4.53T                       -
zarathustra  capacity                    52%                         -
zarathustra  altroot                     -                           default
zarathustra  health                      ONLINE                      -
zarathustra  guid                        15703935022679199154        -
zarathustra  version                     -                           default
zarathustra  bootfs                      -                           default
zarathustra  delegation                  on                          default
zarathustra  autoreplace                 off                         default
zarathustra  cachefile                   -                           default
zarathustra  failmode                    wait                        default
zarathustra  listsnapshots               off                         default
zarathustra  autoexpand                  off                         default
zarathustra  dedupditto                  0                           default
zarathustra  dedupratio                  1.00x                       -
zarathustra  free                        2.16T                       -
zarathustra  allocated                   2.37T                       -
zarathustra  readonly                    off                         -
zarathustra  ashift                      12                          local
zarathustra  comment                     -                           default
zarathustra  expandsize                  -                           -
zarathustra  freeing                     0                           -
zarathustra  fragmentation               44%                         -
zarathustra  leaked                      0                           -
zarathustra  feature@async_destroy       enabled                     local
zarathustra  feature@empty_bpobj         active                      local
zarathustra  feature@lz4_compress        active                      local
zarathustra  feature@spacemap_histogram  active                      local
zarathustra  feature@enabled_txg         active                      local
zarathustra  feature@hole_birth          disabled                    local
zarathustra  feature@extensible_dataset  active                      local
zarathustra  feature@embedded_data       active                      local
zarathustra  feature@bookmarks           disabled                    local
zarathustra  feature@filesystem_limits   enabled                     local
zarathustra  feature@large_blocks        enabled                     local
zarathustra  feature@large_dnode         active                      local
zarathustra  feature@sha512              disabled                    local
zarathustra  feature@skein               disabled                    local
zarathustra  feature@edonr               disabled                    local
zarathustra  feature@userobj_accounting  disabled                    local
λ zfs get all zarathustra/ROOT/gentoo/usr
NAME                         PROPERTY               VALUE                  SOURCE
zarathustra/ROOT/gentoo/usr  type                   filesystem             -
zarathustra/ROOT/gentoo/usr  creation               Wed Aug 24 17:42 2016  -
zarathustra/ROOT/gentoo/usr  used                   1.14G                  -
zarathustra/ROOT/gentoo/usr  available              2.02T                  -
zarathustra/ROOT/gentoo/usr  referenced             96K                    -
zarathustra/ROOT/gentoo/usr  compressratio          1.22x                  -
zarathustra/ROOT/gentoo/usr  mounted                no                     -
zarathustra/ROOT/gentoo/usr  quota                  none                   default
zarathustra/ROOT/gentoo/usr  reservation            none                   default
zarathustra/ROOT/gentoo/usr  recordsize             128K                   default
zarathustra/ROOT/gentoo/usr  mountpoint             /usr                   inherited from zarathustra/ROOT/gentoo
zarathustra/ROOT/gentoo/usr  sharenfs               off                    default
zarathustra/ROOT/gentoo/usr  checksum               on                     default
zarathustra/ROOT/gentoo/usr  compression            lz4                    inherited from zarathustra
zarathustra/ROOT/gentoo/usr  atime                  off                    inherited from zarathustra
zarathustra/ROOT/gentoo/usr  devices                on                     default
zarathustra/ROOT/gentoo/usr  exec                   on                     default
zarathustra/ROOT/gentoo/usr  setuid                 on                     default
zarathustra/ROOT/gentoo/usr  readonly               off                    default
zarathustra/ROOT/gentoo/usr  zoned                  off                    default
zarathustra/ROOT/gentoo/usr  snapdir                hidden                 default
zarathustra/ROOT/gentoo/usr  aclinherit             restricted             default
zarathustra/ROOT/gentoo/usr  canmount               off                    local
zarathustra/ROOT/gentoo/usr  xattr                  sa                     inherited from zarathustra
zarathustra/ROOT/gentoo/usr  copies                 1                      default
zarathustra/ROOT/gentoo/usr  version                5                      -
zarathustra/ROOT/gentoo/usr  utf8only               on                     -
zarathustra/ROOT/gentoo/usr  normalization          formD                  -
zarathustra/ROOT/gentoo/usr  casesensitivity        sensitive              -
zarathustra/ROOT/gentoo/usr  vscan                  off                    default
zarathustra/ROOT/gentoo/usr  nbmand                 off                    default
zarathustra/ROOT/gentoo/usr  sharesmb               off                    default
zarathustra/ROOT/gentoo/usr  refquota               none                   default
zarathustra/ROOT/gentoo/usr  refreservation         none                   default
zarathustra/ROOT/gentoo/usr  primarycache           all                    default
zarathustra/ROOT/gentoo/usr  secondarycache         all                    default
zarathustra/ROOT/gentoo/usr  usedbysnapshots        0                      -
zarathustra/ROOT/gentoo/usr  usedbydataset          96K                    -
zarathustra/ROOT/gentoo/usr  usedbychildren         1.14G                  -
zarathustra/ROOT/gentoo/usr  usedbyrefreservation   0                      -
zarathustra/ROOT/gentoo/usr  logbias                latency                default
zarathustra/ROOT/gentoo/usr  dedup                  off                    default
zarathustra/ROOT/gentoo/usr  mlslabel               none                   default
zarathustra/ROOT/gentoo/usr  sync                   standard               default
zarathustra/ROOT/gentoo/usr  dnodesize              auto                   inherited from zarathustra
zarathustra/ROOT/gentoo/usr  refcompressratio       1.00x                  -
zarathustra/ROOT/gentoo/usr  written                0                      -
zarathustra/ROOT/gentoo/usr  logicalused            438M                   -
zarathustra/ROOT/gentoo/usr  logicalreferenced      40K                    -
zarathustra/ROOT/gentoo/usr  filesystem_limit       none                   default
zarathustra/ROOT/gentoo/usr  snapshot_limit         none                   default
zarathustra/ROOT/gentoo/usr  filesystem_count       none                   default
zarathustra/ROOT/gentoo/usr  snapshot_count         none                   default
zarathustra/ROOT/gentoo/usr  snapdev                hidden                 default
zarathustra/ROOT/gentoo/usr  acltype                posixacl               inherited from zarathustra
zarathustra/ROOT/gentoo/usr  context                none                   default
zarathustra/ROOT/gentoo/usr  fscontext              none                   default
zarathustra/ROOT/gentoo/usr  defcontext             none                   default
zarathustra/ROOT/gentoo/usr  rootcontext            none                   default
zarathustra/ROOT/gentoo/usr  relatime               off                    default
zarathustra/ROOT/gentoo/usr  redundant_metadata     all                    default
zarathustra/ROOT/gentoo/usr  overlay                off                    default
zarathustra/ROOT/gentoo/usr  xyz.haasn:force-cache  true                   inherited from zarathustra/ROOT
zarathustra/ROOT/gentoo/usr  com.sun:auto-snapshot  true                   inherited from zarathustra
@loli10K
Contributor
loli10K commented Jan 6, 2017

@haasn can you try the same tests on a dataset without large dnodes?

@haasn
haasn commented Jan 6, 2017 edited
λ zfs create -o com.sun:auto-snapshot=false -o mountpoint=/z/bench -o dnodesize=legacy zarathustra/MISC/bench 

λ cp -a /usr/include /z/bench/test

λ time tar cf - /z/bench/test | pv >/dev/null 
 370MiB 0:00:01 [ 335MiB/s]
tar cf - /z/bench/test  0.12s user 0.98s system 99% cpu 1.108 total

λ time tar cf - /z/bench/test | pv >/dev/null
 370MiB 0:00:01 [ 357MiB/s]
tar cf - /z/bench/test  0.13s user 0.91s system 99% cpu 1.040 total

λ time tar cf - /z/bench/test | pv >/dev/null
 370MiB 0:00:01 [ 356MiB/s]
tar cf - /z/bench/test  0.12s user 0.92s system 99% cpu 1.044 total

λ time tar cf - /z/bench/test | pv >/dev/null
 370MiB 0:00:01 [ 357MiB/s]
tar cf - /z/bench/test  0.12s user 0.91s system 99% cpu 1.041 total
@kernelOfTruth
Contributor
kernelOfTruth commented Jan 6, 2017 edited

Write throttling comes to mind, but I'm not sure if it could be the culprit here - since it's mostly only reading :

https://www.delphix.com/blog/delphix-engineering/tuning-openzfs-write-throttle

/sys/module/zfs/parameters/zfs_delay_scale
@behlendorf
Member

@haasn it sure looks like lock contention based on the profiling data you provided. Possibly in the zfs_zget()->dmu_object_size_from_db() call path. Could you try two tests:

  • Running the test under strace -c for xfs and zfs to get timing data for each system call to narrow down exactly which calls are slower.

  • Running the test using files with larger sizes to see if you still observe the 3x performance difference.

@dweeezil
Member

I tried this test in a somewhat controlled environment.

ZFS
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 70.13    0.106255           2     51960           newfstatat
 16.20    0.024541           8      3062           getdents
  5.33    0.008081           2      4610           fstat
  3.25    0.004930           2      3065           fcntl

and

XFS
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 79.10    0.095953           2     51960           newfstatat
  6.00    0.007280           2      4610           fstat
  5.04    0.006114           2      3063           getdents
  3.95    0.004787           2      3065           fcntl

This test seems to be mainly stressing getdents() (ZAP traversal).

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment