monitoring io's on a specific file by remote NFS client on a ZFS filesystem (encore)

[wessels]

Hi,

sorry to post this again but my first post didn't make it to the mailing list.

I'm trying to monitor a file, via the iopattern script from the DTrace
toolkit, which resides on a ZFS filesystem and is being modified by a
remote NFS client. I tried this on b104 and b125 nothing more recent.
Plain iopattern without options shows i/o counters as output but when
I supply the filename via the -f parameter all fields remain zero.
I also tried the following oneliners below:
# ./nfsv3fileio.d
Tracing... Hit Ctrl-C to end.
^C

Rbytes Wbytes Pathname
41631744 41421266 <unknown>

# dtrace -n 'nfsv3:::op-read-start,nfsv3:::op-write-start {
@[probefunc,args[1]->noi_curpath] =count(); }'
dtrace: description 'nfsv3:::op-read-start,nfsv3:::op-write-start '
matched 2 probes
^C

rfs3_read <unknown> 867
rfs3_write <unknown> 3470
# dtrace -n 'fsinfo:::read,fsinfo:::write {
@[probefunc,args[0]->fi_pathname] =count(); }' dtrace: description
'fsinfo:::read,fsinfo:::write ' matched 2 probes
^C

fop_read /etc/default/nfs 2
fop_read /etc/resolv.conf 6
fop_read <unknown> 155
fop_write <unknown> 619

Any ideas why this happens, that's the <unknown>? Yes, the i/o are
detected but on which file?

Thanks,

Frederik

[Kyle Hailey]

The file names are cached and if there is some problem on the client then
the cache might be missing the names. The cache is populated by VOP_LOOKUP()
but if vnode_t v_path is NULL then VOP_LOOKUP() was never run which can
only happen when there is some issue on the client like possibly a reboot
and the vnode is obtained from VFS_VGET().

Try umount/mount of the filesystem on the client and see if it refreshes the
cache.

- Kyle Hailey
http://dboptimizer.com

Post by wessels
Hi,
sorry to post this again but my first post didn't make it to the mailing list.
I'm trying to monitor a file, via the iopattern script from the DTrace
toolkit, which resides on a ZFS filesystem and is being modified by a
remote NFS client. I tried this on b104 and b125 nothing more recent.
Plain iopattern without options shows i/o counters as output but when
I supply the filename via the -f parameter all fields remain zero.
# ./nfsv3fileio.d
Tracing... Hit Ctrl-C to end.
^C
Rbytes Wbytes Pathname
41631744 41421266 <unknown>
# dtrace -n 'nfsv3:::op-read-start,nfsv3:::op-write-start {
@[probefunc,args[1]->noi_curpath] =count(); }'
dtrace: description 'nfsv3:::op-read-start,nfsv3:::op-write-start '
matched 2 probes
^C
rfs3_read <unknown> 867
rfs3_write <unknown> 3470
# dtrace -n 'fsinfo:::read,fsinfo:::write {
@[probefunc,args[0]->fi_pathname] =count(); }' dtrace: description
'fsinfo:::read,fsinfo:::write ' matched 2 probes
^C
fop_read /etc/default/nfs 2
fop_read /etc/resolv.conf 6
fop_read <unknown> 155
fop_write <unknown> 619
Any ideas why this happens, that's the <unknown>? Yes, the i/o are
detected but on which file?
Thanks,
Frederik
_______________________________________________
dtrace-discuss mailing list

[wessels]

@Kyle, thanks for looking into this.

The clients are VMWare esx 4.0u1 machines so unmounting their
datastores is a bit difficult since they are production machines.

I fail to see the relation between the nfs client and the iopattern
dtrace script for example. That script is supposed to opperate on the
local filesystem right? So why doesn't it register any i/o's for a
file being actively modified?

All I want to monitor is the amount and size (as second step) of the
i/o's per virtual disk.
Any suggestion is more than welcome.

Frederik

The file names are cached and if there is some problem on the client then the cache might be missing the names. The cache is populated by VOP_LOOKUP() but if vnode_t v_path is NULL then  VOP_LOOKUP() was never run which can only happen when there is some issue on the client like possibly a reboot and the vnode is obtained from VFS_VGET().
Try umount/mount of the filesystem on the client and see if it refreshes the cache.
- Kyle Hailey
http://dboptimizer.com

Post by wessels
Hi,
sorry to post this again but my first post didn't make it to the mailing list.
I'm trying to monitor a file, via the iopattern script from the DTrace
toolkit, which resides on a ZFS filesystem and is being modified by a
remote NFS client. I tried this on b104 and b125 nothing more recent.
Plain iopattern without options shows i/o counters as output but when
I supply the filename via the -f parameter all fields remain zero.
# ./nfsv3fileio.d
Tracing... Hit Ctrl-C to end.
^C
Rbytes Wbytes Pathname
41631744 41421266 <unknown>
# dtrace -n 'nfsv3:::op-read-start,nfsv3:::op-write-start {
@[probefunc,args[1]->noi_curpath] =count(); }'
dtrace: description 'nfsv3:::op-read-start,nfsv3:::op-write-start '
matched 2 probes
^C
rfs3_read <unknown> 867
rfs3_write <unknown> 3470
# dtrace -n 'fsinfo:::read,fsinfo:::write {
@[probefunc,args[0]->fi_pathname] =count(); }' dtrace: description
'fsinfo:::read,fsinfo:::write ' matched 2 probes
^C
fop_read /etc/default/nfs 2
fop_read /etc/resolv.conf 6
fop_read <unknown> 155
fop_write <unknown> 619
Any ideas why this happens, that's the <unknown>? Yes, the i/o are
detected but on which file?
Thanks,
Frederik
_______________________________________________
dtrace-discuss mailing list

--
- Kyle
O: +1.415.341.3430
F: +1.650.494.1676
275 Middlefield Road, Suite 50
Menlo Park, CA 94025
http://www.delphix.com

[Brendan Gregg]

Post by wessels
@Kyle, thanks for looking into this.
The clients are VMWare esx 4.0u1 machines so unmounting their
datastores is a bit difficult since they are production machines.
I fail to see the relation between the nfs client and the iopattern
dtrace script for example. That script is supposed to opperate on the
local filesystem right? So why doesn't it register any i/o's for a
file being actively modified?

It depends where you run iopattern.

When run on the ZFS/NFS server, iopattern will trace back-end I/O to the
local disks. This may not match ZFS/NFS very well at all, due to reads
being cached and writes being buffered and flushed later. I'd use the nfs
provider if you want to see what is being requested.

When run on the NFS client, if the client is Solaris then iopattern will
match NFS client requests (which are matched by io:::done). I don't think
Mac OS X matches NFS client I/O via the io provider yet.

All I want to monitor is the amount and size (as second step) of the

Post by wessels
i/o's per virtual disk.

If you don't care about the NFS details (filename, remote IP, etc), and if
by virtual disk you mean the local disks ZFS is using, then the io provider
should work fine. If you don't see I/O, then ZFS is caching or buffering
it.

Brendan

Post by wessels
Any suggestion is more than welcome.
Frederik

Post by Kyle Hailey
The file names are cached and if there is some problem on the client then

the cache might be missing the names. The cache is populated by VOP_LOOKUP()
but if vnode_t v_path is NULL then VOP_LOOKUP() was never run which can
only happen when there is some issue on the client like possibly a reboot
and the vnode is obtained from VFS_VGET().

Post by Kyle Hailey
Try umount/mount of the filesystem on the client and see if it refreshes

the cache.

Post by Kyle Hailey
- Kyle Hailey
http://dboptimizer.com

Post by wessels
Hi,
sorry to post this again but my first post didn't make it to the mailing

list.

Post by Kyle Hailey

Post by wessels
I'm trying to monitor a file, via the iopattern script from the DTrace
toolkit, which resides on a ZFS filesystem and is being modified by a
remote NFS client. I tried this on b104 and b125 nothing more recent.
Plain iopattern without options shows i/o counters as output but when
I supply the filename via the -f parameter all fields remain zero.
# ./nfsv3fileio.d
Tracing... Hit Ctrl-C to end.
^C
Rbytes Wbytes Pathname
41631744 41421266 <unknown>
# dtrace -n 'nfsv3:::op-read-start,nfsv3:::op-write-start {
@[probefunc,args[1]->noi_curpath] =count(); }'
dtrace: description 'nfsv3:::op-read-start,nfsv3:::op-write-start '
matched 2 probes
^C
rfs3_read <unknown> 867
rfs3_write <unknown> 3470
# dtrace -n 'fsinfo:::read,fsinfo:::write {
@[probefunc,args[0]->fi_pathname] =count(); }' dtrace: description
'fsinfo:::read,fsinfo:::write ' matched 2 probes
^C
fop_read /etc/default/nfs 2
fop_read /etc/resolv.conf 6
fop_read <unknown> 155
fop_write <unknown> 619
Any ideas why this happens, that's the <unknown>? Yes, the i/o are
detected but on which file?
Thanks,
Frederik
_______________________________________________
dtrace-discuss mailing list

--
- Kyle
O: +1.415.341.3430
F: +1.650.494.1676
275 Middlefield Road, Suite 50
Menlo Park, CA 94025
http://www.delphix.com

_______________________________________________
dtrace-discuss mailing list

[wessels]

Hi Brendan,

really looking forward to the book. Very thoughtful to cover
non-Solaris OS as well. As you suggested I browsed chapter 5 and tried
a couple of scripts. But nothing resolves my vmdk filenames. I tried
several providers syscall, fsinfo and nfsv3 and all give <unknown> as
filename when I do i/o on the disk. What puzzles me is that the
virtual machine lockfile filename is resolved. It appears that just
the vmdk files cannot be resolved. The very little amount of i/o
corresponds to the small cat and cp commands I used on the virtual
machine.
Why can't any provider each on a different layer revolve that filename?

Thanks,

Frederik

***@snv1# dtrace -n 'syscall::read:entry { @[fds[arg0].fi_pathname] =
count(); }'
dtrace: description 'syscall::read:entry ' matched 1 probe
^C

/devices/pseudo/***@0:ptm 2
/etc/resolv.conf 2
<unknown> 9

***@snv1# dtrace -n 'fsinfo:::read { @[args[0]->fi_pathname] = sum(arg1); }'
dtrace: description 'fsinfo:::read ' matched 1 probe
^C

/var/adm/wtmpx 4
/etc/resolv.conf 350
<unknown> 1447
/etc/default/nfs 3682
/etc/inet/services 5398

***@snv1# ./nfsv3fileio.dtrace
Tracing... Hit Ctrl-C to end.
^C

Rbytes Wbytes Pathname
0 168 /mpool/running_vm/vm-frontend/.lck-8b00000000000000
0 168
/mpool/running_vm/vm-installer46/.lck-2701000000000000
81920 1340 <unknown>

***@snv1# cat nfsv3fileio.dtrace

#!/usr/sbin/dtrace -s

#pragma D option quiet

dtrace:::BEGIN
{
trace("Tracing... Hit Ctrl-C to end.\n");
}

nfsv3:::op-read-done
{
@readbytes[args[1]->noi_curpath] = sum(args[2]->res_u.ok.data.data_len);
}

nfsv3:::op-write-done
{
@writebytes[args[1]->noi_curpath] = sum(args[2]->res_u.ok.count);
}

dtrace:::END
{
printf("\n%12s %12s %s\n", "Rbytes", "Wbytes", "Pathname");
printa("%@12d %@12d %s\n", @readbytes, @writebytes);
}

[wessels]

Hi Brendan,

really looking forward to the book. Very thoughtful to cover
non-Solaris OS as well. As you suggested I browsed chapter 5 and tried
a couple of scripts. But nothing resolves my vmdk filenames. I tried
several providers syscall, fsinfo and nfsv3 and all give <unknown> as
filename when I do i/o on the disk. What puzzles me is that the
virtual machine lockfile filename is resolved. It appears that just
the vmdk files cannot be resolved. The very little amount of i/o
corresponds to the small cat and cp commands I used on the virtual
machine.
Why can't any provider each on a different layer revolve that filename?

Thanks,

Frederik

***@snv1# dtrace -n 'syscall::read:entry { @[fds[arg0].fi_pathname] =
count(); }'
dtrace: description 'syscall::read:entry ' matched 1 probe
^C

/devices/pseudo/***@0:ptm 2
/etc/resolv.conf 2
<unknown> 9

***@snv1# dtrace -n 'fsinfo:::read { @[args[0]->fi_pathname] = sum(arg1); }'
dtrace: description 'fsinfo:::read ' matched 1 probe
^C

/var/adm/wtmpx 4
/etc/resolv.conf 350
<unknown> 1447
/etc/default/nfs 3682
/etc/inet/services 5398

***@snv1# ./nfsv3fileio.dtrace
Tracing... Hit Ctrl-C to end.
^C

Rbytes Wbytes Pathname
0 168 /mpool/running_vm/vm-frontend/.lck-8b00000000000000
0 168
/mpool/running_vm/vm-installer46/.lck-2701000000000000
81920 1340 <unknown>

***@snv1# cat nfsv3fileio.dtrace

#!/usr/sbin/dtrace -s

#pragma D option quiet

dtrace:::BEGIN
{
trace("Tracing... Hit Ctrl-C to end.\n");
}

nfsv3:::op-read-done
{
@readbytes[args[1]->noi_curpath] = sum(args[2]->res_u.ok.data.data_len);
}

nfsv3:::op-write-done
{
@writebytes[args[1]->noi_curpath] = sum(args[2]->res_u.ok.count);
}

dtrace:::END
{
printf("\n%12s %12s %s\n", "Rbytes", "Wbytes", "Pathname");
printa("%@12d %@12d %s\n", @readbytes, @writebytes);
}