ports/editors/vim — unacceptable patch methodology

UPDATE: It seems the port maintainer decided that he should rename the patch file to 7.2.041^. Yes, that’s right, a caret on the end. This addresses the problem with URI escaping for people who pull patches locally via HTTP, but why he chose this naming convention is beyond me. Given the Makefile’s non-complexity, is it that hard to call the patch 7.2.041-freebsd-ports? Or better yet, why not commit it to CVS — files/ does exist for a reason…

This also applies to ports/editors/vim-lite, obviously.

It seems a recent change to the vim port has introduced a “custom” patch file, called 7.2.041% (note the percentage symbol at the end). Another user has opened up a PR on this matter, but the responsible individual has not responded in a month:

http://www.freebsd.org/cgi/query-pr.cgi?pr=ports/135689

Rather than accept silence, I discussed the matter with flz@freebsd.org directly, who initially committed a fix I recommended (removing the PATCHFILES line). This fix was quickly backed out — because apparently the 7.2.041% patch does exist, just not on any of the official vim mirrors.

So where is this patch, and why can’t it be fetched? Well, it can be… you just have to wait 5 full minutes to go through all the mirrors, many of which time out or exhibit odd behaviour (note the Israeli server which results in “protocol error”):

# cd /usr/ports/editors/vim-lite
# time make fetch
=> 7.2.041% doesn't seem to exist in /usr/ports/distfiles/vim.
=> Attempting to fetch from http://ftp.vim.org/pub/vim/patches/7.2/.
fetch: http://ftp.vim.org/pub/vim/patches/7.2/7.2.041%: Bad Request
=> Attempting to fetch from http://ftp.vim.org/pub/vim/patches/7.2/.
fetch: http://ftp.vim.org/pub/vim/patches/7.2/7.2.041%: Bad Request
=> Attempting to fetch from http://mirrors.24-7-solutions.net/pub/vim/patches/7.2/.
fetch: http://mirrors.24-7-solutions.net/pub/vim/patches/7.2/7.2.041%: Bad Request
=> Attempting to fetch from http://ftp.tw.vim.org/pub/vim/patches/7.2/.
fetch: http://ftp.tw.vim.org/pub/vim/patches/7.2/7.2.041%: Bad Request
=> Attempting to fetch from http://vim.stu.edu.tw/patches/7.2/.
fetch: http://vim.stu.edu.tw/patches/7.2/7.2.041%: Not Found
=> Attempting to fetch from http://gd.tuwien.ac.at/pub/vim/patches/7.2/.
fetch: http://gd.tuwien.ac.at/pub/vim/patches/7.2/7.2.041%: Bad Request
=> Attempting to fetch from http://www.etsimo.uniovi.es/pub/vim/patches/7.2/.
fetch: http://www.etsimo.uniovi.es/pub/vim/patches/7.2/7.2.041%: Bad Request
=> Attempting to fetch from http://www.pt.vim.org/pub/vim/patches/7.2/.
fetch: http://www.pt.vim.org/pub/vim/patches/7.2/7.2.041%: Bad Request
=> Attempting to fetch from http://www.pangora.org/vim.org/pub/vim/patches/7.2/.
fetch: http://www.pangora.org/vim.org/pub/vim/patches/7.2/7.2.041%: Operation timed out
=> Attempting to fetch from http://www.math.technion.ac.il/pub/vim/patches/7.2/.
fetch: http://www.math.technion.ac.il/pub/vim/patches/7.2/7.2.041%: Bad Request
=> Attempting to fetch from http://vim.fyxm.net/pub/vim/patches/7.2/.
fetch: http://vim.fyxm.net/pub/vim/patches/7.2/7.2.041%: Bad Request
=> Attempting to fetch from http://zloba.ath.cx/pub/vim/patches/7.2/.
fetch: http://zloba.ath.cx/pub/vim/patches/7.2/7.2.041%: Bad Request
=> Attempting to fetch from http://ftp2.uk.vim.org/sites/ftp.vim.org/pub/vim/patches/7.2/.
fetch: http://ftp2.uk.vim.org/sites/ftp.vim.org/pub/vim/patches/7.2/7.2.041%: Bad Request
=> Attempting to fetch from http://vim.mirror.fr/patches/7.2/.
fetch: http://vim.mirror.fr/patches/7.2/7.2.041%: Operation timed out
=> Attempting to fetch from ftp://ftp.vim.org/pub/vim/patches/7.2/.
fetch: ftp://ftp.vim.org/pub/vim/patches/7.2/7.2.041%: File unavailable (e.g., file not found, no access)
=> Attempting to fetch from ftp://ftp2.us.vim.org/pub/vim/patches/7.2/.
fetch: ftp://ftp2.us.vim.org/pub/vim/patches/7.2/7.2.041%: Operation timed out
=> Attempting to fetch from ftp://ftp9.us.vim.org/pub/vim/patches/7.2/.
fetch: ftp://ftp9.us.vim.org/pub/vim/patches/7.2/7.2.041%: File unavailable (e.g., file not found, no access)
=> Attempting to fetch from ftp://ftp.ca.vim.org/pub/vim/patches/7.2/.
fetch: ftp://ftp.ca.vim.org/pub/vim/patches/7.2/7.2.041%: File unavailable (e.g., file not found, no access)
=> Attempting to fetch from ftp://ftp.nl.vim.org/pub/vim/patches/7.2/.
fetch: ftp://ftp.nl.vim.org/pub/vim/patches/7.2/7.2.041%: File unavailable (e.g., file not found, no access)
=> Attempting to fetch from ftp://ftp.de.vim.org/patches/7.2/.
fetch: ftp://ftp.de.vim.org/patches/7.2/7.2.041%: File unavailable (e.g., file not found, no access)
=> Attempting to fetch from ftp://ftp3.de.vim.org/pub/vim/patches/7.2/.
fetch: ftp://ftp3.de.vim.org/pub/vim/patches/7.2/7.2.041%: File unavailable (e.g., file not found, no access)
=> Attempting to fetch from ftp://ftp.uk.vim.org/pub/vim/patches/7.2/.
fetch: ftp://ftp.uk.vim.org/pub/vim/patches/7.2/7.2.041%: File unavailable (e.g., file not found, no access)
=> Attempting to fetch from ftp://ftp.ie.vim.org/pub/vim/patches/7.2/.
fetch: ftp://ftp.ie.vim.org/pub/vim/patches/7.2/7.2.041%: File unavailable (e.g., file not found, no access)
=> Attempting to fetch from ftp://ftp.at.vim.org/pub/vim/patches/7.2/.
fetch: ftp://ftp.at.vim.org/pub/vim/patches/7.2/7.2.041%: File unavailable (e.g., file not found, no access)
=> Attempting to fetch from ftp://ftp.pt.vim.org/pub/vim/patches/7.2/.
fetch: ftp://ftp.pt.vim.org/pub/vim/patches/7.2/7.2.041%: File unavailable (e.g., file not found, no access)
=> Attempting to fetch from ftp://ftp.is.vim.org/pub/vim/patches/7.2/.
fetch: ftp://ftp.is.vim.org/pub/vim/patches/7.2/7.2.041%: File unavailable (e.g., file not found, no access)
=> Attempting to fetch from ftp://ftp.il.vim.org/pub/vim/patches/7.2/.
fetch: ftp://ftp.il.vim.org/pub/vim/patches/7.2/7.2.041%: Protocol error
=> Attempting to fetch from ftp://ftp.pl.vim.org/pub/vim/patches/7.2/.
fetch: ftp://ftp.pl.vim.org/pub/vim/patches/7.2/7.2.041%: File unavailable (e.g., file not found, no access)
=> Attempting to fetch from ftp://ftp.ro.vim.org/pub/vim/patches/7.2/.
fetch: ftp://ftp.ro.vim.org/pub/vim/patches/7.2/7.2.041%: File unavailable (e.g., file not found, no access)
=> Attempting to fetch from ftp://ftp.sk.vim.org/pub/vim/patches/7.2/.
fetch: ftp://ftp.sk.vim.org/pub/vim/patches/7.2/7.2.041%: File unavailable (e.g., file not found, no access)
=> Attempting to fetch from ftp://ftp.tw.vim.org/pub/vim/patches/7.2/.
fetch: ftp://ftp.tw.vim.org/pub/vim/patches/7.2/7.2.041%: File unavailable (e.g., file not found, no access)
=> Attempting to fetch from ftp://vim.stu.edu.tw/pub/vim/patches/7.2/.
fetch: ftp://vim.stu.edu.tw/pub/vim/patches/7.2/7.2.041%: File unavailable (e.g., file not found, no access)
=> Attempting to fetch from ftp://ftp.jp.vim.org/pub/vim/patches/7.2/.
fetch: ftp://ftp.jp.vim.org/pub/vim/patches/7.2/7.2.041%: File unavailable (e.g., file not found, no access)
=> Attempting to fetch from ftp://ftp.kr.vim.org/pub/vim/patches/7.2/.
fetch: ftp://ftp.kr.vim.org/pub/vim/patches/7.2/7.2.041%: File unavailable (e.g., file not found, no access)
=> Attempting to fetch from ftp://ftp.mirrorservice.org/sites/ftp.vim.org/pub/vim/patches/7.2/.
fetch: ftp://ftp.mirrorservice.org/sites/ftp.vim.org/pub/vim/patches/7.2/7.2.041%: File unavailable (e.g., file not found, no access)
=> Attempting to fetch from ftp://ftp.FreeBSD.org/pub/FreeBSD/ports/local-distfiles/obrien/.
7.2.041%                                      100% of   21 kB   34 kBps
0.256u 0.506s 4:58.00 0.2%      129+1071k 0+0io 0pf+0w

Apparently the 7.2.041% patch is a FreeBSD-specific version of the official 7.2.041 patch which is on the mirrors. But what I’d like to know why this custom FreeBSD-specific 7.2.041 patch was not committed to CVS (e.g. files/7.2.041%). Why must it reside in the maintainer’s public_distfiles? This is silly.

Likewise, I think the existing methodology of vim updates is retarded; for example, there were over 300 patches for 7.0 before 7.1 was released. This isn’t the fault of FreeBSD, but rather Bram Moolenaar.

My experience with an Intel X25-M and Windows XP

EDIT (June 18, 2009)

The friendly guys over at DSLReports informed me that to achieve proper SSD speed, the filesystem actually has to be properly aligned on a 4KB boundary — which Windows XP does not do out-of-the-box. Instead, you’re required to run diskpart.exe on an existing Windows machine with your SSD hooked up to achieve this. The folks over at the OCZ forums have put together quite a series of documents explaining the details. What’s stated there does make sense — remember, flash is memory, and memory alignment (yes, as in RAM!) is actually something kernels and even libc (on *IX) do to ensure performance. So this doesn’t surprise me, and at the same time, probably explains what I’m seeing.

But as my reply says, I feel this is even more evidence that existing software (OSes, applications) are not ready for SSDs yet, and chances of me forgetting to do this the next time I format the drive are very high. It’s simply not worth all this rigmarole.

Below is the original portion of my blog post.

Last week I purchased an Intel X25-M (80GB), as I figured I was ready to plop down over US$300 on something that gave me incredible performance. The drive arrived earlier this week, and included firmware 8820 (saved me the trouble of having to update it). My workstation setup (disk/controller-wise) then became very simple:

• Asus P5Q SE (Intel ICH10-based)
• Intel X25-M, 80GB (SATA II)
• Western Digital WD5000AAKS, 500GB (SATA II)
• Pioneer DVD-ROM (SATA)

The WD drive was going to become D:, dedicated entirely to things like mass storage (movies, downloads, games, etc.), while the X25-M was going to be used as the boot/OS drive and for applications. Simple.

I reinstalled Windows a couple days ago onto the X25-M. The first thing I’ll say is that the installation was definitely faster than that of a hard drive, which is no surprise. The fastest part was once the GUI-based portion of the installer was up — that whole thing took maybe 8 minutes at most. Cool.

Then came booting into XP. Well, this is probably the most impressive thing I’ve ever seen: the time the BIOS finishes POST until the point I’m logged in and have a usable desktop is 6 seconds. That also includes the time it takes for me to type my password. Amazing.

Benchmarks on the X25-M are also equally as impressive. Read speeds are around 220-250MB/sec, while write speeds are around 50-60MB/sec (varies based on block size).

One oddity I did run into was during nVidia driver installation, where the installer suddenly spit out a message stating “Nvsvc could not be started; rebooting your computer will fix this problem”. I’ve never once seen that message on any non-SSD-based system I’ve installed nVidia’s drivers on, and I haven’t seen it since rebooting, but it was still strange. (EDIT: It appears this is a newly-introduced problem with nVidia’s last two driver releases, at least for GeForce 9 and Quadro NVS 440 cards. This problem has nothing to do with an SSD being used. :-) )

And then came what I dreaded… strange “stalls” which I couldn’t explain. These were rare; most of the time things opened quickly (blazingly fast), but there were times when things like Firefox took literally 6-7 seconds to launch.

So I started doing reading. And more reading. And even more reading. The more I read, the more I found troublesome annoyances. Here’s a list of the ones I’ve found:

Web browsers and SSDs don’t mix very well due to use of disk caching for visited pages. Apparently this thrashes too hard on the SSD, and bottlenecks start to appear. Firefox has some about:config parameters you can adjust to help minimise the pain, but the pain still exists. Then I read about how Firefox on an SSD was performing horribly due to use of the “phishing filter” (suspected attack sites and suspected forgery sites), so the solution was to disable those entirely. Specifically, setting these two about:config parms:

• browser.safebrowsing.enabled = false
• browser.safebrowsing.malware.enabled = false

Next came general Windows filesystem performance. I disable NTFS atime (access times) by default regardless if I’m using an SSD or classic hard disk, so that’s not the problem. Occasionally small programs — like CCleaner — would take 2-3 seconds to start. What was the system spending its time doing? I checked Perfmon and wasn’t able to figure it out. It’s like the SSD was “too fast” for the system…

More reading determined I had to do all kinds of bizarre tweaks to the system, including massive registry changes. Here’s a list of what was recommended:

• Disable paging file entirely on C: (SSD), and move it entirely to D: (hard drive)
• Disable the Windows Indexing Service (which didn’t apply to me because the service wasn’t started to begin with
• Disable the Windows Prefetcher — HKLM\SYSTEM\CurrentControlSet\Control\Session Manager\Memory Management\PrefetchParameters\EnablePrefetcher=dword:00000000
• Stop Windows from relocating files required for quicker/faster booting to the front of the disk (improving boot times) — HKLM\Software\Microsoft\Dfrg\BootOptimizeFunction\Enable="N"
• Stop Windows from relocating commonly-used files to sectors closer to the front of the disk (improving launch times) — SOFTWARE\Microsoft\Windows\CurrentVersion\OptimalLayout\EnableAutoLayout=dword:00000000
• Disable NTFS atimes (access times) — HKLM\SYSTEM\CurrentControlSet\Control\FileSystem\NtfsDisableLastAccessUpdate=dword:00000001 (note: I do this on all my systems, so this really isn’t a negative against SSDs)

I also ran into one incident where HD Tach (benchmarking program) crashed in such a way where the process was left lingering around in memory chewing up 100% of one of my cores (e.g. on a quad-core, 25% CPU).

I did all of these things, and didn’t really see any form of improvement. Mysterious unexpected delays when launching things would still happen. CPU usage was not a problem; this was purely something going on behind-the-scenes as a result of the SSD being either too fast, or write operations which were “too” synchronous for the OS.

At this point, I will be returning the SSD to my place of purchase. I really love the no-moving-parts aspect, and I’m impressed by read speeds, but this degree of system tuning required just to get “decent performance” out of something that already HAS screaming performance is… well, not worth it IMHO.

What I’m saying is: SSDs are great, but software (OSes, applications, etc.) are obviously not ready for them. Most software has been engineered under the assumption that there’s a hard disk involved, and hopefully over the next 5-10 years that assumption will change.

I will say one thing about SSDs, though: these would be *perfect* for laptops. Those little stalls and so on are pretty much normal on laptops to begin with (I’m basing this on my experience with a Lenovo T60p Widescreen), so an SSD would decrease laptop heat by a large amount, and increase overall responsiveness. But for the kind of desktop usage I have? Well, the X25-M won’t cut it. And I refuse to “destroy” my Windows system with magical registry tweaks which impact the entire system (and not just a single filesystem).

FreeBSD and ZFS — more performance quirks

I’ve been trying to work out the source of “strange” performance-related issues when using ZFS on FreeBSD. The situation is reproducible, but not always, and it seems the complex inner nature of ZFS is probably contributing to the problem.

The problem I’m trying to track down is what causes sudden fread() operations, with 4KB reads, to suddenly start taking an absurd amount of time (0.2 seconds, for example), on a ZFS raidz1 pool with 4 disks all capable of operating at 80-100MB/sec (read and write).

My understanding is that the slowness is expected initially as ZFS’s ZIL and ARC do not have any reference to this data the first time around. And that’s fine — not to mention, seems true. For example, today I performed the following test:

1) rm Maildir/header_cache.db
2) mutt -y
3) Ran through all of the folders, thus populating the Maildir header cache. A folder with 400 files in it would take maybe 10 full seconds. Then I exited mutt.
4) Again, rm header_cache.db
5) mutt -y
6) Once more, ran through all the folders. This time things were much faster — almost instantaneous. So populating the cache was very fast/quick given that ZFS now had some of the files/whatever cached in the ARC, or possibly references to the system calls in the ZIL.

This is an ideal situation, and makes sense. The ARC has a tendency to grow very large as more and more I/O happens, and that’s fine — that’s the nature of the ZFS beast.

However, where things get bizarre is when the above situation “logical” scenario stops occurring — acting as if the ZFS ARC or ZIL is “full” and doesn’t choose to cache anything more for some particular reason. Again, I can reproduce this quite easily using the above procedure, but it’s not a very good real-world test to post to a mailing list. It’s getting to the point where I’m probably going to have to write some C code that mimics all of the scenarios possible. There is definitely a problem somewhere, and I think that’s the only way I’m going to get people to track it down.

But something today occurred to me while reading the Cache Flushes section of the ZFS Evil Tuning Guide. I was left wondering if setting the FreeBSD equivalent of zfs_nocacheflush would improve things.

So today I decided to set vfs.zfs.cache_flush_disable=1 in /boot/loader.conf to see how things performed.

Something tells me I’m probably going to have to create a ZFS-related WordPress Category in my blog just for this kind of thing. :-)

ZFS support in loader(8) being continually added/removed

FreeBSD users should be aware of the massive rash of commits which have occurred over the past few weeks with regards to LOADER_ZFS_SUPPORT functionality. This functionality has been added, removed, tinkered with, re-added, removed, etc. numerous times. Proof is provided below. As of this writing, LOADER_ZFS_SUPPORT has been disabled entirely. Please see these commits:

• src/sys/boot/i386/loader/Makefile

This affects both i386 and amd64, despite the pathname implying otherwise.

FreeBSD users should be outraged by this, and be questioning why said changes are not being fully tested before being committed. I’ll use this opportunity as confirmation of further proof that all administrators should be paying VERY close attention to commits to src-all in RELEASE and STABLE branches.

I consider this evidence further justification for keeping one’s root filesystem as UFS.

FreeBSD and ZFS — horrible raidz1 speed — finale

A follow-up to the following two posts of mine:

• FreeBSD and ZFS — horrible raidz1 speed
• FreeBSD and ZFS — horrible raidz1 speed — part 2

The problem I described has not recurred since enabling prefetch. So it seems whatever performance-related problems we had with prefetch when ZFS was first committed to FreeBSD “back in the day” have since been addressed. I wish I could pinpoint where/when/how this was fixed, but the beast is complex…

I’ve since re-enabled prefetch on my co-located production servers (Intel ICH7-based) and I’m seeing great improvements there too. Those are single-disk systems (e.g. no raidz1 in use) too.

I’d recommend that users who have previously disabled the ZFS prefetch mechanism on FreeBSD should re-enable it and reboot. :-)

Comcast isn’t messing with my port 53 traffic…

This is in response to the Slashdot article and the official blog post claiming that Comcast is transparently tinkering with TCP port 53 traffic.

Location: Mountain View, CA
Non-Comcast server: 72.20.106.4
Comcast connection: 98.248.46.159

There is an actual nameserver (BIND) running on 72.20.106.4 which per ACLs denies queries being made from non-permitted clients. The Comcast connection is not in the ACL list, so the nameserver should politely return REFUSED no matter what’s queried.

The Comcast connection is behind a router, so NAT is involved.

comcast# dig @72.20.106.4 comcast.sucks.com. a

; <<>> DiG 9.4.3-P2 <<>> @72.20.106.4 comcast.sucks.com. a
; (1 server found)
;; global options:  printcmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: REFUSED, id: 49471
;; flags: qr rd; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 0
;; WARNING: recursion requested but not available

;; QUESTION SECTION:
;comcast.sucks.com.             IN      A

;; Query time: 12 msec
;; SERVER: 72.20.106.4#53(72.20.106.4)
;; WHEN: Tue Jun  9 12:48:57 2009
;; MSG SIZE  rcvd: 35

What the server saw:

server# tcpdump -v -p -i em0 -l -n -s 8192 "host 98.248.46.159 and not port 22 and not port 993"
tcpdump: listening on em0, link-type EN10MB (Ethernet), capture size 8192 bytes
12:48:57.264897 IP (tos 0x20, ttl 54, id 48387, offset 0, flags [none], proto UDP (17), length 63) 98.248.46.159.52697 > 72.20.106.4.53: 49471+ A? comcast.sucks.com. (35)
12:48:57.265005 IP (tos 0x0, ttl 64, id 46332, offset 0, flags [none], proto UDP (17), length 63) 72.20.106.4.53 > 98.248.46.159.52697: 49471 Refused- 0/0/0 (35)


Now let’s try TCP:

comcast# dig @72.20.106.4 comcast.sucks.com. a +tcp

; <<>> DiG 9.4.3-P2 <<>> @72.20.106.4 comcast.sucks.com. a +tcp
; (1 server found)
;; global options:  printcmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: REFUSED, id: 34286
;; flags: qr rd; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 0
;; WARNING: recursion requested but not available

;; QUESTION SECTION:
;comcast.sucks.com.             IN      A

;; Query time: 14 msec
;; SERVER: 72.20.106.4#53(72.20.106.4)
;; WHEN: Tue Jun  9 12:50:37 2009
;; MSG SIZE  rcvd: 35

And what the server saw:

server# tcpdump -v -p -i em0 -l -n -s 8192 "host 98.248.46.159 and not port 22 and not port 993"
12:50:37.675402 IP (tos 0x20, ttl 54, id 50693, offset 0, flags [DF], proto TCP (6), length 60) 98.248.46.159.57521 > 72.20.106.4.53: S, cksum 0xe098 (correct), 1964159373:1964159373(0) win 65535 <mss 1460,nop,wscale 3,sackOK,timestamp 662893746 0>
12:50:37.675443 IP (tos 0x0, ttl 64, id 48248, offset 0, flags [DF], proto TCP (6), length 60) 72.20.106.4.53 > 98.248.46.159.57521: S, cksum 0x9124 (correct), 1547364460:1547364460(0) ack 1964159374 win 65535 <mss 1460,nop,wscale 3,sackOK,timestamp 2908314978 662893746>
12:50:37.689896 IP (tos 0x20, ttl 54, id 50696, offset 0, flags [DF], proto TCP (6), length 52) 98.248.46.159.57521 > 72.20.106.4.53: ., cksum 0x9f5a (correct), ack 1 win 8326 <nop,nop,timestamp 662893758 2908314978>
12:50:37.689927 IP (tos 0x20, ttl 54, id 50697, offset 0, flags [DF], proto TCP (6), length 89) 98.248.46.159.57521 > 72.20.106.4.53: P, cksum 0x6f5a (correct), 1:38(37) ack 1 win 8326 <nop,nop,timestamp 662893758 2908314978>34286+ A? comcast.sucks.com. (35)
12:50:37.690104 IP (tos 0x0, ttl 64, id 48250, offset 0, flags [DF], proto TCP (6), length 89) 72.20.106.4.53 > 98.248.46.159.57521: P, cksum 0xef20 (correct), 1:38(37) ack 38 win 8326 >nop,nop,timestamp 2908314993 662893758>34286 Refused- 0/0/0 (35)
12:50:37.701886 IP (tos 0x20, ttl 54, id 50704, offset 0, flags [DF], proto TCP (6), length 52) 98.248.46.159.57521 > 72.20.106.4.53: F, cksum 0x9ef1 (correct), 38:38(0) ack 38 win 8326 <nop,nop,timestamp 662893773 2908314993>
12:50:37.701905 IP (tos 0x0, ttl 64, id 48251, offset 0, flags [DF], proto TCP (6), length 52) 72.20.106.4.53 > 98.248.46.159.57521: ., cksum 0x9ee5 (correct), ack 39 win 8326 <nop,nop,timestamp 2908315005 662893773>
12:50:37.701938 IP (tos 0x0, ttl 64, id 48252, offset 0, flags [DF], proto TCP (6), length 52) 72.20.106.4.53 > 98.248.46.159.57521: F, cksum 0x9ee4 (correct), 38:38(0) ack 39 win 8326 <nop,nop,timestamp 2908315005 662893773>
12:50:37.713879 IP (tos 0x20, ttl 54, id 50706, offset 0, flags [DF], proto TCP (6), length 52) 98.248.46.159.57521 > 72.20.106.4.53: ., cksum 0x9ed9 (correct), ack 39 win 8325 <nop,nop,timestamp 662893785 2908315005>


Finally, my ICSI results for those who care.

Conclusion: nothing being modified here.

FreeBSD and ZFS — horrible raidz1 speed — part 2

While debugging the aforementioned problem, I decided to try re-enabling ZFS’s prefetch capability as a test; “maybe things have greatly improved between v6 and v13″, I thought.

Based on what I can tell so far (it’s only been 10-15 minutes, and I’ve transferred hundreds of megabytes of data), that appears to have fixed the problem.

$ rm ~/Maildir/header_cache.db
$ time mutt -f ~/Maildir/system

real    0m0.151s
user    0m0.030s
sys     0m0.014s
$ time mutt -f ~/Maildir/system

real    0m0.038s
user    0m0.004s
sys     0m0.012s
$ time mutt -f ~/Maildir/system

real    0m0.493s
user    0m0.012s
sys     0m0.004s

There are occasional times where ZFS “lags”, e.g. the above times will jump up to 0.5 seconds or so, but I believe that’s an issue which has been mentioned many times in the past by users — occasionally ZFS appearing “bursty” in I/O. Not sure what the cause of that is, but I know I’m not the only one seeing that behaviour.

Anyway, I’ll keep an eye on things for a few days and see if things remain speedy or if they get worse. ZFS prefetch being enabled could still be a red herring; for all I know memory fragmentation could be the root of the problem. Who knows — too soon to tell…

FreeBSD and ZFS — horrible raidz1 read speed

I’ve been noticing what appears to be absolutely horrible speeds from a ZFS raidz1 pool, but only in some circumstances — specifically, when mutt and header caching (for Maildir) is used.

The setup is as follows:

ad4: 190782MB <WDC WD2000JD-00HBB0 08.02D08> at ata2-master SATA150
ad8: 715404MB <WDC WD7501AALS-00J7B0 05.00K05> at ata4-master SATA300
ad10: 715404MB <WDC WD7501AALS-00J7B0 05.00K05> at ata5-master SATA300
ad12: 715404MB <WDC WD7500AACS-00D6B0 01.01A01> at ata6-master SATA300
ad14: 715404MB <WDC WD7500AACS-00D6B0 01.01A01> at ata7-master SATA300

        NAME        STATE     READ WRITE CKSUM
        storage     ONLINE       0     0     0
          raidz1    ONLINE       0     0     0
            ad8     ONLINE       0     0     0
            ad10    ONLINE       0     0     0
            ad12    ONLINE       0     0     0
            ad14    ONLINE       0     0     0

Filesystem   1024-blocks      Used      Avail Capacity  Mounted on
storage/home    67108864     95232   67013632     0%    /home
storage       2149507840 227146240 1922361600    11%    /storage
/dev/ad4s1e      8122126     52450    7419906     1%    /tmp

This indicates that /home (e.g. /home/jdc/Maildir) lives on the ZFS pool storage, consisting of four (4) SATA300 disks. The UFS2-based stuff (OS disk, etc.) consists of a single SATA150 disk.

Now for relevant bits from my muttrc:

set mbox_type=Maildir
set folder="~/Maildir"
set mbox="~/Maildir"
set spoolfile="~/Maildir"
set header_cache="~/Maildir/header_cache.db"
set maildir_header_cache_verify=no

Now for the tests. First, we populate the Maildir header cache:

$ rm ~/Maildir/header_cache.db
$ mutt -f ~/Maildir/system
$ ls -l ~/Maildir/header_cache.db
-rw-------    1 jdc       users     671744  1 Jun 20:10 /home/jdc/Maildir/header_cache.db

Next, we copy the contents of ~/Maildir/system (which is on the ZFS pool) to /tmp/Maildir/system (which is UFS2):

$ rsync -a ~/Maildir/system /tmp/Maildir/

mutt will use ~/Maildir/header_cache.db no matter what we pass to the -f flag (see the above muttrc).

And now it’s time to prove my statement.

$ time mutt -f ~/Maildir/system

real    0m3.447s
user    0m0.030s
sys     0m0.022s
$ time mutt -f /tmp/Maildir/system

real    0m0.233s
user    0m0.013s
sys     0m0.022s

The only ZFS-related tunable I’ve set is vfs.zfs.prefetch_disable="1".

I’m really not sure what to make of this — we’re talking about a common operation that’s 17 times slower when using ZFS vs. UFS2. ZFS’s ARC infrastructure should already have the contents of this stuff in memory, so I’m not sure where the delays are coming from. I don’t think it’s ZIL-related, since that’s supposed to be used for writes. Surely raidz1 isn’t *that* slow…?

And before anyone claims my disks are slow or responsible for the problem…

# dd if=/dev/ad4 of=/dev/null bs=64k
 L(q)  ops/s    r/s   kBps   ms/r    w/s   kBps   ms/w   %busy Name
    1    733    733  46883    1.4      0      0    0.0   99.2| ad4

# dd if=/dev/ad8 of=/dev/null bs=64k
 L(q)  ops/s    r/s   kBps   ms/r    w/s   kBps   ms/w   %busy Name
    1   1659   1659 106156    0.6      0      0    0.0   97.0| ad8

# dd if=/dev/ad10 of=/dev/null bs=64k
 L(q)  ops/s    r/s   kBps   ms/r    w/s   kBps   ms/w   %busy Name
    1   1739   1739 111267    0.6      0      0    0.0   96.8| ad10

# dd if=/dev/ad12 of=/dev/null bs=64k
 L(q)  ops/s    r/s   kBps   ms/r    w/s   kBps   ms/w   %busy Name
    1   1461   1461  93510    0.7      0      0    0.0   98.4| ad12

# dd if=/dev/ad14 of=/dev/null bs=64k
 L(q)  ops/s    r/s   kBps   ms/r    w/s   kBps   ms/w   %busy Name
    1   1375   1375  88017    0.7      0      0    0.0   98.3| ad14

They’re not, as can be seen from sequential I/O and gstat(8) output.

I’m willing to bet if I bust out ktrace(1) on this stuff, the delays seen will be on read(2) calls.