[RFC][PATCH 0/5] NFS: trace points added to mounting path

[RFC][PATCH 0/5] NFS: trace points added to mounting path

[Steve Dickson]

Hello,

Very recently patches were added to the mainline kernel that
enabled the use of trace points. This patch series takes
advantage of those patch by introducing trace points 
to the mounting path of NFS mounts. Its hoped these
trace points can be used by system administrators to
identify why NFS mounts are failing or hang in 
production kernels.

IMHO, one general problem with today's "canned" NFS debugging today is it 
becomes very verbose very quickly.... "I get here" and "I get there" type of 
debugging statements. Although they help trace the code but very rarely 
shows/defines what the actual problem was. So what I've try to do is 
"define the error paths" by putting a trace point at every error exit 
in hopes to define where and why things broke. 

So the ultimate goal would be to replace all the dprintks with trace points
but still be able to enable them through the rpcdebug command (although we
might want to think about splitting the command out into three different 
commands nfsdebug, nfsddebug, rpcdebug). Since trace points have very little
overhead, a set of trace points could be enable in production with have
little or no effect on functionality or performance.

Another advantage with trace points is the type and amount of
information that can be retrieved. With these trace points, I'm
passing in the error code as well as the data structure[s] associated
with that error. This allows the "canned" information that IT people
would used (via the rpcdebug command which would turn on a group of
trace points) as well as more detailed information that kernel developers 
can used (via systemtap scripts which would turn on individual trace
points).

Patch summary:
    * fs/nfs/client.c

    * fs/nfs/getroot.c

    * fs/nfs/super.c

      The based files where traces where added.

    * include/trace/nfs.h

    * kernel/trace/Makefile

    * kernel/trace/nfs-trace.c

      The overhead of added the trace points and then converting them
      into trace marks			.

    * samples/nfs/nfs_mount.stp

      The systemtap script used to access the trace marks. I probably
      should have documented the file better, but the first three
      functions in the file are how structures are pulled from the
      kernel. The rest are probes used to active the trace markers.


Comments... Acceptance?? 

steved.

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Chuck Lever]

On Jan 16, 2009, at Jan 16, 2009, 11:22 AM, Steve Dickson wrote:

> Hello,
>
> Very recently patches were added to the mainline kernel that
> enabled the use of trace points. This patch series takes
> advantage of those patch by introducing trace points
> to the mounting path of NFS mounts. Its hoped these
> trace points can be used by system administrators to
> identify why NFS mounts are failing or hang in
> production kernels.
>
>
> IMHO, one general problem with today's "canned" NFS debugging today  
> is it
> becomes very verbose very quickly.... "I get here" and "I get there"  
> type of
> debugging statements. Although they help trace the code but very  
> rarely
> shows/defines what the actual problem was. So what I've try to do is
> "define the error paths" by putting a trace point at every error exit
> in hopes to define where and why things broke.
>
> So the ultimate goal would be to replace all the dprintks with trace  
> points
> but still be able to enable them through the rpcdebug command  
> (although we
> might want to think about splitting the command out into three  
> different
> commands nfsdebug, nfsddebug, rpcdebug). Since trace points have  
> very little
> overhead, a set of trace points could be enable in production with  
> have
> little or no effect on functionality or performance.
>
> Another advantage with trace points is the type and amount of
> information that can be retrieved. With these trace points, I'm
> passing in the error code as well as the data structure[s] associated
> with that error. This allows the "canned" information that IT people
> would used (via the rpcdebug command which would turn on a group of
> trace points) as well as more detailed information that kernel  
> developers
> can used (via systemtap scripts which would turn on individual trace
> points).
>
> Patch summary:
>    * fs/nfs/client.c
>
>    * fs/nfs/getroot.c
>
>    * fs/nfs/super.c
>
>      The based files where traces where added.
>
>    * include/trace/nfs.h
>
>    * kernel/trace/Makefile
>
>    * kernel/trace/nfs-trace.c
>
>      The overhead of added the trace points and then converting them
>      into trace marks			.
>
>    * samples/nfs/nfs_mount.stp
>
>      The systemtap script used to access the trace marks. I probably
>      should have documented the file better, but the first three
>      functions in the file are how structures are pulled from the
>      kernel. The rest are probes used to active the trace markers.
>
>
> Comments... Acceptance??


I'm all for improving the observability of the NFS client.

But I don't (yet) see the advantage of adding this complexity in the  
mount path.  Maybe the more complex and asynchronous parts of the NFS  
client, like the cached read and write paths, are more suitable to  
this type of tool.

Why can't we simply improve the information content of the dprintks?   
Can you give a few real examples of problems that these new trace  
points can identify that better dprintks wouldn't be able to address?   
Generally, what kind of problems do admins face that the dprintks  
don't handle today, and what are the alternatives to addressing those  
issues?

Do admins who run enterprise kernels actually use SystemTap, or do  
they fall back on network traces and other tried and true  
troubleshooting methodologies?

If we think the mount path needs such instrumentation, consider  
updating fs/nfs/mount_clnt.c and net/sunrpc/rpcb_clnt.c as well.

-- 
Chuck Lever
chuck[dot]lever[at]oracle[dot]com

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Greg Banks]

Steve Dickson wrote:
> So the ultimate goal would be to replace all the dprintks with trace points
> but still be able to enable them through the rpcdebug command
I have a patch which changes the definition of the dprintk() macro (but
*not* dprintk() callsites) to allow enabling and disabling individual
dprintk() statements through a /proc/ interface.  Would you be
interested in that?

-- 
Greg Banks, P.Engineer, SGI Australian Software Group.
the brightly coloured sporks of revolution.
I don't speak for SGI.

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Christoph Hellwig]

On Fri, Jan 16, 2009 at 11:22:41AM -0500, Steve Dickson wrote:
> Comments... Acceptance?? 

Please add support to actually make use of these without a big pile of
out of tree crap.  

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Jeff Moyer]

Greg Banks <gnb@melbourne.sgi.com> writes:

> Steve Dickson wrote:
>> So the ultimate goal would be to replace all the dprintks with trace points
>> but still be able to enable them through the rpcdebug command
> I have a patch which changes the definition of the dprintk() macro (but
> *not* dprintk() callsites) to allow enabling and disabling individual
> dprintk() statements through a /proc/ interface.  Would you be
> interested in that?

That sounds like duplicated work.  How does it differ from Jason Baron's
dynamic printk patches (which I believe are now upstream)?

Cheers,
Jeff

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Jason Baron]

On Mon, Jan 19, 2009 at 09:27:30AM -0500, Jeff Moyer wrote:
> Greg Banks <gnb@melbourne.sgi.com> writes:
> 
> > Steve Dickson wrote:
> >> So the ultimate goal would be to replace all the dprintks with trace points
> >> but still be able to enable them through the rpcdebug command
> > I have a patch which changes the definition of the dprintk() macro (but
> > *not* dprintk() callsites) to allow enabling and disabling individual
> > dprintk() statements through a /proc/ interface.  Would you be
> > interested in that?
> 
> That sounds like duplicated work.  How does it differ from Jason Baron's
> dynamic printk patches (which I believe are now upstream)?
> 
> Cheers,
> Jeff

indeed. I've implemented a solution in a very similar problem space
which is now upstream, see:

http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commitdiff;h=346e15beb5343c2eb8216d820f2ed8f150822b08;hp=33376c1c043c05077b4ac79c33804266f6c45e49

One of the core fundamental differences that I see is that 'dprintk'
checks a global variable per dprintk line. Whereas, 'dynamic printk'
assigns each module a set of bits in a *single* global variable. The
idea was that if you have thousands of these debug lines throughout the
kernel, I wanted to have a small footprint.

The per-dprintk granularity could be implemented on top of the
per-module approach that i've taken. That is, each dprintk statement
could activate the module that its associated with when its activated.
Then, a further per-line variable could be checked.

We should probably move this discussion to lkml, since this probably
should involve a wider audience. Perhaps, you can re-post your patchset
there?

thanks,

-Jason

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Greg Banks]

Jason Baron wrote:
> On Mon, Jan 19, 2009 at 09:27:30AM -0500, Jeff Moyer wrote:
>   
>> Greg Banks <gnb@melbourne.sgi.com> writes:
>>
>>     
>>> Steve Dickson wrote:
>>>       
>>>> So the ultimate goal would be to replace all the dprintks with trace points
>>>> but still be able to enable them through the rpcdebug command
>>>>         
>>> I have a patch which changes the definition of the dprintk() macro (but
>>> *not* dprintk() callsites) to allow enabling and disabling individual
>>> dprintk() statements through a /proc/ interface.  Would you be
>>> interested in that?
>>>       
>> That sounds like duplicated work.  How does it differ from Jason Baron's
>> dynamic printk patches (which I believe are now upstream)?
>>
>> Cheers,
>> Jeff
>>     
>
> indeed. I've implemented a solution in a very similar problem space
> which is now upstream, see:
>
> http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commitdiff;h=346e15beb5343c2eb8216d820f2ed8f150822b08;hp=33376c1c043c05077b4ac79c33804266f6c45e49
>
>   
Meh, I've been spending too much time in insular SLES10 land.

> One of the core fundamental differences that I see is that 'dprintk'
> checks a global variable per dprintk line.
Yes, this is a key design feature.

The problem I was addressing was debugging NFS/RDMA.  That transport had
at the time no way to do any kind of network capture, and dprintks were
the *only* debugging mechanism.  So the code is absolutely riddled with
dprintks, some enormous and some in key performance paths.  This means
that enabling dprintks on a per-module basis would a) overflow the
dprintk buffer in a few milliseconds and b) perturb the time behaviour
of the code sufficiently to mask the problem you were trying to diagnose.

Later it became apparent that this would also be very useful for field
support folks.

>  Whereas, 'dynamic printk'
> assigns each module a set of bits in a *single* global variable. 
This seems to be more or less equivalent to the mechanism that
nfs/sunrpc use today, i.e. quite coarse grained.
> The
> idea was that if you have thousands of these debug lines throughout the
> kernel, I wanted to have a small footprint.
>   

Indeed.  For me,debuggability and supportability are far more important.
> The per-dprintk granularity could be implemented on top of the
> per-module approach that i've taken. That is, each dprintk statement
> could activate the module that its associated with when its activated.
> Then, a further per-line variable could be checked.
>   

Yes.  Or you could make the per-line variables the only state kept and
do the equivalent of

echo "module sunrpc +p" > /proc/dprintk

when the sysadmin does

echo "set enabled=1 <module_name>" > dynamic_printk/modules

i.e. run a query over the dprintk records and mark all the ones that
match the module.
> We should probably move this discussion to lkml, since this probably
> should involve a wider audience. Perhaps, you can re-post your patchset
> there?
>
>
>   
Ok, will do.

-- 
Greg Banks, P.Engineer, SGI Australian Software Group.
the brightly coloured sporks of revolution.
I don't speak for SGI.

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Greg Banks]

Frank Ch. Eigler wrote:
> Hi -
>
> On Mon, Jan 19, 2009 at 10:12:55AM +1100, Greg Banks wrote:
>   
>> [...]
>>     
>>> It would make more sense to me to turn dprintk's into trace_marks, 
>>>       
>> Umm, ok.  Sorry to be so ignorant but where would I find the doc that
>> tells me about adding trace marks ?
>>     
>
> Documentation/markers.txt
>   

Thanks.
>   
>> The control interface seems a little primitive.  It seems like you
>> can only activate and deactivate single printks ?
>>     
>
> Or single classes (identical names) per activate/deactivate call.
>
>   
The problem with this "classes" approach -- which sounds to my ignorant
ears like the "facilities" feature of nfs/sunrpc dprintks -- is
predicting which combination of classes to define so that they're useful
in the field years later with unknown bugs and unknown load patterns.  I
found that querying by function name was more useful in practice.
>
> [...]
> - it could generalize the handling of these dprintks, by not just
>   being tied to message printing, but becoming of possible use for
>   statistics/health monitoring
>   

That sounds potentially useful.  I was considering extending my dprintk
patch to add a flag to optionally bump a counter when the dprintk() line
is executed, but doing it via trace markers could be more useful if less
performant.

Let me do some reading on trace markers and get back to this.

-- 
Greg Banks, P.Engineer, SGI Australian Software Group.
the brightly coloured sporks of revolution.
I don't speak for SGI.

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[K.Prasad]

On Mon, Jan 19, 2009 at 09:27:30AM -0500, Jeff Moyer wrote:
> Greg Banks <gnb@melbourne.sgi.com> writes:
> 
> > Steve Dickson wrote:
> >> So the ultimate goal would be to replace all the dprintks with trace points
> >> but still be able to enable them through the rpcdebug command
> > I have a patch which changes the definition of the dprintk() macro (but
> > *not* dprintk() callsites) to allow enabling and disabling individual
> > dprintk() statements through a /proc/ interface.  Would you be
> > interested in that?
> 
> That sounds like duplicated work.  How does it differ from Jason Baron's
> dynamic printk patches (which I believe are now upstream)?
> 
> Cheers,
> Jeff

Introducing/converting one of the accepted methods of static
instrumentation - like tracepoints would help more users (whether
in-kernel or otherwise) harness them.

Steve,
	Would it help convert the systemtap script (nfs_mount.stp) in
Patch - 5 into a kernel module (perhaps in samples/ directory) to bring
an in-kernel user of these tracepoints?

Thanks,
K.Prasad

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Steve Dickson]

K.Prasad wrote:
> On Mon, Jan 19, 2009 at 09:27:30AM -0500, Jeff Moyer wrote:
>> Greg Banks <gnb@melbourne.sgi.com> writes:
>>
>>> Steve Dickson wrote:
>>>> So the ultimate goal would be to replace all the dprintks with trace points
>>>> but still be able to enable them through the rpcdebug command
>>> I have a patch which changes the definition of the dprintk() macro (but
>>> *not* dprintk() callsites) to allow enabling and disabling individual
>>> dprintk() statements through a /proc/ interface.  Would you be
>>> interested in that?
>> That sounds like duplicated work.  How does it differ from Jason Baron's
>> dynamic printk patches (which I believe are now upstream)?
>>
>> Cheers,
>> Jeff
> 
> Introducing/converting one of the accepted methods of static
> instrumentation - like tracepoints would help more users (whether
> in-kernel or otherwise) harness them.
> 
> Steve,
> 	Would it help convert the systemtap script (nfs_mount.stp) in
> Patch - 5 into a kernel module (perhaps in samples/ directory) to bring
> an in-kernel user of these tracepoints?
Well nfs_mount.stp was just an example of how to pull the information
from the kernel.. I just wanted to complete the loop... but as 
Christoph pointed out it probably shouldn't been included in the posting.

I'm not sure moving the nfs_mount.stp script into kernel 
would make sense. One of the advantages of trace point and system
scripts (depending on what is passed up) it allows users to define
exactly what they need to see.. 

For example, a kernel guy might be interested in a particular bit in a flag 
field which would be meaningless to an IT guy. On the other hand, the IT guy 
would be interested in the error code. One trace point could supply all the
information but different systemtap scripts would be need to show the 
desired information.

My point being, if we move things down into the kernel, I think we would
lose this type of flexibly...

steved.

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Arnaldo Carvalho de Melo]

Em Wed, Jan 21, 2009 at 11:39:56AM -0500, Steve Dickson escreveu:
> K.Prasad wrote:
> > On Mon, Jan 19, 2009 at 09:27:30AM -0500, Jeff Moyer wrote:
> >> Greg Banks <gnb@melbourne.sgi.com> writes:
> >>
> >>> Steve Dickson wrote:
> >>>> So the ultimate goal would be to replace all the dprintks with trace points
> >>>> but still be able to enable them through the rpcdebug command
> >>> I have a patch which changes the definition of the dprintk() macro (but
> >>> *not* dprintk() callsites) to allow enabling and disabling individual
> >>> dprintk() statements through a /proc/ interface.  Would you be
> >>> interested in that?
> >> That sounds like duplicated work.  How does it differ from Jason Baron's
> >> dynamic printk patches (which I believe are now upstream)?
> >>
> >> Cheers,
> >> Jeff
> > 
> > Introducing/converting one of the accepted methods of static
> > instrumentation - like tracepoints would help more users (whether
> > in-kernel or otherwise) harness them.
> > 
> > Steve,
> > 	Would it help convert the systemtap script (nfs_mount.stp) in
> > Patch - 5 into a kernel module (perhaps in samples/ directory) to bring
> > an in-kernel user of these tracepoints?
> Well nfs_mount.stp was just an example of how to pull the information
> from the kernel.. I just wanted to complete the loop... but as 
> Christoph pointed out it probably shouldn't been included in the posting.
> 
> I'm not sure moving the nfs_mount.stp script into kernel 
> would make sense. One of the advantages of trace point and system
> scripts (depending on what is passed up) it allows users to define
> exactly what they need to see.. 
> 
> For example, a kernel guy might be interested in a particular bit in a flag 
> field which would be meaningless to an IT guy. On the other hand, the IT guy 
> would be interested in the error code. One trace point could supply all the
> information but different systemtap scripts would be need to show the 
> desired information.
> 
> My point being, if we move things down into the kernel, I think we would
> lose this type of flexibly...

I suggest you provide an ftrace plugin, just like I'm doing with
blktrace, see:

http://lkml.org/lkml/2009/1/20/190

- Arnaldo

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Steve Dickson]

Sorry for the delayed response... That darn flux capacitor broke again! ;-)
 

Chuck Lever wrote:
> 
> I'm all for improving the observability of the NFS client.
Well, in theory, trace points will also touch the server and all
of the rpc code... 

> 
> But I don't (yet) see the advantage of adding this complexity in the
> mount path.  Maybe the more complex and asynchronous parts of the NFS
> client, like the cached read and write paths, are more suitable to this
> type of tool.
Well the complexity is, at this point, due to how the trace points
are tied to and used by the systemtap. I'm hopeful this complexity 
will die down as time goes on... 

> 
> Why can't we simply improve the information content of the dprintks?
The theory is trace point can be turned on, in production kernels, with
little or no performance issues... 

> Can you give a few real examples of problems that these new trace points
> can identify that better dprintks wouldn't be able to address?
They can supply more information that can be used by both a kernel
guy and an IT guy.... Meaning they can supply detailed structure information
that a kernel guy would need as well as supplying the simple error code 
that an IT guy would be interested.

> Generally, what kind of problems do admins face that the dprintks don't
> handle today, and what are the alternatives to addressing those issues?
Not being an admin guy, I really don't have an answer for this... but 
I can say since trace point are not so much of a drag on the system as
printks are.. with in timing issues using trace point would be a big advantage
over printks

> 
> Do admins who run enterprise kernels actually use SystemTap, or do they
> fall back on network traces and other tried and true troubleshooting
> methodologies?
Currently to run systemtap, one need kernel debug info and kernel developer
info installed on the system. Most productions system don't install those types
of packages.... But with trace points those type of packages will no longer be 
needed, so I could definitely see admins using systemtap once its available... 
Look at Dtrace... people are using that now that its available and fairly stable. 
 
> 
> If we think the mount path needs such instrumentation, consider updating
> fs/nfs/mount_clnt.c and net/sunrpc/rpcb_clnt.c as well.
> 
I was just following what what was currently being debug when
'rpcinfo -m nfs -s mount' was set... maybe I missed something...
I'll take a look...

steved.

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Chuck Lever]

Hey Steve-

On Jan 21, 2009, at Jan 21, 2009, 12:13 PM, Steve Dickson wrote:
> Sorry for the delayed response... That darn flux capacitor broke  
> again! ;-)
>
>
> Chuck Lever wrote:
>>
>> I'm all for improving the observability of the NFS client.
> Well, in theory, trace points will also touch the server and all
> of the rpc code...
>
>>
>> But I don't (yet) see the advantage of adding this complexity in the
>> mount path.  Maybe the more complex and asynchronous parts of the NFS
>> client, like the cached read and write paths, are more suitable to  
>> this
>> type of tool.
> Well the complexity is, at this point, due to how the trace points
> are tied to and used by the systemtap. I'm hopeful this complexity
> will die down as time goes on...

I understand that your proposed mount path changes were attempting to  
provide a simple example of using trace points that could be applied  
to the NFS client and server in general.

However I'm interested mostly in improving how the mount path in  
specific reports problems.  I'm not convinced that trace points (or  
our current dprintk, for that matter) is a useful approach to solving  
NFS mount issues, in specific.

But that introduces the general question of whether trace points,  
dprintk, network tracing, or something else is the most appropriate  
tool to address the most common troubleshooting problems in any  
particular area of the NFS client or server.  I'd also like some  
clarity on what our problem statement is here.  What problems are we  
trying to address?

>> Why can't we simply improve the information content of the dprintks?
> The theory is trace point can be turned on, in production kernels,  
> with
> little or no performance issues...

mount isn't a performance path, which is one reason I think trace  
points might be overkill for this case.

>> Can you give a few real examples of problems that these new trace  
>> points
>> can identify that better dprintks wouldn't be able to address?
> They can supply more information that can be used by both a kernel
> guy and an IT guy.... Meaning they can supply detailed structure  
> information
> that a kernel guy would need as well as supplying the simple error  
> code
> that an IT guy would be interested.

My point is, does that flexibility really help some poor admin who is  
trying to diagnose a mount problem?  Is it going to reduce the number  
of calls to your support desk?

I'd like to see an example of a real mount problem or two that dprintk  
isn't adequate for, but a trace point could have helped.  In other  
words, can we get some use cases for dprintk and trace points for  
mount problems in specific?  I think that would help us understand the  
trade-offs a little better.

Some general use cases for trace points might also widen our dialog  
about where they are appropriate to use.  I'm not at all arguing  
against using trace points in general, but I would like to see some  
thinking about whether they are the most appropriate tool for each of  
the many troubleshooting jobs we have.

>> Generally, what kind of problems do admins face that the dprintks  
>> don't
>> handle today, and what are the alternatives to addressing those  
>> issues?
> Not being an admin guy, I really don't have an answer for this... but
> I can say since trace point are not so much of a drag on the system as
> printks are.. with in timing issues using trace point would be a big  
> advantage
> over printks

I like the idea of not depending on the system log, and that's  
appropriate for performance hot paths and asynchronous paths where  
timing can be an issue.  That's one reason why I created the NFS and  
RPC performance metrics facility.

But mount is not a performance path, and is synchronous, more or  
less.  In addition, mount encounters problems much more frequently  
than the read or write path, because mount depends a lot on what  
options are selected and the network environment its running in.  It's  
the first thing to try contacting the server, as well, so it "shakes  
out" a lot of problems before a read or write is even done.

So something like dprintk or trace points or a network trace that have  
some set up overhead might be less appropriate for mount than, say,  
beefing up the error reporting framework in the mount path, just as an  
example.

>> Do admins who run enterprise kernels actually use SystemTap, or do  
>> they
>> fall back on network traces and other tried and true troubleshooting
>> methodologies?
> Currently to run systemtap, one need kernel debug info and kernel  
> developer
> info installed on the system. Most productions system don't install  
> those types
> of packages.... But with trace points those type of packages will no  
> longer be
> needed, so I could definitely see admins using systemtap once its  
> available...
> Look at Dtrace... people are using that now that its available and  
> fairly stable.
>
>> If we think the mount path needs such instrumentation, consider  
>> updating
>> fs/nfs/mount_clnt.c and net/sunrpc/rpcb_clnt.c as well.
>>
> I was just following what what was currently being debug when
> 'rpcinfo -m nfs -s mount' was set...

`rpcdebug -m nfs -s mount` also enables the dprintks in fs/nfs/ 
mount_clnt.c, at least.  As with most dprintk infrastructure in NFS,  
it's really aimed at developers and not end users or admins.  The  
rpcbind client is also an integral part of the mount process, so I  
suggested that too.

-- 
Chuck Lever
chuck[dot]lever[at]oracle[dot]com

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Trond Myklebust]

On Wed, 2009-01-21 at 13:01 -0500, Chuck Lever wrote:
> `rpcdebug -m nfs -s mount` also enables the dprintks in fs/nfs/ 
> mount_clnt.c, at least.  As with most dprintk infrastructure in NFS,  
> it's really aimed at developers and not end users or admins.  The  
> rpcbind client is also an integral part of the mount process, so I  
> suggested that too.

This would be my main gripe with suggestions that we convert all the
existing dprintks. As Chuck says, they are pretty much a hodgepodge of
messages designed to help kernel developers to debug the NFS and RPC
code.

If you want something dtrace-like to allow administrators to run scripts
to monitor the health of their cluster and troubleshoot performance
problems, then you really want to start afresh. That really needs to be
designed as a long-term API, and should ideally represent the desired
functionality in a manner that is more or less independent of the
underlying code (something that is clearly not the case for the current
mess of dprintks). Otherwise, scripts will have to be rewritten every
time we make some minor tweak or change to the code (i.e. for every
kernel release).

Cheers
  Trond

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Steve Dickson]

Chuck Lever wrote:
> Hey Steve-
> 
> On Jan 21, 2009, at Jan 21, 2009, 12:13 PM, Steve Dickson wrote:
>> Sorry for the delayed response... That darn flux capacitor broke
>> again! ;-)
>>
>>
>> Chuck Lever wrote:
>>>
>>> I'm all for improving the observability of the NFS client.
>> Well, in theory, trace points will also touch the server and all
>> of the rpc code...
>>
>>>
>>> But I don't (yet) see the advantage of adding this complexity in the
>>> mount path.  Maybe the more complex and asynchronous parts of the NFS
>>> client, like the cached read and write paths, are more suitable to this
>>> type of tool.
>> Well the complexity is, at this point, due to how the trace points
>> are tied to and used by the systemtap. I'm hopeful this complexity
>> will die down as time goes on...
> 
> I understand that your proposed mount path changes were attempting to
> provide a simple example of using trace points that could be applied to
> the NFS client and server in general.
Very true... Its definitely just a template... If/when we agree to a 
format of the template, I would like to simple clone it through the
rest of the code.

> However I'm interested mostly in improving how the mount path in
> specific reports problems.  I'm not convinced that trace points (or our
> current dprintk, for that matter) is a useful approach to solving NFS
> mount issues, in specific.
> 
> But that introduces the general question of whether trace points,
> dprintk, network tracing, or something else is the most appropriate tool
> to address the most common troubleshooting problems in any particular
> area of the NFS client or server.  I'd also like some clarity on what
> our problem statement is here.  What problems are we trying to address?
The problem I'm trying to address is allowing admins to debug (or decipher)
NFS problems on production system in a very non-intrusive way. Meaning
having no ill effects on performance or stability when the trace points
are enabled. 

> 
>>> Why can't we simply improve the information content of the dprintks?
>> The theory is trace point can be turned on, in production kernels, with
>> little or no performance issues...
> 
> mount isn't a performance path, which is one reason I think trace points
> might be overkill for this case.
Maybe so, but again, it was one of the easier paths to convert. Would it 
be more palatable if I converted the I/O paths?

> 
>>> Can you give a few real examples of problems that these new trace points
>>> can identify that better dprintks wouldn't be able to address?
>> They can supply more information that can be used by both a kernel
>> guy and an IT guy.... Meaning they can supply detailed structure
>> information
>> that a kernel guy would need as well as supplying the simple error code
>> that an IT guy would be interested.
> 
> My point is, does that flexibility really help some poor admin who is
> trying to diagnose a mount problem?  Is it going to reduce the number of
> calls to your support desk?
I think so... Once the admin either learn what is available and how
to use them they will be able better more concise bug reports. So maybe
there may not a decrease in calls but each caller (potentially) will
supply the support desk with better information.
  
> 
> I'd like to see an example of a real mount problem or two that dprintk
> isn't adequate for, but a trace point could have helped.  In other
> words, can we get some use cases for dprintk and trace points for mount
> problems in specific?  I think that would help us understand the
> trade-offs a little better.
In the mount path that might be a bit difficult... but with trace
points you would be able to look at the entire super block or entire 
server and client structures something you can't static/canned 
printks... 
 
> 
> Some general use cases for trace points might also widen our dialog
> about where they are appropriate to use.  I'm not at all arguing against
> using trace points in general, but I would like to see some thinking
> about whether they are the most appropriate tool for each of the many
> troubleshooting jobs we have.
I/O paths jumps into my head... since trace points much less of a performance
killer than printks, the I/O path might be an appropriate use...

> 
>>> Generally, what kind of problems do admins face that the dprintks don't
>>> handle today, and what are the alternatives to addressing those issues?
>> Not being an admin guy, I really don't have an answer for this... but
>> I can say since trace point are not so much of a drag on the system as
>> printks are.. with in timing issues using trace point would be a big
>> advantage
>> over printks
> 
> I like the idea of not depending on the system log, and that's
> appropriate for performance hot paths and asynchronous paths where
> timing can be an issue.  That's one reason why I created the NFS and RPC
> performance metrics facility.
Which is total being underutilized... IMHO... I can see a combination of
using both.... Using the metrics to identify a problem and the using
trace point to solve the problem...
 
> 
> But mount is not a performance path, and is synchronous, more or less. 
> In addition, mount encounters problems much more frequently than the
> read or write path, because mount depends a lot on what options are
> selected and the network environment its running in.  It's the first
> thing to try contacting the server, as well, so it "shakes out" a lot of
> problems before a read or write is even done.
> 
> So something like dprintk or trace points or a network trace that have
> some set up overhead might be less appropriate for mount than, say,
> beefing up the error reporting framework in the mount path, just as an
> example.
Trace points by far have much much less overhead than printks... thats
one of their major advantages... 

> 
>>> Do admins who run enterprise kernels actually use SystemTap, or do they
>>> fall back on network traces and other tried and true troubleshooting
>>> methodologies?
>> Currently to run systemtap, one need kernel debug info and kernel
>> developer
>> info installed on the system. Most productions system don't install
>> those types
>> of packages.... But with trace points those type of packages will no
>> longer be
>> needed, so I could definitely see admins using systemtap once its
>> available...
>> Look at Dtrace... people are using that now that its available and
>> fairly stable.
>>
>>> If we think the mount path needs such instrumentation, consider updating
>>> fs/nfs/mount_clnt.c and net/sunrpc/rpcb_clnt.c as well.
>>>
>> I was just following what what was currently being debug when
>> 'rpcinfo -m nfs -s mount' was set...
> 
> `rpcdebug -m nfs -s mount` also enables the dprintks in
> fs/nfs/mount_clnt.c, at least.  As with most dprintk infrastructure in
> NFS, it's really aimed at developers and not end users or admins.  The
> rpcbind client is also an integral part of the mount process, so I
> suggested that too.
> 
ACK...

steved.

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Steve Dickson]

Hey,

Trond Myklebust wrote:
> On Wed, 2009-01-21 at 13:01 -0500, Chuck Lever wrote:
>> `rpcdebug -m nfs -s mount` also enables the dprintks in fs/nfs/ 
>> mount_clnt.c, at least.  As with most dprintk infrastructure in NFS,  
>> it's really aimed at developers and not end users or admins.  The  
>> rpcbind client is also an integral part of the mount process, so I  
>> suggested that too.
> 
> This would be my main gripe with suggestions that we convert all the
> existing dprintks. As Chuck says, they are pretty much a hodgepodge of
> messages designed to help kernel developers to debug the NFS and RPC
> code.
Well as I see it, this is our chance to clean it up... 

> 
> If you want something dtrace-like to allow administrators to run scripts
> to monitor the health of their cluster and troubleshoot performance
> problems, then you really want to start afresh. That really needs to be
> designed as a long-term API, and should ideally represent the desired
> functionality in a manner that is more or less independent of the
> underlying code (something that is clearly not the case for the current
> mess of dprintks). 
I'm not sure how the trace points could independent of the underlying code,
but I do agree a well designed API would be optimal.... But before we go
off designing something I think we need to decide with the end game is.

Do we want to trace points:
    1) at all 
    2) for debugging 
    3) for performance
    4) 2 and 3

Once we get the above nailed down then we can decide how to go...

Also, Greg and Jason Baron (from Red Hat) are off working on 
improving the dprintk() that are currently exist... I would
suspect we would want to also tie in with that to see if
it would be applicable...


> Otherwise, scripts will have to be rewritten every
> time we make some minor tweak or change to the code (i.e. for every
> kernel release).
No matter how well we design this, I'm sure there will always be
a need for tweaks in the user level scripts... but we call always
leave that up to the nfs-utils maintainer....  (Doh!) 8-)

steved.

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Steve Dickson]

Arnaldo Carvalho de Melo wrote:
> Em Wed, Jan 21, 2009 at 11:39:56AM -0500, Steve Dickson escreveu:
>> K.Prasad wrote:
>>> On Mon, Jan 19, 2009 at 09:27:30AM -0500, Jeff Moyer wrote:
>>>> Greg Banks <gnb@melbourne.sgi.com> writes:
>>>>
>>>>> Steve Dickson wrote:
>>>>>> So the ultimate goal would be to replace all the dprintks with trace points
>>>>>> but still be able to enable them through the rpcdebug command
>>>>> I have a patch which changes the definition of the dprintk() macro (but
>>>>> *not* dprintk() callsites) to allow enabling and disabling individual
>>>>> dprintk() statements through a /proc/ interface.  Would you be
>>>>> interested in that?
>>>> That sounds like duplicated work.  How does it differ from Jason Baron's
>>>> dynamic printk patches (which I believe are now upstream)?
>>>>
>>>> Cheers,
>>>> Jeff
>>> Introducing/converting one of the accepted methods of static
>>> instrumentation - like tracepoints would help more users (whether
>>> in-kernel or otherwise) harness them.
>>>
>>> Steve,
>>> 	Would it help convert the systemtap script (nfs_mount.stp) in
>>> Patch - 5 into a kernel module (perhaps in samples/ directory) to bring
>>> an in-kernel user of these tracepoints?
>> Well nfs_mount.stp was just an example of how to pull the information
>> from the kernel.. I just wanted to complete the loop... but as 
>> Christoph pointed out it probably shouldn't been included in the posting.
>>
>> I'm not sure moving the nfs_mount.stp script into kernel 
>> would make sense. One of the advantages of trace point and system
>> scripts (depending on what is passed up) it allows users to define
>> exactly what they need to see.. 
>>
>> For example, a kernel guy might be interested in a particular bit in a flag 
>> field which would be meaningless to an IT guy. On the other hand, the IT guy 
>> would be interested in the error code. One trace point could supply all the
>> information but different systemtap scripts would be need to show the 
>> desired information.
>>
>> My point being, if we move things down into the kernel, I think we would
>> lose this type of flexibly...
> 
> I suggest you provide an ftrace plugin, just like I'm doing with
> blktrace, see:
> 
> http://lkml.org/lkml/2009/1/20/190
I agree its something I need to look into...

steved.

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Chuck Lever]

On Jan 21, 2009, at Jan 21, 2009, 2:37 PM, Steve Dickson wrote:
> Chuck Lever wrote:
>> Hey Steve-
>>
>> I'd like to see an example of a real mount problem or two that  
>> dprintk
>> isn't adequate for, but a trace point could have helped.  In other
>> words, can we get some use cases for dprintk and trace points for  
>> mount
>> problems in specific?  I think that would help us understand the
>> trade-offs a little better.
> In the mount path that might be a bit difficult... but with trace
> points you would be able to look at the entire super block or entire
> server and client structures something you can't static/canned
> printks...

I've never ever seen an NFS mount problem that required an admin to  
provide information from a superblock.  That seems like a lot of  
implementation detail that would be meaningless to admins and support  
desk folks.

This is why I think we need to have some real world customer examples  
of mount problems (or read performance problems, or whatever) that we  
want to be able to diagnose in enterprise distributions.  I'm not  
saying this to throw up a road block... I think we really need to  
understand the problem before designing the solution, and so let's  
start with some practical examples.

Again, I'm not saying trace points are bad or wrong, just that they  
may not be appropriate for a particular code path and the type of  
problems that arise during specific NFS operations.  I'm not  
criticizing your particular sample code.  I'm asking "Before we add  
trace points everywhere, are trace points strategically the right  
debugging tool in every case?"

Basically we have to know well in advance what kind of information  
will be needed at each trace point.  Who can predict?  If you have to  
solder in trace points in advance, in some ways that doesn't seem any  
more flexible than a dprintk.  What you've demonstrated is another  
good general tool for debugging, but you haven't convinced me that  
this is the right tool for, say, the mount path, or ACL support, and  
so on.

>> But mount is not a performance path, and is synchronous, more or  
>> less.
>> In addition, mount encounters problems much more frequently than the
>> read or write path, because mount depends a lot on what options are
>> selected and the network environment its running in.  It's the first
>> thing to try contacting the server, as well, so it "shakes out" a  
>> lot of
>> problems before a read or write is even done.
>>
>> So something like dprintk or trace points or a network trace that  
>> have
>> some set up overhead might be less appropriate for mount than, say,
>> beefing up the error reporting framework in the mount path, just as  
>> an
>> example.
> Trace points by far have much much less overhead than printks... thats
> one of their major advantages...

Yeah, but that doesn't matter in some cases, like mount, or  
asynchronous file deletes, or .... so we have to look at some of the  
other issues with using them when deciding if they are the right tool  
for the job.

I think we need to visit this issue on a case-by-case basis.   
Sometimes dprintk is appropriate.  Sometimes printk(KERN_ERR).   
Sometimes a performance metric.  Having specific troubleshooting in  
mind when we design this is critical, otherwise we are going to add a  
lot of kruft for no real benefit.

That's an advantage of something like SystemTap.  You can specify  
whatever is needed for a specific problem, and you don't need to  
recompile the kernel to do it.  Enterprise distributions can provide  
specific scripts for their code base, which doesn't change much.   
Upstream is free to make whatever drastic modifications to the code  
base without worrying about breaking a kernel-user space API.

Trond has always maintained that dprintk() is best for developers, but  
probably inappropriate for field debugging, and I think that may also  
apply to trace points.  So I'm not against adding trace points where  
appropriate, but I'm doubtful that they will be helpful outside of  
kernel development; ie I wonder if they will specifically help  
customers of enterprise distributions.

-- 
Chuck Lever
chuck[dot]lever[at]oracle[dot]com

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Trond Myklebust]

On Wed, 2009-01-21 at 14:58 -0500, Steve Dickson wrote:
> Do we want to trace points:
>     1) at all 
>     2) for debugging 
>     3) for performance
>     4) 2 and 3
> 
> Once we get the above nailed down then we can decide how to go...

I think it might be a good idea to flesh out a bit what you mean by
"debugging" here. Since you mentioned it in conjunction with the two
words "administrators" and "scripts", I assume that you are not talking
about kernel code debugging?

Cheers
  Trond

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Christoph Hellwig]

On Wed, Jan 21, 2009 at 03:04:01PM -0200, Arnaldo Carvalho de Melo wrote:
> I suggest you provide an ftrace plugin, just like I'm doing with
> blktrace, see:

*nod*

ftrace for now, long-term we also want some ltt integration (hopefully
we'll have some form of a generic shim so that one data source can
provide trace information for both ftrace and ltt)

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Greg Banks]

Chuck Lever wrote:
>>> Why can't we simply improve the information content of the dprintks?
>>>       
>> The theory is trace point can be turned on, in production kernels,  
>> with
>> little or no performance issues...
>>     
>
> mount isn't a performance path, 
Perhaps not on the client, but when you have >6000 clients mounting
simultaneously then mount is most definitely a performance path on the
server :-)

> which is one reason I think trace  
> points might be overkill for this case.
>   

I think both dprintks and trace points are the wrong approach for
client-side mount problems.  What you really want there is good and
useful diagnostic information going unconditionally via printk().  Mount
problems happen frequently enough, and are often not the client's fault
but the server's or a firewall's, that system admins need to be able to
work out what went wrong in retrospect by looking in syslog.

But just because Steve chose an unfortunate example doesn't invalidate
his point.  There are plenty of gnarly logic paths in the NFS client and
server which need better runtime diagnostics.  On the server,  anything
involving an upcall to userspace .  On the client, silly rename or
attribute caching.
>
>> Not being an admin guy, I really don't have an answer for this... but
>> I can say since trace point are not so much of a drag on the system as
>> printks are.. with in timing issues using trace point would be a big  
>> advantage
>> over printks
>>     
>
>   
Well that argument works both ways.  Several times now I've seen
problems where a significant part of the debugging process has involved
noticing correlations between timing of dprintks and syslog messages
from other subsystems, like IPoIB or TCP.  That's harder to do if the
debug statements and printks go through separate mechanisms to userspace.

-- 
Greg Banks, P.Engineer, SGI Australian Software Group.
the brightly coloured sporks of revolution.
I don't speak for SGI.

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Greg Banks]

Chuck Lever wrote:
>
>
> I think we need to visit this issue on a case-by-case basis.   
> Sometimes dprintk is appropriate.  Sometimes printk(KERN_ERR).   
> Sometimes a performance metric.
Well said.

> Trond has always maintained that dprintk() is best for developers, but  
> probably inappropriate for field debugging,
It's not a perfect tool but it beats nothing at all.
>  and I think that may also  
> apply to trace points.  
It depends on whether distros can be convinced to enable it by default,
and install by default any necessary userspace infrastructure.   The
most important thing for field debugging is Just Knowing that you have
all the bits necessary to perform useful debugging without having to
find some RPM that matches the kernel that the machine is actually
running now, and not the one that was present when the machine was
installed.

-- 
Greg Banks, P.Engineer, SGI Australian Software Group.
the brightly coloured sporks of revolution.
I don't speak for SGI.

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Arnaldo Carvalho de Melo]

Em Thu, Jan 22, 2009 at 09:36:53AM +1100, Greg Banks escreveu:
> Chuck Lever wrote:
> >
> >
> > I think we need to visit this issue on a case-by-case basis.   
> > Sometimes dprintk is appropriate.  Sometimes printk(KERN_ERR).   
> > Sometimes a performance metric.
> Well said.
> 
> > Trond has always maintained that dprintk() is best for developers, but  
> > probably inappropriate for field debugging,
> It's not a perfect tool but it beats nothing at all.
> >  and I think that may also  
> > apply to trace points.  
> It depends on whether distros can be convinced to enable it by default,
> and install by default any necessary userspace infrastructure.   The
> most important thing for field debugging is Just Knowing that you have
> all the bits necessary to perform useful debugging without having to
> find some RPM that matches the kernel that the machine is actually
> running now, and not the one that was present when the machine was
> installed.

Exactly, that is why an ftrace plugin, that only when selected using
echo "nfs" > /debug/tracing/current_tracer will activate the tracepoints
and provide output via /debug/tracing/trace or /deb/tracing/trace_pipe,
possibly combined with other ftrace plugins such as the stacktrace,
blktrace, etc.

I.e. no need at all for any matching userspace tool, near zero impact
when not activated, useful, if done right, for both developers and for
admins.

Again, an example can be found in the blktrace ftrace plugin[1], that
instead of adding a requirement will eventually drop an existing, well
established one (blktrace(8)).

- Arnaldo

[1] http://lkml.org/lkml/2009/1/20/190

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Trond Myklebust]

On Thu, 2009-01-22 at 09:36 +1100, Greg Banks wrote:
> Chuck Lever wrote:
> >
> >
> > I think we need to visit this issue on a case-by-case basis.   
> > Sometimes dprintk is appropriate.  Sometimes printk(KERN_ERR).   
> > Sometimes a performance metric.
> Well said.
> 
> > Trond has always maintained that dprintk() is best for developers, but  
> > probably inappropriate for field debugging,
> It's not a perfect tool but it beats nothing at all.
> >  and I think that may also  
> > apply to trace points.  
> It depends on whether distros can be convinced to enable it by default,
> and install by default any necessary userspace infrastructure.   The
> most important thing for field debugging is Just Knowing that you have
> all the bits necessary to perform useful debugging without having to
> find some RPM that matches the kernel that the machine is actually
> running now, and not the one that was present when the machine was
> installed.

Which is precisely why dprintk() is such a bad choice as a basis for a
set of trace points: every new patch and bugfix that the distro applies
will result in a reshuffling of the trace points as code is cleaned up
and moved around or removed entirely.

Cheers
  Trond

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[J. Bruce Fields]

On Thu, Jan 22, 2009 at 09:36:53AM +1100, Greg Banks wrote:
> Chuck Lever wrote:
> >
> >
> > I think we need to visit this issue on a case-by-case basis.   
> > Sometimes dprintk is appropriate.  Sometimes printk(KERN_ERR).   
> > Sometimes a performance metric.
> Well said.
> 
> > Trond has always maintained that dprintk() is best for developers, but  
> > probably inappropriate for field debugging,
> It's not a perfect tool but it beats nothing at all.
> >  and I think that may also  
> > apply to trace points.  
> It depends on whether distros can be convinced to enable it by default,
> and install by default any necessary userspace infrastructure.   The
> most important thing for field debugging is Just Knowing that you have
> all the bits necessary to perform useful debugging without having to
> find some RPM that matches the kernel that the machine is actually
> running now, and not the one that was present when the machine was
> installed.

On the mount case specifically: How far are we from the idea of a mount
program that can identify most problems itself?  I know its error
reporting has gotten better....

I suppose the main feedback mount gets right now is an error code from
the mount system call, and that may be too narrow an interface to cover
most problems.  Is there some way we can give mount a real interface it
can use to find out this stuff instead of just dumping more strings into
the logs?

My main obstacle to judging a solution is that I don't have in mind a
good list of (say) the top 10 problems that can cause the first mount to
fail.  Hm:

	- dns lookup of the server fails
	- server isn't reachable
	- server isn't running nfs
	- requested path isn't known to server or isn't exported
	- export is there, but requires more security
	- user doesn't have gss credentials
	- file permissions on the export are wrong
	...

--b.

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Trond Myklebust]

On Wed, 2009-01-21 at 20:47 -0200, Arnaldo Carvalho de Melo wrote:
> Em Thu, Jan 22, 2009 at 09:36:53AM +1100, Greg Banks escreveu:
> > Chuck Lever wrote:
> > >
> > >
> > > I think we need to visit this issue on a case-by-case basis.   
> > > Sometimes dprintk is appropriate.  Sometimes printk(KERN_ERR).   
> > > Sometimes a performance metric.
> > Well said.
> > 
> > > Trond has always maintained that dprintk() is best for developers, but  
> > > probably inappropriate for field debugging,
> > It's not a perfect tool but it beats nothing at all.
> > >  and I think that may also  
> > > apply to trace points.  
> > It depends on whether distros can be convinced to enable it by default,
> > and install by default any necessary userspace infrastructure.   The
> > most important thing for field debugging is Just Knowing that you have
> > all the bits necessary to perform useful debugging without having to
> > find some RPM that matches the kernel that the machine is actually
> > running now, and not the one that was present when the machine was
> > installed.
> 
> Exactly, that is why an ftrace plugin, that only when selected using
> echo "nfs" > /debug/tracing/current_tracer will activate the tracepoints
> and provide output via /debug/tracing/trace or /deb/tracing/trace_pipe,
> possibly combined with other ftrace plugins such as the stacktrace,
> blktrace, etc.
> 
> I.e. no need at all for any matching userspace tool, near zero impact
> when not activated, useful, if done right, for both developers and for
> admins.
> 
> Again, an example can be found in the blktrace ftrace plugin[1], that
> instead of adding a requirement will eventually drop an existing, well
> established one (blktrace(8)).

I must be missing something. Exactly what functionality does this then
give us that we don't have already with the existing RPC/NFS dprintk()
scheme?

Trond

RE: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Muntz, Daniel]

My favorite: when you try a Kerberos mount and one of the kernel modules
requried for this isn't loaded, mount gets ENOMEM and says "out of
memory"

  -Dan

-----Original Message-----
From: J. Bruce Fields [mailto:bfields@fieldses.org] 
Sent: Wednesday, January 21, 2009 2:56 PM
To: Greg Banks
Cc: Chuck Lever; Linux NFS Mailing list; Linux NFSv4 mailing list;
SystemTAP
Subject: Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

On Thu, Jan 22, 2009 at 09:36:53AM +1100, Greg Banks wrote:
> Chuck Lever wrote:
> >
> >
> > I think we need to visit this issue on a case-by-case basis.   
> > Sometimes dprintk is appropriate.  Sometimes printk(KERN_ERR).   
> > Sometimes a performance metric.
> Well said.
> 
> > Trond has always maintained that dprintk() is best for developers, 
> > but probably inappropriate for field debugging,
> It's not a perfect tool but it beats nothing at all.
> >  and I think that may also
> > apply to trace points.  
> It depends on whether distros can be convinced to enable it by
default,
> and install by default any necessary userspace infrastructure.   The
> most important thing for field debugging is Just Knowing that you have

> all the bits necessary to perform useful debugging without having to 
> find some RPM that matches the kernel that the machine is actually 
> running now, and not the one that was present when the machine was 
> installed.

On the mount case specifically: How far are we from the idea of a mount
program that can identify most problems itself?  I know its error
reporting has gotten better....

I suppose the main feedback mount gets right now is an error code from
the mount system call, and that may be too narrow an interface to cover
most problems.  Is there some way we can give mount a real interface it
can use to find out this stuff instead of just dumping more strings into
the logs?

My main obstacle to judging a solution is that I don't have in mind a
good list of (say) the top 10 problems that can cause the first mount to
fail.  Hm:

	- dns lookup of the server fails
	- server isn't reachable
	- server isn't running nfs
	- requested path isn't known to server or isn't exported
	- export is there, but requires more security
	- user doesn't have gss credentials
	- file permissions on the export are wrong
	...

--b.
--
To unsubscribe from this list: send the line "unsubscribe linux-nfs" in
the body of a message to majordomo@vger.kernel.org More majordomo info
at  http://vger.kernel.org/majordomo-info.html

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Arnaldo Carvalho de Melo]

Em Wed, Jan 21, 2009 at 05:57:46PM -0500, Trond Myklebust escreveu:
> On Wed, 2009-01-21 at 20:47 -0200, Arnaldo Carvalho de Melo wrote:
> > Em Thu, Jan 22, 2009 at 09:36:53AM +1100, Greg Banks escreveu:
> > > Chuck Lever wrote:
> > > >
> > > >
> > > > I think we need to visit this issue on a case-by-case basis.   
> > > > Sometimes dprintk is appropriate.  Sometimes printk(KERN_ERR).   
> > > > Sometimes a performance metric.
> > > Well said.
> > > 
> > > > Trond has always maintained that dprintk() is best for developers, but  
> > > > probably inappropriate for field debugging,
> > > It's not a perfect tool but it beats nothing at all.
> > > >  and I think that may also  
> > > > apply to trace points.  
> > > It depends on whether distros can be convinced to enable it by default,
> > > and install by default any necessary userspace infrastructure.   The
> > > most important thing for field debugging is Just Knowing that you have
> > > all the bits necessary to perform useful debugging without having to
> > > find some RPM that matches the kernel that the machine is actually
> > > running now, and not the one that was present when the machine was
> > > installed.
> > 
> > Exactly, that is why an ftrace plugin, that only when selected using
> > echo "nfs" > /debug/tracing/current_tracer will activate the tracepoints
> > and provide output via /debug/tracing/trace or /deb/tracing/trace_pipe,
> > possibly combined with other ftrace plugins such as the stacktrace,
> > blktrace, etc.
> > 
> > I.e. no need at all for any matching userspace tool, near zero impact
> > when not activated, useful, if done right, for both developers and for
> > admins.
> > 
> > Again, an example can be found in the blktrace ftrace plugin[1], that
> > instead of adding a requirement will eventually drop an existing, well
> > established one (blktrace(8)).
> 
> I must be missing something. Exactly what functionality does this then
> give us that we don't have already with the existing RPC/NFS dprintk()
> scheme?

Filtering by CPU, the possibity of printing stack traces when the
tracepoints are hit, combination with other tracers to try to mix events
and correlate problems, a request may be taking too long because some
problems are happening on a lower layer subsystem that has, in turn,
tracepoints exposed thru another ftrace plugin.

But then I haven't looked too closely to the places that are being
proposed for conversion to tracepoints in NFS land, will do.

- Arnaldo

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Greg Banks]

Trond Myklebust wrote:
> On Thu, 2009-01-22 at 09:36 +1100, Greg Banks wrote:
>   
>> Chuck Lever wrote:
>>     
>>>
>>>       
>> It depends on whether distros can be convinced to enable it by default,
>> and install by default any necessary userspace infrastructure.   The
>> most important thing for field debugging is Just Knowing that you have
>> all the bits necessary to perform useful debugging without having to
>> find some RPM that matches the kernel that the machine is actually
>> running now, and not the one that was present when the machine was
>> installed.
>>     
>
> Which is precisely why dprintk() is such a bad choice as a basis for a
> set of trace points: every new patch and bugfix that the distro applies
> will result in a reshuffling of the trace points as code is cleaned up
> and moved around or removed entirely.
>   
Yes, if the filename and line number were the only information going
out.  The dprintk() format is usually enough (ignoring the patchy
quality of the current dprintk set)  to give a developer enough clue
about which dprintk is which.  Or am I missing something?

-- 
Greg Banks, P.Engineer, SGI Australian Software Group.
the brightly coloured sporks of revolution.
I don't speak for SGI.

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Trond Myklebust]

On Thu, 2009-01-22 at 10:11 +1100, Greg Banks wrote:
> Trond Myklebust wrote:
> > On Thu, 2009-01-22 at 09:36 +1100, Greg Banks wrote:
> >   
> >> Chuck Lever wrote:
> >>     
> >>>
> >>>       
> >> It depends on whether distros can be convinced to enable it by default,
> >> and install by default any necessary userspace infrastructure.   The
> >> most important thing for field debugging is Just Knowing that you have
> >> all the bits necessary to perform useful debugging without having to
> >> find some RPM that matches the kernel that the machine is actually
> >> running now, and not the one that was present when the machine was
> >> installed.
> >>     
> >
> > Which is precisely why dprintk() is such a bad choice as a basis for a
> > set of trace points: every new patch and bugfix that the distro applies
> > will result in a reshuffling of the trace points as code is cleaned up
> > and moved around or removed entirely.
> >   
> Yes, if the filename and line number were the only information going
> out.  The dprintk() format is usually enough (ignoring the patchy
> quality of the current dprintk set)  to give a developer enough clue
> about which dprintk is which.  Or am I missing something?

The current dprintk() set was never designed to be anything other than a
logging tool with a very coarse filter (the bitmask
in /proc/sys/sunrpc/*_debug). It was designed to be human-readable only
(no fixed format).

As I understand it, you are not only proposing to make that filter
extremely fine (individually addressable trace points), but also to
enable the application of scripting tools like systemtap and LTTng in
order to provide bespoke debugging of your customer problems. Have I
misunderstood you, or is that correct?

The question then is how is this going to work out in an environment
where the individually addressable trace points/dprintk()s pop in and
out of existence at the whim of a patch, and where the output format is
similarly volatile?
IOW: I'm referring to the difference between an interface that was
designed purely to be interpreted by humans, and one that is designed
from scratch to be interpreted by scripts.

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Frank Ch. Eigler]

Trond Myklebust <trond.myklebust@fys.uio.no> writes:

> [...]  As I understand it, you are not only proposing to make that
> filter extremely fine (individually addressable trace points), but
> also to enable the application of scripting tools like systemtap and
> LTTng in order to provide bespoke debugging of your customer
> problems. Have I misunderstood you, or is that correct?

Perhaps.

> The question then is how is this going to work out in an environment
> where the individually addressable trace points/dprintk()s pop in
> and out of existence at the whim of a patch, and where the output
> format is similarly volatile?

It would work no worse than what there is now.  For environments where
the code is not subject to that much patching, it could be
piggybacked-upon for more analysis.

> IOW: I'm referring to the difference between an interface that was
> designed purely to be interpreted by humans, and one that is
> designed from scratch to be interpreted by scripts.

It need not be a disjunction.  As more formal machine-oriented
interfaces come into existence, the same tools can shift focus to
them.  Depending on the tool, the shift may be nearly invisible to a
naive end user.


- FChE

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Greg Banks]

Trond Myklebust wrote:
> On Thu, 2009-01-22 at 10:11 +1100, Greg Banks wrote:
>   
>> Trond Myklebust wrote:
>>     
>>> On Thu, 2009-01-22 at 09:36 +1100, Greg Banks wrote:
>>>   
>>>       
>>>> Chuck Lever wrote:
>>>>     
>>>>         
>>>>>       
>>>>>           
>>>> It depends on whether distros can be convinced to enable it by default,
>>>> and install by default any necessary userspace infrastructure.   The
>>>> most important thing for field debugging is Just Knowing that you have
>>>> all the bits necessary to perform useful debugging without having to
>>>> find some RPM that matches the kernel that the machine is actually
>>>> running now, and not the one that was present when the machine was
>>>> installed.
>>>>     
>>>>         
>>> Which is precisely why dprintk() is such a bad choice as a basis for a
>>> set of trace points: every new patch and bugfix that the distro applies
>>> will result in a reshuffling of the trace points as code is cleaned up
>>> and moved around or removed entirely.
>>>   
>>>       
>> Yes, if the filename and line number were the only information going
>> out.  The dprintk() format is usually enough (ignoring the patchy
>> quality of the current dprintk set)  to give a developer enough clue
>> about which dprintk is which.  Or am I missing something?
>>     
>
> The current dprintk() set was never designed to be anything other than a
> logging tool with a very coarse filter (the bitmask
> in /proc/sys/sunrpc/*_debug). It was designed to be human-readable only
> (no fixed format).
>
> As I understand it, you are not only proposing to make that filter
> extremely fine (individually addressable trace points), but also to
> enable the application of scripting tools like systemtap and LTTng in
> order to provide bespoke debugging of your customer problems. Have I
> misunderstood you, or is that correct?
>   

These are two separate proposals between which we're trying to find some
commonality.

In my proposal, the dprintk()s remain designed primarily for humans
(support staff or kernel developers) to read in conjunction with the
correct source code, but control is made fine-grain to make the
mechanism more controllable.  This can be done regardless of whether
trace points are involved and regardless of whether we attempt to
support scripts.

Changing dprintk() to add a trace point is just a way to get some trace
points with strictly minimum changes to callsites.

Replacing dprintk()s with new trace points has more or less the same
result but means more futzing with callsites.

> The question then is how is this going to work out in an environment
> where the individually addressable trace points/dprintk()s pop in and
> out of existence at the whim of a patch, and where the output format is
> similarly volatile?
> IOW: I'm referring to the difference between an interface that was
> designed purely to be interpreted by humans, and one that is designed
> from scratch to be interpreted by scripts.
>
>   

The maintenance problem of correlating any kind of instrumentation point
in kernel code with scripts living out in userspace exists regardless of
how you choose to implement the instrumentation.

-- 
Greg Banks, P.Engineer, SGI Australian Software Group.
the brightly coloured sporks of revolution.
I don't speak for SGI.

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Steve Dickson]

Trond Myklebust wrote:
> On Wed, 2009-01-21 at 14:58 -0500, Steve Dickson wrote:
>> Do we want to trace points:
>>     1) at all 
>>     2) for debugging 
>>     3) for performance
>>     4) 2 and 3
>>
>> Once we get the above nailed down then we can decide how to go...
> 
> I think it might be a good idea to flesh out a bit what you mean by
> "debugging" here. Since you mentioned it in conjunction with the two
> words "administrators" and "scripts", I assume that you are not talking
> about kernel code debugging?
I'm talking debugging for both admins and kernel people...

With trace points and systemtap you can do both.

steved.

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Steve Dickson]

Chuck Lever wrote:
> On Jan 21, 2009, at Jan 21, 2009, 2:37 PM, Steve Dickson wrote:
>> Chuck Lever wrote:
>>> Hey Steve-
>>>
>>> I'd like to see an example of a real mount problem or two that dprintk
>>> isn't adequate for, but a trace point could have helped.  In other
>>> words, can we get some use cases for dprintk and trace points for mount
>>> problems in specific?  I think that would help us understand the
>>> trade-offs a little better.
>> In the mount path that might be a bit difficult... but with trace
>> points you would be able to look at the entire super block or entire
>> server and client structures something you can't static/canned
>> printks...
> 
> I've never ever seen an NFS mount problem that required an admin to
> provide information from a superblock.  That seems like a lot of
> implementation detail that would be meaningless to admins and support
> desk folks.
True... but my point is with trace points and systemtap scripts
one has access to BOTH highly technical data (for the developer)
and simple error codes (for the admins).... Unlike with printks...
  
> 
> This is why I think we need to have some real world customer examples of
> mount problems (or read performance problems, or whatever) that we want
> to be able to diagnose in enterprise distributions.  I'm not saying this
> to throw up a road block... I think we really need to understand the
> problem before designing the solution, and so let's start with some
> practical examples.
I'm not sure this is an obtainable goal.... I see it as we put in a 
well design infrastructure (something I think Trond is suggesting)
and then let the consumers of the infrastructure tell us what is need... 
Believe there are enterprise people that know *exactly* what
they are looking for... ;-)

> 
> Again, I'm not saying trace points are bad or wrong, just that they may
> not be appropriate for a particular code path and the type of problems
> that arise during specific NFS operations.  I'm not criticizing your
> particular sample code.  I'm asking "Before we add trace points
> everywhere, are trace points strategically the right debugging tool in
> every case?"
Good point... but the fact trace points very little overhead with them its
kinda hard to see why they would not be the right tool... But again
I do see your point... 
 
> 
> Basically we have to know well in advance what kind of information will
> be needed at each trace point.  Who can predict?  If you have to solder
> in trace points in advance, in some ways that doesn't seem any more
> flexible than a dprintk.  What you've demonstrated is another good
> general tool for debugging, but you haven't convinced me that this is
> the right tool for, say, the mount path, or ACL support, and so on.
No worries.. I'll keep trying! ;-) 

To your point, I know for a fact there are customers asking for
trace points in particular areas of the code (not the NFS code atm).
So, again, I think we should take the "build it and will come"
approach... Meaning, give people something to work with and they
will let us know what they need...
 
> 
> I think we need to visit this issue on a case-by-case basis.  Sometimes
> dprintk is appropriate.  Sometimes printk(KERN_ERR).  Sometimes a
> performance metric.  Having specific troubleshooting in mind when we
> design this is critical, otherwise we are going to add a lot of kruft
> for no real benefit.
I can agree with this...

> 
> That's an advantage of something like SystemTap.  You can specify
> whatever is needed for a specific problem, and you don't need to
> recompile the kernel to do it.  Enterprise distributions can provide
> specific scripts for their code base, which doesn't change much. 
> Upstream is free to make whatever drastic modifications to the code base
> without worrying about breaking a kernel-user space API.
> 
> Trond has always maintained that dprintk() is best for developers, but
> probably inappropriate for field debugging, and I think that may also
> apply to trace points.  So I'm not against adding trace points where
> appropriate, but I'm doubtful that they will be helpful outside of
> kernel development; ie I wonder if they will specifically help customers
> of enterprise distributions.
> 
Time will tell... I think once customers see how useful and powerful
traces can but they be come addicted.... fairly quickly....

steved.

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Steve Dickson]

Greg Banks wrote:
> 
> These are two separate proposals between which we're trying to find some
> commonality.
I agree.. a common effort does make the most sense... imho...

> 
> In my proposal, the dprintk()s remain designed primarily for humans
> (support staff or kernel developers) to read in conjunction with the
> correct source code, but control is made fine-grain to make the
> mechanism more controllable.  This can be done regardless of whether
> trace points are involved and regardless of whether we attempt to
> support scripts.
I would think it the "fine-grain control mechanism" could also manage
trace points as well, true?

> 
> Changing dprintk() to add a trace point is just a way to get some trace
> points with strictly minimum changes to callsites.
I'm not sure this would be a good idea since, as Trond or Chuck pointed out,
there is really not rhyme or reason on where the dprintks live today... 

> 
> Replacing dprintk()s with new trace points has more or less the same
> result but means more futzing with callsites.
Well not if the replacements are well thought out and designed, since
there does not have 1-to-1 replacement... 
 
> 
> The maintenance problem of correlating any kind of instrumentation point
> in kernel code with scripts living out in userspace exists regardless of
> how you choose to implement the instrumentation.
> 
+1

steved.

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Steve Dickson]

Greg Banks wrote:
> I think both dprintks and trace points are the wrong approach for
> client-side mount problems.  What you really want there is good and
> useful diagnostic information going unconditionally via printk().  Mount
> problems happen frequently enough, and are often not the client's fault
> but the server's or a firewall's, that system admins need to be able to
> work out what went wrong in retrospect by looking in syslog.
> 
> But just because Steve chose an unfortunate example doesn't invalidate
> his point.  There are plenty of gnarly logic paths in the NFS client and
> server which need better runtime diagnostics.  On the server,  anything
> involving an upcall to userspace .  On the client, silly rename or
> attribute caching.
It appears I did pick an "unfortunate example"... since I was really
trying to introduce trace points to see how they could be used...
Maybe picking the I/O path would have been better... 


>>> Not being an admin guy, I really don't have an answer for this... but
>>> I can say since trace point are not so much of a drag on the system as
>>> printks are.. with in timing issues using trace point would be a big  
>>> advantage
>>> over printks
>>>     
>>   
> Well that argument works both ways.  Several times now I've seen
> problems where a significant part of the debugging process has involved
> noticing correlations between timing of dprintks and syslog messages
> from other subsystems, like IPoIB or TCP.  That's harder to do if the
> debug statements and printks go through separate mechanisms to userspace.

Yes... I have seen this an number of times and places... :-(

steved.

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Trond Myklebust]

On Thu, 2009-01-22 at 08:07 -0500, Steve Dickson wrote:
> > I think it might be a good idea to flesh out a bit what you mean by
> > "debugging" here. Since you mentioned it in conjunction with the two
> > words "administrators" and "scripts", I assume that you are not talking
> > about kernel code debugging?
> I'm talking debugging for both admins and kernel people...
> 
> With trace points and systemtap you can do both.

Yes, but we still need to figure out details of what each type of user
is expecting/wants.

I suspect that when we get down to cases, we will find that a lot of the
tracepoints that administrators find useful will want to be put in the
VFS rather than in the filesystems themselves. If you have tracepoints
in sys_stat() and sys_fstat(), why would you also need a tracepoint in
nfs_getattr()? AFAICS, that would just make scripting ugly...

Cheers
  Trond

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Steve Dickson]

Trond Myklebust wrote:
> On Thu, 2009-01-22 at 08:07 -0500, Steve Dickson wrote:
>>> I think it might be a good idea to flesh out a bit what you mean by
>>> "debugging" here. Since you mentioned it in conjunction with the two
>>> words "administrators" and "scripts", I assume that you are not talking
>>> about kernel code debugging?
>> I'm talking debugging for both admins and kernel people...
>>
>> With trace points and systemtap you can do both.
> 
> Yes, but we still need to figure out details of what each type of user
> is expecting/wants.
Will that be possible? Until we get something in their hands, how will
they even know what they want or need.

> 
> I suspect that when we get down to cases, we will find that a lot of the
> tracepoints that administrators find useful will want to be put in the
> VFS rather than in the filesystems themselves. If you have tracepoints
> in sys_stat() and sys_fstat(), why would you also need a tracepoint in
> nfs_getattr()? AFAICS, that would just make scripting ugly...
I believe there is an effort to do some type of system call tracing 
as we speak and that effort should be followed to ensure there is
no duplicate of effort... But in the end, I would think more would be
better then less... since each point can be explicitly enabled and disabled
a little duplication may not be all that bad..

steved.

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Steve Dickson]

J. Bruce Fields wrote:
> 
> On the mount case specifically: How far are we from the idea of a mount
> program that can identify most problems itself?  I know its error
> reporting has gotten better....
> 
> I suppose the main feedback mount gets right now is an error code from
> the mount system call, and that may be too narrow an interface to cover
> most problems.  Is there some way we can give mount a real interface it
> can use to find out this stuff instead of just dumping more strings into
> the logs?
Interesting.... Store something like a reason code (similar to what they have
in he Kerberos) in somewhere in the proc file system? 

Its seems to me this is a common problem among network file systems... 

steved.

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[J. Bruce Fields]

On Thu, Jan 22, 2009 at 10:59:49AM -0500, Steve Dickson wrote:
> J. Bruce Fields wrote:
> > 
> > On the mount case specifically: How far are we from the idea of a mount
> > program that can identify most problems itself?  I know its error
> > reporting has gotten better....
> > 
> > I suppose the main feedback mount gets right now is an error code from
> > the mount system call, and that may be too narrow an interface to cover
> > most problems.  Is there some way we can give mount a real interface it
> > can use to find out this stuff instead of just dumping more strings into
> > the logs?
> Interesting.... Store something like a reason code (similar to what they have
> in he Kerberos)

Maybe.

> in somewhere in the proc file system? 

But then I don't know how you'd associate it with a particular mount
attempt.

--b.

> Its seems to me this is a common problem among network file systems... 

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Arnaldo Carvalho de Melo]

Em Thu, Jan 22, 2009 at 10:49:43AM -0500, Steve Dickson escreveu:
> 
> 
> Trond Myklebust wrote:
> > On Thu, 2009-01-22 at 08:07 -0500, Steve Dickson wrote:
> >>> I think it might be a good idea to flesh out a bit what you mean by
> >>> "debugging" here. Since you mentioned it in conjunction with the two
> >>> words "administrators" and "scripts", I assume that you are not talking
> >>> about kernel code debugging?
> >> I'm talking debugging for both admins and kernel people...
> >>
> >> With trace points and systemtap you can do both.
> > 
> > Yes, but we still need to figure out details of what each type of user
> > is expecting/wants.
> Will that be possible? Until we get something in their hands, how will
> they even know what they want or need.
> 
> > 
> > I suspect that when we get down to cases, we will find that a lot of the
> > tracepoints that administrators find useful will want to be put in the
> > VFS rather than in the filesystems themselves. If you have tracepoints
> > in sys_stat() and sys_fstat(), why would you also need a tracepoint in
> > nfs_getattr()? AFAICS, that would just make scripting ugly...
> I believe there is an effort to do some type of system call tracing 
> as we speak and that effort should be followed to ensure there is
> no duplicate of effort... But in the end, I would think more would be
> better then less... since each point can be explicitly enabled and disabled
> a little duplication may not be all that bad..

I believe that the use case scenario here is blktrace, it was done
before tracepoints were in the kernel, before developers thought that
not requiring whatever size/complexity userspace binary to grok whatever
fast/optimum way to relay data so as some userspace tool would
inteligently process.

Now we're trying to keep the existing developer assists and augment it
with other, standardized ways coming for other subsystems, looking at
how to get the best ways of every trace-me-harder approach previously
endeavoured.

tracepoints, ftrace, etc, are an excellent opportunity for people to go
from stone age
print-msg-that-could-be-interesting-to-some-class-of-observer to
something OS provided, highly optimized.

<expletives deleted>

Erm, what is it that you think should be covered in a from everybody in
this community tracing perspective point of view?

- Arnaldo

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Greg Banks]

Steve Dickson wrote:
>   
> True... but my point is with trace points and systemtap scripts
> one has access to BOTH highly technical data (for the developer)
> and simple error codes (for the admins).... Unlike with printks...
>   
Yes, there's a lot more power in trace points.

-- 
Greg Banks, P.Engineer, SGI Australian Software Group.
the brightly coloured sporks of revolution.
I don't speak for SGI.

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Greg Banks]

Steve Dickson wrote:
> Greg Banks wrote:
>   
>> In my proposal, the dprintk()s remain designed primarily for humans
>> (support staff or kernel developers) to read in conjunction with the
>> correct source code, but control is made fine-grain to make the
>> mechanism more controllable.  This can be done regardless of whether
>> trace points are involved and regardless of whether we attempt to
>> support scripts.
>>     
> I would think it the "fine-grain control mechanism" could also manage
> trace points as well, true?
>   

Yes, and it would have the same value.  When I get back from LCA next
week I want to look at how one would fit that control mechanism into
trace points.
>   
>> Changing dprintk() to add a trace point is just a way to get some trace
>> points with strictly minimum changes to callsites.
>>     
> I'm not sure this would be a good idea since, as Trond or Chuck pointed out,
> there is really not rhyme or reason on where the dprintks live today... 
>   
Indeed, but it would be a starting point.
>   
>> Replacing dprintk()s with new trace points has more or less the same
>> result but means more futzing with callsites.
>>     
> Well not if the replacements are well thought out and designed, since
> there does not have 1-to-1 replacement... 
>   
I would hope that there would be *more* tracepoints than dprintks.

-- 
Greg Banks, P.Engineer, SGI Australian Software Group.
the brightly coloured sporks of revolution.
I don't speak for SGI.

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Greg Banks]

J. Bruce Fields wrote:
> On Thu, Jan 22, 2009 at 10:59:49AM -0500, Steve Dickson wrote:
>   
>> J. Bruce Fields wrote:
>>     
>>
>> Interesting.... Store something like a reason code (similar to what they have
>> in he Kerberos)
>>     
>
> Maybe.
>
>   
>> in somewhere in the proc file system? 
>>     
>
> But then I don't know how you'd associate it with a particular mount
> attempt.
>
>
>   
You could do something truly awful like add a new code in the unused
bits of the errno value returned from mount.  It would confuse an
unmodified userspace, but reporting "Unknown Error" isn't much less
useful than "I/O Error".

-- 
Greg Banks, P.Engineer, SGI Australian Software Group.
the brightly coloured sporks of revolution.
I don't speak for SGI.

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[J. Bruce Fields]

On Fri, Jan 23, 2009 at 09:54:20AM +1100, Greg Banks wrote:
> J. Bruce Fields wrote:
> > On Thu, Jan 22, 2009 at 10:59:49AM -0500, Steve Dickson wrote:
> >   
> >> J. Bruce Fields wrote:
> >>     
> >>
> >> Interesting.... Store something like a reason code (similar to what they have
> >> in he Kerberos)
> >>     
> >
> > Maybe.
> >
> >   
> >> in somewhere in the proc file system? 
> >>     
> >
> > But then I don't know how you'd associate it with a particular mount
> > attempt.
> >
> >
> >   
> You could do something truly awful like add a new code in the unused
> bits of the errno value returned from mount.  It would confuse an
> unmodified userspace, but reporting "Unknown Error" isn't much less
> useful than "I/O Error".

There must be cases where the existing error gives us some information,
but not as much as we'd like, so the "Unknown Error" could be a step
backwards for unmodified userspace.  An extra mount option (normally
hidden from the user) could be used to tell the kernel that the
application doing the mount was capable of handling the new error codes.
Ugh.

--b.

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Chuck Lever]

On Jan 21, 2009, at Jan 21, 2009, 5:56 PM, J. Bruce Fields wrote:
> On Thu, Jan 22, 2009 at 09:36:53AM +1100, Greg Banks wrote:
>> Chuck Lever wrote:
>>>
>>>
>>> I think we need to visit this issue on a case-by-case basis.
>>> Sometimes dprintk is appropriate.  Sometimes printk(KERN_ERR).
>>> Sometimes a performance metric.
>> Well said.
>>
>>> Trond has always maintained that dprintk() is best for developers,  
>>> but
>>> probably inappropriate for field debugging,
>> It's not a perfect tool but it beats nothing at all.
>>> and I think that may also
>>> apply to trace points.
>> It depends on whether distros can be convinced to enable it by  
>> default,
>> and install by default any necessary userspace infrastructure.   The
>> most important thing for field debugging is Just Knowing that you  
>> have
>> all the bits necessary to perform useful debugging without having to
>> find some RPM that matches the kernel that the machine is actually
>> running now, and not the one that was present when the machine was
>> installed.
>
> On the mount case specifically: How far are we from the idea of a  
> mount
> program that can identify most problems itself?  I know its error
> reporting has gotten better....

> I suppose the main feedback mount gets right now is an error code from
> the mount system call, and that may be too narrow an interface to  
> cover
> most problems.  Is there some way we can give mount a real interface  
> it
> can use to find out this stuff instead of just dumping more strings  
> into
> the logs?

A main reason it does this rather than generate error messages on the  
terminal is that mount has to run in "background" environments.   
Mounts done at boot time do not have a controlling terminal.  A bg  
mount can drop into the background, and thus it loses its controlling  
terminal.  Automounter doesn't have a controlling terminal to begin  
with.

My feeling is that, as mount is a system tool, it should report its  
problems in the system log.  If there's a controlling terminal, report  
it there too.  But by and large it is a tool that is run most often  
without direct human intervention or monitoring.

In addition there are a lot of cases it can (and does) handle by  
itself.  Renegotiating mount option settings is one of these things.

It's a narrow interface, but I'm not sure yet it's entirely inadequate.

> My main obstacle to judging a solution is that I don't have in mind a
> good list of (say) the top 10 problems that can cause the first  
> mount to
> fail.  Hm:
>
> 	- dns lookup of the server fails
> 	- server isn't reachable
> 	- server isn't running nfs
> 	- requested path isn't known to server or isn't exported
> 	- export is there, but requires more security
> 	- user doesn't have gss credentials
> 	- file permissions on the export are wrong
> 	...

	- tcp_wrappers or iptables blocking access
	- network routing problems
	- v2/v3 server not running rpcbind or lockd

This is exactly why I want to start with some real world examples.   
Without examples we are much more likely to design something that  
isn't useful to anyone.  History (or e-mail archives) gives us a lot  
of information about what might be common problems.

I think we handle some of these cases reasonably well today, though  
they could probably stand some polish; others, like security  
configuration, are still a little new and kind of a low priority (for  
good or bad reasons) and so it is still a bit confusing.

But really, if mount can report a clear error message and suggest a  
course of corrective action, I don't think a dprintk or trace point or  
SystemTap will be of any greater help.

--
Chuck Lever
chuck[dot]lever[at]oracle[dot]com

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Chuck Lever]

On Jan 22, 2009, at Jan 22, 2009, 10:19 AM, Steve Dickson wrote:
> Greg Banks wrote:
>> I think both dprintks and trace points are the wrong approach for
>> client-side mount problems.  What you really want there is good and
>> useful diagnostic information going unconditionally via printk().   
>> Mount
>> problems happen frequently enough, and are often not the client's  
>> fault
>> but the server's or a firewall's, that system admins need to be  
>> able to
>> work out what went wrong in retrospect by looking in syslog.
>>
>> But just because Steve chose an unfortunate example doesn't  
>> invalidate
>> his point.  There are plenty of gnarly logic paths in the NFS  
>> client and
>> server which need better runtime diagnostics.  On the server,   
>> anything
>> involving an upcall to userspace .  On the client, silly rename or
>> attribute caching.
> It appears I did pick an "unfortunate example"... since I was really
> trying to introduce trace points to see how they could be used...
> Maybe picking the I/O path would have been better...

Choosing mount was reasonable, as it's simple.  The discussion we are  
having about what tool is right for the job would have probably been  
less interesting if you had stuck with the I/O path.

The big picture though, is what do we need to do to make it easier to  
troubleshoot and solve problems.  That is a much bigger question than  
how we report errors.

--
Chuck Lever
chuck[dot]lever[at]oracle[dot]com

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Greg Banks]

J. Bruce Fields wrote:
> On Fri, Jan 23, 2009 at 09:54:20AM +1100, Greg Banks wrote:
>   
>> J. Bruce Fields wrote:
>>     
>>> On Thu, Jan 22, 2009 at 10:59:49AM -0500, Steve Dickson wrote:
>>>   
>>>       
>>>> J. Bruce Fields wrote:
>>>>     
>>>>
>>>> Interesting.... Store something like a reason code (similar to what they have
>>>> in he Kerberos)
>>>>     
>>>>         
>>> Maybe.
>>>
>>>   
>>>       
>>>> in somewhere in the proc file system? 
>>>>     
>>>>         
>>> But then I don't know how you'd associate it with a particular mount
>>> attempt.
>>>
>>>
>>>   
>>>       
>> You could do something truly awful like add a new code in the unused
>> bits of the errno value returned from mount.  It would confuse an
>> unmodified userspace, but reporting "Unknown Error" isn't much less
>> useful than "I/O Error".
>>     
>
> There must be cases where the existing error gives us some information,
> but not as much as we'd like, so the "Unknown Error" could be a step
> backwards for unmodified userspace.  An extra mount option (normally
> hidden from the user) could be used to tell the kernel that the
> application doing the mount was capable of handling the new error codes.
> Ugh.
>
>
>   
Ugh is right.

On further thought, you could use the extra mount option to enable a
behaviour where the kernel would format into the mount options buffer a
string describing the reasons for the mount failure.  If the option
weren't present the kernel could emit that same message via printk().

-- 
Greg Banks, P.Engineer, SGI Australian Software Group.
the brightly coloured sporks of revolution.
I don't speak for SGI.

Re: [RFC][PATCH 0/5] NFS: trace points added to mounting path

[Greg Banks]

Chuck Lever wrote:
>
> The big picture though, is what do we need to do to make it easier to
> troubleshoot and solve problems.  That is a much bigger question than
> how we report errors.
Indeed.

-- 
Greg Banks, P.Engineer, SGI Australian Software Group.
the brightly coloured sporks of revolution.
I don't speak for SGI.