Ongoing bursts of pool traffic not from userland/zpl

[rottegift]

On all pools, including those that have been imported with the -N flag, and including brand new pools, at the top of the master/master zfs/spl branch and with the xnuzones spl branch (which is more stable for me) and with http://lundman.net/ftp/osx.zfs/osx.zfs-signed-20131225.dmg on a fresh Mavericks,
there is periodic traffic to and from the pools such that they are never quiet enough to spin down. It's also a substantial number of IOPS.

Where is the traffic coming from? Nothing at the vfs level and up, surely, so probably nothing in userland. fs_usage and a bit of dtrace with anything that doesn't rely on dereferencing arg[0]->blah is unrevealing.

1. create new pool (of any type)
2. watch the sporadic traffic
3. export the pool
4. import the pool with -N
5. watch the sporadic traffic

: root@cla:solaris ; dd if=/dev/zero of=test bs=4k count=1m
: root@cla:solaris ; zpool create testpool /Volumes/Mule/solaris/test
cla:~ smd$ zpool iostat testpool 5
capacity operations bandwidth
pool alloc free read write read write

---

testpool 888K 3.97G 0 158 1.80K 337K
testpool 888K 3.97G 0 125 0 129K
testpool 888K 3.97G 0 124 0 129K
testpool 888K 3.97G 0 161 0 172K
testpool 888K 3.97G 0 115 0 129K
testpool 888K 3.97G 0 49 0 56.4K
testpool 888K 3.97G 0 101 0 115K
: root@cla:solaris ; zpool export testpool
Unmount successful for /testpool
: root@cla:solaris ; zpool import -N -d /Volumes/Mule/solaris/ testpool
cla:~ smd$ zpool iostat testpool 5
capacity operations bandwidth
pool alloc free read write read write

---

testpool 978K 3.97G 9 161 87.7K 220K
testpool 973K 3.97G 0 41 0 42.9K
testpool 944K 3.97G 0 0 0 0
testpool 916K 3.97G 0 0 0 0
testpool 916K 3.97G 0 0 0 0
testpool 916K 3.97G 0 0 0 0
testpool 916K 3.97G 0 0 0 0
testpool 973K 3.97G 0 41 0 42.9K
testpool 1.21M 3.97G 0 188 0 396K
testpool 973K 3.97G 0 120 0 122K
...
ad infinitum

The really weird thing is the changing alloc count. It did not seem to be reflected in the top level dataset properties, but that's not the case. The dataset is still not mounted but:

cla:~ smd$ zfs get -p all testpool | egrep 'used|referenced|written'
testpool used 885760 -
testpool referenced 804352 -
testpool usedbysnapshots 0 -
testpool usedbydataset 804352 -
testpool usedbychildren 81408 -
testpool usedbyrefreservation 0 -
testpool written 804352 -
cla:~ smd$ zfs get -p all testpool | egrep 'used|referenced|written'
testpool used 1054720 -
testpool referenced 804352 -
testpool usedbysnapshots 0 -
testpool usedbydataset 804352 -
testpool usedbychildren 250368 -
testpool usedbyrefreservation 0 -
testpool written 804352 -
cla:~ smd$ zfs get -p all testpool | egrep 'used|referenced|written'
testpool used 885760 -
testpool referenced 804352 -
testpool usedbysnapshots 0 -
testpool usedbydataset 804352 -
testpool usedbychildren 81408 -
testpool usedbyrefreservation 0 -
testpool written 804352 -

Why on earth would usedbychildren increase?

[alanruttenberg]

I am also seeing writing every 30 seconds. Links below to the output of
sudo fs_usage -w -f filesys | egrep /dev/disk\[0345789].\*
for one of those writes, as well as for zdb

I don't see increases in usedbychildren.

Spotlight is turned off

https://dl.dropboxusercontent.com/u/4905123/zdb-2014-02-04.txt.txt
https://dl.dropboxusercontent.com/u/4905123/fsusage-2014-02-04.txt

[rottegift]

Possibly cross-platform

http://lists.freebsd.org/pipermail/freebsd-fs/2014-January/018774.html

(atime is obviously a red herring - I get the traffic with atime=off and nothing mounted at all)

and ollllld

openzfs/zfs#210

But I do not see this behaviour when the empty test pools are imported in OmniOS r151008j.

[chenpc]

As I trace code and use DTrace
I found that the root cause is osx issues vfs sync every 25s.

          zfs`spa_sync_allpools+0xad
          zfs`zfs_vfs_sync+0x18
          mach_kernel`VFS_SYNC+0xc6
          mach_kernel`0xffffff80003e4b30+0x43
          mach_kernel`vfs_iterate+0x10a
          mach_kernel`sync+0x17
          mach_kernel`unix_syscall64+0x1f3
          mach_kernel`hndl_unix_scall64+0x16

And we handle zfs_vfs_sync as spa_sync_allpools.
spa_sync_allpools force txg to move on and force uberblock updating even if there is no dirty data.

In face, we should separate each vfs and handle this sync call by zil_commit.(just like FreeBSD/Linux)

You can re-produce this issue by just typing 'sync' from the terminal.

I suggest that we should try to store zfsvfs by vfs_fsprivate

[rottegift]

Yup, zfs_vfs_sync appears to be the source of the traffic pattern I reported. Thanks for finding it.

In face, we should separate each vfs and handle this sync call by zil_commit.(just like FreeBSD/Linux)

… or indeed like maczfs and Apple’s zfs-59.

[lundman]

openzfsonosx/spl@d020b25
b8bf95d

Modelled after FreeBSD's vfs_sync. Hopefully that will make things more quiet.

[rottegift]

Works fine in master and upstream-20140408.

Thanks !

[lundman]

Ok the new sync had a bug where it would try to sync ctldir (.zfs) entries as well, and would panic. I would recommend updating. And definitely do not set snapdirs=visible until then.
7186f19...394c35e
5508c08