Fwd: Re: Strange ZFS performance
Jeremy Chadwick
it CC'd). The attachments are included inline.
SMART stats for the disk look fine, so the disk is unlikely to be
responsible for this issue. OP, could you also please provide the
output of "atacontrol cap ad12"?
The arcstats entry that interested me the most was this (prior to the
reboot):
> kstat.zfs.misc.arcstats.memory_throttle_count: 39958287
The box probably needs tuning in /boot/loader.conf to relieve this
problem.
Below are values I've been using on our production systems for a month
or two now. These are for machines with 8GB RAM installed. The OP may
need to adjust the first two parameters (I tend to go with RAM/2 for
vm.kmem_size and then subtract a bit more for arc_max (in this case
512MB less than kmem_size)).
# Increase vm.kmem_size to allow for ZFS ARC to utilise more memory.
vm.kmem_size="4096M"
vfs.zfs.arc_max="3584M"
# Disable ZFS prefetching
# http://southbrain.com/south/2008/04/the-nightmare-comes-slowly-zfs.html
# Increases overall speed of ZFS, but when disk flushing/writes occur,
# system is less responsive (due to extreme disk I/O).
# NOTE: 8.0-RC1 disables this by default on systems <= 4GB RAM anyway
# NOTE: System has 8GB of RAM, so prefetch would be enabled by default.
vfs.zfs.prefetch_disable="1"
# Decrease ZFS txg timeout value from 30 (default) to 5 seconds. This
# should increase throughput and decrease the "bursty" stalls that
# happen during immense I/O with ZFS.
# http://lists.freebsd.org/pipermail/freebsd-fs/2009-December/007343.html
# http://lists.freebsd.org/pipermail/freebsd-fs/2009-December/007355.html
vfs.zfs.txg.timeout="5"
--
| Jeremy Chadwick j...@parodius.com |
| Parodius Networking http://www.parodius.com/ |
| UNIX Systems Administrator Mountain View, CA, USA |
| Making life hard for others since 1977. PGP: 4BD6C0CB |
----- Forwarded message from Mikle <nekoex...@gmail.com> -----
> From: Mikle <nekoex...@gmail.com>
> To: Jeremy Chadwick <fre...@jdc.parodius.com>
> Date: Mon, 5 Apr 2010 01:25:36 +0400
> Cc: freeb...@freebsd.org
> Subject: Re: Strange ZFS performance
>
> On Sun, Apr 04, 2010 at 01:41:27PM -0700, Jeremy Chadwick wrote:
> > Please provide the following output:
> >
> > 1) uname -a
> > 2) sysctl kstat.zfs.misc.arcstats
> > 3) smartctl -a /dev/ad12
> FreeBSD takino.zet 8.0-STABLE FreeBSD 8.0-STABLE #0: Mon Mar 8 06:25:34 MSK 2010 ro...@takino.zet:/usr/obj/usr/src/sys/TAKINO amd64
> (TAKINO is pretty basic untuned config, generic config plus ipfw-related things minus '-g' debug flag)
> sysctl & smart outputs are in the attaches.
> > Also, does rebooting the box restore write speed (yes, this is a serious
> > question/recommendation)?
> Yes, it did slightly: after reboot i got 6MB/s.
>
> Also, one more (may be) related thing: there was a power-crash some time ago.
>
> Wbr,
> smartctl 5.39.1 2010-01-28 r3054 [FreeBSD 8.0-STABLE amd64] (local build)
> Copyright (C) 2002-10 by Bruce Allen, http://smartmontools.sourceforge.net
>
> === START OF INFORMATION SECTION ===
> Model Family: Western Digital Caviar Green family
> Device Model: WDC WD10EADS-00M2B0
> Serial Number: WD-WMAV50024981
> Firmware Version: 01.00A01
> User Capacity: 1,000,204,886,016 bytes
> Device is: In smartctl database [for details use: -P show]
> ATA Version is: 8
> ATA Standard is: Exact ATA specification draft version not indicated
> Local Time is: Mon Apr 5 00:53:13 2010 MSD
> SMART support is: Available - device has SMART capability.
> SMART support is: Enabled
>
> === START OF READ SMART DATA SECTION ===
> SMART overall-health self-assessment test result: PASSED
>
> General SMART Values:
> Offline data collection status: (0x84) Offline data collection activity
> was suspended by an interrupting command from host.
> Auto Offline Data Collection: Enabled.
> Self-test execution status: ( 0) The previous self-test routine completed
> without error or no self-test has ever
> been run.
> Total time to complete Offline
> data collection: (19980) seconds.
> Offline data collection
> capabilities: (0x7b) SMART execute Offline immediate.
> Auto Offline data collection on/off support.
> Suspend Offline collection upon new
> command.
> Offline surface scan supported.
> Self-test supported.
> Conveyance Self-test supported.
> Selective Self-test supported.
> SMART capabilities: (0x0003) Saves SMART data before entering
> power-saving mode.
> Supports SMART auto save timer.
> Error logging capability: (0x01) Error logging supported.
> General Purpose Logging supported.
> Short self-test routine
> recommended polling time: ( 2) minutes.
> Extended self-test routine
> recommended polling time: ( 230) minutes.
> Conveyance self-test routine
> recommended polling time: ( 5) minutes.
> SCT capabilities: (0x303f) SCT Status supported.
> SCT Feature Control supported.
> SCT Data Table supported.
>
> SMART Attributes Data Structure revision number: 16
> Vendor Specific SMART Attributes with Thresholds:
> ID# ATTRIBUTE_NAME FLAG VALUE WORST THRESH TYPE UPDATED WHEN_FAILED RAW_VALUE
> 1 Raw_Read_Error_Rate 0x002f 200 200 051 Pre-fail Always - 1
> 3 Spin_Up_Time 0x0027 111 107 021 Pre-fail Always - 7441
> 4 Start_Stop_Count 0x0032 100 100 000 Old_age Always - 488
> 5 Reallocated_Sector_Ct 0x0033 200 200 140 Pre-fail Always - 0
> 7 Seek_Error_Rate 0x002e 200 200 000 Old_age Always - 3
> 9 Power_On_Hours 0x0032 093 093 000 Old_age Always - 5568
> 10 Spin_Retry_Count 0x0032 100 100 000 Old_age Always - 0
> 11 Calibration_Retry_Count 0x0032 100 100 000 Old_age Always - 0
> 12 Power_Cycle_Count 0x0032 100 100 000 Old_age Always - 290
> 192 Power-Off_Retract_Count 0x0032 200 200 000 Old_age Always - 23
> 193 Load_Cycle_Count 0x0032 200 200 000 Old_age Always - 464
> 194 Temperature_Celsius 0x0022 114 098 000 Old_age Always - 33
> 196 Reallocated_Event_Count 0x0032 200 200 000 Old_age Always - 0
> 197 Current_Pending_Sector 0x0032 200 200 000 Old_age Always - 0
> 198 Offline_Uncorrectable 0x0030 200 200 000 Old_age Offline - 0
> 199 UDMA_CRC_Error_Count 0x0032 200 200 000 Old_age Always - 1
> 200 Multi_Zone_Error_Rate 0x0008 200 200 000 Old_age Offline - 0
>
> SMART Error Log Version: 1
> No Errors Logged
>
> SMART Self-test log structure revision number 1
> No self-tests have been logged. [To run self-tests, use: smartctl -t]
>
>
> SMART Selective self-test log data structure revision number 1
> SPAN MIN_LBA MAX_LBA CURRENT_TEST_STATUS
> 1 0 0 Not_testing
> 2 0 0 Not_testing
> 3 0 0 Not_testing
> 4 0 0 Not_testing
> 5 0 0 Not_testing
> Selective self-test flags (0x0):
> After scanning selected spans, do NOT read-scan remainder of disk.
> If Selective self-test is pending on power-up, resume after 0 minute delay.
>
> kstat.zfs.misc.arcstats.hits: 10478566
> kstat.zfs.misc.arcstats.misses: 2896913
> kstat.zfs.misc.arcstats.demand_data_hits: 7189095
> kstat.zfs.misc.arcstats.demand_data_misses: 2588712
> kstat.zfs.misc.arcstats.demand_metadata_hits: 3289471
> kstat.zfs.misc.arcstats.demand_metadata_misses: 308201
> kstat.zfs.misc.arcstats.prefetch_data_hits: 0
> kstat.zfs.misc.arcstats.prefetch_data_misses: 0
> kstat.zfs.misc.arcstats.prefetch_metadata_hits: 0
> kstat.zfs.misc.arcstats.prefetch_metadata_misses: 0
> kstat.zfs.misc.arcstats.mru_hits: 4075848
> kstat.zfs.misc.arcstats.mru_ghost_hits: 184856
> kstat.zfs.misc.arcstats.mfu_hits: 6402718
> kstat.zfs.misc.arcstats.mfu_ghost_hits: 59708
> kstat.zfs.misc.arcstats.deleted: 2809459
> kstat.zfs.misc.arcstats.recycle_miss: 2950531
> kstat.zfs.misc.arcstats.mutex_miss: 3149
> kstat.zfs.misc.arcstats.evict_skip: 34090903
> kstat.zfs.misc.arcstats.hash_elements: 12170
> kstat.zfs.misc.arcstats.hash_elements_max: 20747
> kstat.zfs.misc.arcstats.hash_collisions: 363681
> kstat.zfs.misc.arcstats.hash_chains: 1727
> kstat.zfs.misc.arcstats.hash_chain_max: 5
> kstat.zfs.misc.arcstats.p: 344023154
> kstat.zfs.misc.arcstats.c: 414288960
> kstat.zfs.misc.arcstats.c_min: 53456640
> kstat.zfs.misc.arcstats.c_max: 427653120
> kstat.zfs.misc.arcstats.size: 409855944
> kstat.zfs.misc.arcstats.hdr_size: 2531984
> kstat.zfs.misc.arcstats.l2_hits: 0
> kstat.zfs.misc.arcstats.l2_misses: 0
> kstat.zfs.misc.arcstats.l2_feeds: 0
> kstat.zfs.misc.arcstats.l2_rw_clash: 0
> kstat.zfs.misc.arcstats.l2_writes_sent: 0
> kstat.zfs.misc.arcstats.l2_writes_done: 0
> kstat.zfs.misc.arcstats.l2_writes_error: 0
> kstat.zfs.misc.arcstats.l2_writes_hdr_miss: 0
> kstat.zfs.misc.arcstats.l2_evict_lock_retry: 0
> kstat.zfs.misc.arcstats.l2_evict_reading: 0
> kstat.zfs.misc.arcstats.l2_free_on_write: 0
> kstat.zfs.misc.arcstats.l2_abort_lowmem: 0
> kstat.zfs.misc.arcstats.l2_cksum_bad: 0
> kstat.zfs.misc.arcstats.l2_io_error: 0
> kstat.zfs.misc.arcstats.l2_size: 0
> kstat.zfs.misc.arcstats.l2_hdr_size: 0
> kstat.zfs.misc.arcstats.memory_throttle_count: 39958287
> kstat.zfs.misc.arcstats.hits: 70211
> kstat.zfs.misc.arcstats.misses: 4902
> kstat.zfs.misc.arcstats.demand_data_hits: 50240
> kstat.zfs.misc.arcstats.demand_data_misses: 2813
> kstat.zfs.misc.arcstats.demand_metadata_hits: 19971
> kstat.zfs.misc.arcstats.demand_metadata_misses: 2089
> kstat.zfs.misc.arcstats.prefetch_data_hits: 0
> kstat.zfs.misc.arcstats.prefetch_data_misses: 0
> kstat.zfs.misc.arcstats.prefetch_metadata_hits: 0
> kstat.zfs.misc.arcstats.prefetch_metadata_misses: 0
> kstat.zfs.misc.arcstats.mru_hits: 28017
> kstat.zfs.misc.arcstats.mru_ghost_hits: 8
> kstat.zfs.misc.arcstats.mfu_hits: 42194
> kstat.zfs.misc.arcstats.mfu_ghost_hits: 0
> kstat.zfs.misc.arcstats.deleted: 195
> kstat.zfs.misc.arcstats.recycle_miss: 0
> kstat.zfs.misc.arcstats.mutex_miss: 0
> kstat.zfs.misc.arcstats.evict_skip: 1571
> kstat.zfs.misc.arcstats.hash_elements: 6036
> kstat.zfs.misc.arcstats.hash_elements_max: 6043
> kstat.zfs.misc.arcstats.hash_collisions: 781
> kstat.zfs.misc.arcstats.hash_chains: 454
> kstat.zfs.misc.arcstats.hash_chain_max: 3
> kstat.zfs.misc.arcstats.p: 283834368
> kstat.zfs.misc.arcstats.c: 427653120
> kstat.zfs.misc.arcstats.c_min: 53456640
> kstat.zfs.misc.arcstats.c_max: 427653120
> kstat.zfs.misc.arcstats.size: 409581888
> kstat.zfs.misc.arcstats.hdr_size: 1261312
> kstat.zfs.misc.arcstats.l2_hits: 0
> kstat.zfs.misc.arcstats.l2_misses: 0
> kstat.zfs.misc.arcstats.l2_feeds: 0
> kstat.zfs.misc.arcstats.l2_rw_clash: 0
> kstat.zfs.misc.arcstats.l2_writes_sent: 0
> kstat.zfs.misc.arcstats.l2_writes_done: 0
> kstat.zfs.misc.arcstats.l2_writes_error: 0
> kstat.zfs.misc.arcstats.l2_writes_hdr_miss: 0
> kstat.zfs.misc.arcstats.l2_evict_lock_retry: 0
> kstat.zfs.misc.arcstats.l2_evict_reading: 0
> kstat.zfs.misc.arcstats.l2_free_on_write: 0
> kstat.zfs.misc.arcstats.l2_abort_lowmem: 0
> kstat.zfs.misc.arcstats.l2_cksum_bad: 0
> kstat.zfs.misc.arcstats.l2_io_error: 0
> kstat.zfs.misc.arcstats.l2_size: 0
> kstat.zfs.misc.arcstats.l2_hdr_size: 0
> kstat.zfs.misc.arcstats.memory_throttle_count: 0
----- End forwarded message -----
Mikle Krutov
vm.kmem_size="1024M"
vfs.zfs.arc_max="512M"
vfs.zfs.txg.timeout="5"
No change in perfomance. Also, now reading directrly from hdd is slow, too (22-30MB/s), so that shows me that this could be some hardware problem (sata controller? but than the other disks were in same situation too. also, i've thought that that could be sata cable - and changed it - no speed after this).
Additional information for dd:
dd if=/dev/zero of=./file bs=4M count=10
41943040 bytes transferred in 0.039295 secs (1067389864 bytes/sec)
dd if=/dev/zero of=./file bs=4M count=20
83886080 bytes transferred in 0.076702 secs (1093663943 bytes/sec)
dd if=/dev/zero of=./file bs=4M count=30
125829120 bytes transferred in 0.114576 secs (1098216647 bytes/sec)
dd if=/dev/zero of=./file bs=4M count=40
167772160 bytes transferred in 0.174362 secs (962206293 bytes/sec)
dd if=/dev/zero of=./file bs=4M count=50
209715200 bytes transferred in 45.636052 secs (4595384 bytes/sec)
done without any delay, all the time zpool iostat & gstat are showing me 100KB/s-3MB/s
Any information i could provide to help us know what's the source of the problem?
--
Wbr,
Krutov Mikle
Mikle Krutov
> On Mon, 5 Apr 2010, Mikle Krutov wrote:
> > Any information i could provide to help us know what's the source of the problem?
>
> large. I suggest running
>
> iostat -x 30
>
> while doing long-duration write and see what the actual values are.
> It seems likely that you are overrunning what your controller or disk
> is capable of handling and this is creating an I/O backlog which is
> far greater than what it would be if zfs had queued fewer
> simultaneous requests.
>
> It may be that tuning zfs_vdev_max_pending to a small value may help
> keep your controller from being overloaded.
>
> Bob
> --
> Bob Friesenhahn
> bfri...@simple.dallas.tx.us, http://www.simplesystems.org/users/bfriesen/
> GraphicsMagick Maintainer, http://www.GraphicsMagick.org/
With copeing from one disk to another (e.g. reading from ad12), svc_t is
pretty large (2.0-3.5 on target disk v.s. 11 in the beginning - up to 42
to the end on ad12).
For writing it is ~20 in the beginning, and pretty fast it enlarges to 200
Also, if it was the overrun of hdd/controller capability, by my mind,
io should have been very slow for some amount of time, while zfs is flushing
the data from mem to the hdd, and then it should go up to normal 60MB/s.
It does not happen, e.g. if i'm trying to write something just after
reboot with no data to be flushed from my mem speed is already 2-6MB/s
But still, i've tried to set vfs.zfs.vdev.max_pending to 8 and 4, it did not help.
--
Wbr,
Krutov Mikle