Hi. I have a FreeBSD 10.0-STABLE #0 r264414 based system with 32 GB RAM running ZFS/Geli.
I would like to understand if the response pattern to these steps show a bug. Steps (details below): A. Boot the system. Create a large file, 5x the RAM, using dd. B. Run a 'find' on a zfs directory (tree) with approx 32 Million files. C. Run 'find' command _back-to-back_ for a total of 4 times. 'find' response time goes down from: 32 min -> 17 min -> 1+ min -> 17 seconds. (No other significant zfs i/o is going on at this time). Question: Q1. Why are the second and third 'find' back-to-back steps taking so long? MFU should have (AFAIK) held on to the metadata after the first 'find' operation was over. Shouldn't the subsequent 'find' have executed faster!? (There is no other i/o intensive or job running. No NFS clients are present in the tests, even though NFS sharing is configured.) Q2. I have another issue, though not detailed here. A ruby script doing a traversal of all the files via its 'Find' api gets to be very very slow, particularly after a new 'find' job kicks in, in-parallel due to some default system security policy: /etc/periodic/security/110.neggrpperm. When I kill the second 'find', the ruby script 'Find' based call continues _still_ at its very slow pace, for hours. A script that is just listing files could have finished in two hours instead takes approx 10 hours even if that is the only file i/o going on. Q3. Could the two issues above possibly related? Thanks, =Lakhinder Steps: ==============================================> # Step A. Freshly booted system. root@fbsd_10:/zdata_1/xx # $ dd if=/dev/zero of=file_2 bs=16M count=10240; date 10240+0 records in 10240+0 records out 171798691840 bytes transferred in 192.188421 secs (893907609 bytes/sec) # Step B # cd over to another directory with approx 32 Million files # in its various subdirectories. root@fbsd_10:/zdata_1/sr_2gig # date; find . | wc; date Sun Jun 15 15:52:32 PDT 2014 32673014 32673014 2378434006 Sun Jun 15 16:24:22 PDT 2014 # time taken is approx. 32 minutes. # Step C-1. root@fbsd_10:/zdata_1/sr_2gig # date; find . | wc; date Sun Jun 15 16:24:22 PDT 2014 32673014 32673014 2378434006 Sun Jun 15 16:41:56 PDT 2014 # time taken is approx. 17 minutes. # Step C-2. root@fbsd_10:/zdata_1/sr_2gig # date; find . | wc; date Sun Jun 15 16:41:56 PDT 2014 32673014 32673014 2378434006 Sun Jun 15 16:43:07 PDT 2014 # time taken is approx 1+ minute. # Step C-3. root@fbsd_10:/zdata_1/sr_2gig # date; find . | wc; date Sun Jun 15 16:43:07 PDT 2014 32673014 32673014 2378434006 Sun Jun 15 16:43:26 PDT 2014 #time taken is 19 seconds. --------------- system details -------------------------------------- OS version: FreeBSD fbsd_10 10.0-STABLE FreeBSD 10.0-STABLE #0 r264414: Sun Apr 13 19:33:56 UTC 2014 r...@grind.freebsd.org:/usr/obj/usr/src/sys/GENERIC amd64 cat /boot/loader.conf: aesni_load="YES" geli_load="YES" zfs_load="YES" vfs.zfs.arc_meta_limit=17179869184 # 16 GB limit for ARC Meta. kern.maxvnodes=50000000 Here is 'top' after running a _recent_ 'find'. last pid: 75231; load averages: 0.48, 0.28, 0.33 up 0+20:20:26 11:58:50 37 processes: 1 running, 36 sleeping CPU: 0.0% user, 0.0% nice, 0.0% system, 0.0% interrupt, 99.9% idle Mem: 28M Active, 796K Inact, 30G Wired, 2620K Cache, 97M Buf, 911M Free ARC: 24G Total, 4756M MFU, 18G MRU, 16K Anon, 385M Header, 1308M Other Swap: 1638M Total, 41M Used, 1597M Free, 2% Inuse PID USERNAME THR PRI NICE SIZE RES STATE C TIME WCPU COMMAND 2486 root 1 21 0 34980K 2236K nanslp 6 1:46 0.00% perl5..16.3 2478 root 1 20 0 56300K 15720K select 3 1:14 0.00% tmux 2483 root 1 20 0 19824K 1612K CPU5 5 0:47 0.00% top **** # after the _recent_ refresh with 'find': root@fbsd_10:/ # sysctl vfs.zfs: vfs.zfs.arc_max: 32373334016 vfs.zfs.arc_min: 8589934592 vfs.zfs.arc_meta_used: 17180938800 vfs.zfs.arc_meta_limit: 17179869184 vfs.zfs.l2arc_write_max: 8388608 vfs.zfs.l2arc_write_boost: 8388608 vfs.zfs.l2arc_headroom: 2 vfs.zfs.l2arc_feed_secs: 1 vfs.zfs.l2arc_feed_min_ms: 200 vfs.zfs.l2arc_noprefetch: 1 vfs.zfs.l2arc_feed_again: 1 vfs.zfs.l2arc_norw: 1 vfs.zfs.anon_size: 16384 vfs.zfs.anon_metadata_lsize: 0 vfs.zfs.anon_data_lsize: 0 vfs.zfs.mru_size: 18898130944 vfs.zfs.mru_metadata_lsize: 10115874816 vfs.zfs.mru_data_lsize: 8479965184 vfs.zfs.mru_ghost_size: 6764165120 vfs.zfs.mru_ghost_metadata_lsize: 6764165120 vfs.zfs.mru_ghost_data_lsize: 0 vfs.zfs.mfu_size: 4986851840 vfs.zfs.mfu_metadata_lsize: 4631966208 vfs.zfs.mfu_data_lsize: 0 vfs.zfs.mfu_ghost_size: 2492798976 vfs.zfs.mfu_ghost_metadata_lsize: 2492798976 vfs.zfs.mfu_ghost_data_lsize: 0 vfs.zfs.l2c_only_size: 0 vfs.zfs.dedup.prefetch: 1 vfs.zfs.nopwrite_enabled: 1 vfs.zfs.mdcomp_disable: 0 vfs.zfs.prefetch_disable: 0 vfs.zfs.zfetch.max_streams: 8 vfs.zfs.zfetch.min_sec_reap: 2 vfs.zfs.zfetch.block_cap: 256 vfs.zfs.zfetch.array_rd_sz: 1048576 vfs.zfs.top_maxinflight: 32 vfs.zfs.resilver_delay: 2 vfs.zfs.scrub_delay: 4 vfs.zfs.scan_idle: 50 vfs.zfs.scan_min_time_ms: 1000 vfs.zfs.free_min_time_ms: 1000 vfs.zfs.resilver_min_time_ms: 3000 vfs.zfs.no_scrub_io: 0 vfs.zfs.no_scrub_prefetch: 0 vfs.zfs.metaslab.gang_bang: 131073 vfs.zfs.metaslab.debug_load: 0 vfs.zfs.metaslab.debug_unload: 0 vfs.zfs.metaslab.df_alloc_threshold: 131072 vfs.zfs.metaslab.df_free_pct: 4 vfs.zfs.metaslab.min_alloc_size: 10485760 vfs.zfs.metaslab.load_pct: 50 vfs.zfs.metaslab.unload_delay: 8 vfs.zfs.metaslab.preload_limit: 3 vfs.zfs.metaslab.preload_enabled: 1 vfs.zfs.metaslab.weight_factor_enable: 0 vfs.zfs.condense_pct: 200 vfs.zfs.mg_alloc_failures: 12 vfs.zfs.mg_noalloc_threshold: 0 vfs.zfs.write_to_degraded: 0 vfs.zfs.check_hostid: 1 vfs.zfs.recover: 0 vfs.zfs.deadman_synctime_ms: 1000000 vfs.zfs.deadman_checktime_ms: 5000 vfs.zfs.deadman_enabled: 0 vfs.zfs.spa_asize_inflation: 24 vfs.zfs.txg.timeout: 5 vfs.zfs.vdev.cache.max: 16384 vfs.zfs.vdev.cache.size: 0 vfs.zfs.vdev.cache.bshift: 16 vfs.zfs.vdev.trim_on_init: 1 vfs.zfs.vdev.max_active: 1000 vfs.zfs.vdev.sync_read_min_active: 10 vfs.zfs.vdev.sync_read_max_active: 10 vfs.zfs.vdev.sync_write_min_active: 10 vfs.zfs.vdev.sync_write_max_active: 10 vfs.zfs.vdev.async_read_min_active: 1 vfs.zfs.vdev.async_read_max_active: 3 vfs.zfs.vdev.async_write_min_active: 1 vfs.zfs.vdev.async_write_max_active: 10 vfs.zfs.vdev.scrub_min_active: 1 vfs.zfs.vdev.scrub_max_active: 2 vfs.zfs.vdev.aggregation_limit: 131072 vfs.zfs.vdev.read_gap_limit: 32768 vfs.zfs.vdev.write_gap_limit: 4096 vfs.zfs.vdev.bio_flush_disable: 0 vfs.zfs.vdev.bio_delete_disable: 0 vfs.zfs.vdev.trim_max_bytes: 2147483648 vfs.zfs.vdev.trim_max_pending: 64 vfs.zfs.max_auto_ashift: 13 vfs.zfs.zil_replay_disable: 0 vfs.zfs.cache_flush_disable: 0 vfs.zfs.zio.use_uma: 1 vfs.zfs.zio.exclude_metadata: 0 vfs.zfs.sync_pass_deferred_free: 2 vfs.zfs.sync_pass_dont_compress: 5 vfs.zfs.sync_pass_rewrite: 2 vfs.zfs.snapshot_list_prefetch: 0 vfs.zfs.super_owner: 0 vfs.zfs.debug: 0 vfs.zfs.version.ioctl: 3 vfs.zfs.version.acl: 1 vfs.zfs.version.spa: 5000 vfs.zfs.version.zpl: 5 vfs.zfs.trim.enabled: 1 vfs.zfs.trim.txg_delay: 32 vfs.zfs.trim.timeout: 30 vfs.zfs.trim.max_interval: 1
_______________________________________________ developer mailing list developer@open-zfs.org http://lists.open-zfs.org/mailman/listinfo/developer