Adding to the previous test, I also did a local UFS of the same 3G to
the iscsi ZFS volume. The dtrace didn't show anything, but this
completed the fastest of all, and so it sheds light that its the
NFS->ZFS->iSCSI interaction that is terrible, but ZFS->iSCSI is
fastest, with NFS->UFS/ZFS being second fastest.
On 5/4/06, Jeff A. Smith <Jeff.A.Smith at sun.com> wrote:
> Joe Little wrote:
> >
> > I will confess to not knowing how to measure latency. I haven't
> > observed the issue with UFS, but I haven't been trying much since UFS
> > doesn't interest me as much. That said, our UFS only Solaris 9/10
> > machines haven't had this issue.
> >
> Hi Joe,
>
> I've attached a very basic dtrace script to measure latency for
> all NFS3 server ops. Notice that this script measures the latency
> incurred both from NFS3 server processing and the underlying file
> system.
>
> Just run it as root on your server and crank up a NFS3 client. It
> will produce the following metrics:
>
> 1. op count
> 2. avg response time per op
> 3. avg system time consumed per op
> 4. quantized avg resp time
> 5. quantized avg system time
>
> I recommend running the same workload against a NFS mounted
> tmpfs (to set the utopian baseline), UFS, and ZFS. Then look
> for the large differences. That will give us an idea of which
> NFS3 procs are having perf issues, and we can dig deeper.
>
> I'm out of town Friday and Monday, but Spencer will cover for
> me if you run into any problems.
>
> Jeff
>
>
> #!/usr/sbin/dtrace -Fs
>
> fbt:nfssrv:common_dispatch:entry
> /args[0]->rq_vers == 3 && ! self->trace/
> {
> self->trace = 1;
> this->proc = args[0]->rq_proc;
> self->pname = (this->proc >= 0 && this->proc <= 21) ?
> stringof (nfssrv`rfscallnames_v3[this->proc]) :
> stringof ("invalid proc");
> self->time = timestamp;
> self->vtime = vtimestamp;
> @opcount[self->pname] = count();
> }
>
> fbt:nfssrv:common_dispatch:return
> /self->trace/
> {
> this->usec = (timestamp - self->time) / 1000;
> this->systm = (vtimestamp - self->vtime) / 1000;
> @avgtime[self->pname] = avg(this->usec);
> @qnttime[self->pname] = quantize(this->usec);
>
> @avgsystm[self->pname] = avg(this->systm);
> @qntsystm[self->pname] = quantize(this->systm);
>
> self->pname = 0;
> self->trace = 0;
> }
>
> END
> {
> printf("\n\nNFS3 op counts\n");
> printf( "==============\n");
> printa("%-20s %...@12d\n", @opcount);
>
> printf("\n\nNFS3 op avg response time (usec)\n");
> printf( "================================\n");
> printa("%-20s %...@12d\n", @avgtime);
>
> printf("\n\nNFS3 op avg system time (usec)\n");
> printf( "==============================\n");
> printa("%-20s %...@12d\n", @avgsystm);
>
> printf("\n\nNFS3 op quantized response time (usec)\n");
> printf( "======================================\n");
> printa("%-20s %...@12d\n", @qnttime);
>
> printf("\n\nNFS3 op quantized system time (usec)\n");
> printf( "====================================\n");
> printa("%-20s %...@12d\n", @qntsystm);
> }
>
>
>
