2008-05-21 18:19:52

by Chuck Lever

[permalink] [raw]
Subject: [PATCH 0/6] Initial set of 2.6.27 patches, take 3

Hi Trond-

Resending the first batch of 2.6.27 patches, with additional fixes.

Using the RPC procedure name in debugging messages should no longer add a
risk of a segmentation fault.

I've also done a third re-implementation of the tk_action function name
patch. I finally managed to find an interface that will perform the symbol
table lookup, and can be called from a module or from built-in code.

Oddly this API has been around for a while; I'm not sure how I missed it
originally. But it should implement the nice function-name-rather-than-
memory-address feature without a wonky table, and without requiring any
additional changes when adding a new FSM state function. It will display
the function name if the lookup succeeds; otherwise it will display a hex
memory address. It works for any arbitrary pointer stored in the
tk_action field.

I've thought of a couple of other ways rpc_show_tasks() could be improved.
First, it could display the IP address of the server handling each request;
and it should have a different column layout for systems with 64-bit
addresses. All for another day, I suppose.

---

Chuck Lever (6):
SUNRPC: Display some debugging information as text rather than numbers
SUNRPC: Refactor rpc_show_tasks
SUNRPC: Don't display the rpc_show_tasks header if there are no tasks
SUNRPC: Rename "call_" functions that are no longer FSM states
SUNRPC: Add a function to display the name of an RPC procedure
NFS: Update help text for CONFIG_NFS_FS


fs/Kconfig | 115 ++++++++++++++++++++++++-------------------------
net/sunrpc/clnt.c | 124 ++++++++++++++++++++++++++++++-----------------------
2 files changed, 128 insertions(+), 111 deletions(-)

--
Signature


2008-05-21 18:16:22

by Chuck Lever

[permalink] [raw]
Subject: [PATCH 2/6] SUNRPC: Add a function to display the name of an RPC procedure

Improve debugging messages in call_start() and call_verify() by having
them show the RPC procedure name instead of the procedure number.

Signed-off-by: Chuck Lever <[email protected]>
---

net/sunrpc/clnt.c | 23 +++++++++++++++++++----
1 files changed, 19 insertions(+), 4 deletions(-)


diff --git a/net/sunrpc/clnt.c b/net/sunrpc/clnt.c
index 8945307..b20638b 100644
--- a/net/sunrpc/clnt.c
+++ b/net/sunrpc/clnt.c
@@ -690,6 +690,21 @@ rpc_restart_call(struct rpc_task *task)
}
EXPORT_SYMBOL_GPL(rpc_restart_call);

+#ifdef RPC_DEBUG
+static const char *rpc_proc_name(const struct rpc_task *task)
+{
+ const struct rpc_procinfo *proc = task->tk_msg.rpc_proc;
+
+ if (proc) {
+ if (proc->p_name)
+ return proc->p_name;
+ else
+ return "NULL";
+ } else
+ return "no proc";
+}
+#endif
+
/*
* 0. Initial state
*
@@ -701,9 +716,9 @@ call_start(struct rpc_task *task)
{
struct rpc_clnt *clnt = task->tk_client;

- dprintk("RPC: %5u call_start %s%d proc %d (%s)\n", task->tk_pid,
+ dprintk("RPC: %5u call_start %s%d proc %s (%s)\n", task->tk_pid,
clnt->cl_protname, clnt->cl_vers,
- task->tk_msg.rpc_proc->p_proc,
+ rpc_proc_name(task),
(RPC_IS_ASYNC(task) ? "async" : "sync"));

/* Increment call count */
@@ -1431,10 +1446,10 @@ call_verify(struct rpc_task *task)
error = -EPROTONOSUPPORT;
goto out_err;
case RPC_PROC_UNAVAIL:
- dprintk("RPC: %5u %s: proc %p unsupported by program %u, "
+ dprintk("RPC: %5u %s: proc %s unsupported by program %u, "
"version %u on server %s\n",
task->tk_pid, __func__,
- task->tk_msg.rpc_proc,
+ rpc_proc_name(task),
task->tk_client->cl_prog,
task->tk_client->cl_vers,
task->tk_client->cl_server);


2008-05-21 18:16:13

by Chuck Lever

[permalink] [raw]
Subject: [PATCH 1/6] NFS: Update help text for CONFIG_NFS_FS

Clean up: refresh the help text for Kconfig items related to the NFS
client. Remove obsolete URLs, and make the language consistent among
the options.

Also move the ROOT_NFS config option next to the options related to the
NFS client.

Signed-off-by: Chuck Lever <[email protected]>
---

fs/Kconfig | 115 ++++++++++++++++++++++++++++++------------------------------
1 files changed, 57 insertions(+), 58 deletions(-)


diff --git a/fs/Kconfig b/fs/Kconfig
index cf12c40..07a61f5 100644
--- a/fs/Kconfig
+++ b/fs/Kconfig
@@ -1544,10 +1544,6 @@ config UFS_FS
The recently released UFS2 variant (used in FreeBSD 5.x) is
READ-ONLY supported.

- If you only intend to mount files from some other Unix over the
- network using NFS, you don't need the UFS file system support (but
- you need NFS file system support obviously).
-
Note that this option is generally not needed for floppies, since a
good portable way to transport files and directories between unixes
(and even other operating systems) is given by the tar program ("man
@@ -1587,6 +1583,7 @@ menuconfig NETWORK_FILESYSTEMS
Say Y here to get to see options for network filesystems and
filesystem-related networking code, such as NFS daemon and
RPCSEC security modules.
+
This option alone does not add any kernel code.

If you say N, all options in this submenu will be skipped and
@@ -1595,76 +1592,92 @@ menuconfig NETWORK_FILESYSTEMS
if NETWORK_FILESYSTEMS

config NFS_FS
- tristate "NFS file system support"
+ tristate "NFS client support"
depends on INET
select LOCKD
select SUNRPC
select NFS_ACL_SUPPORT if NFS_V3_ACL
help
- If you are connected to some other (usually local) Unix computer
- (using SLIP, PLIP, PPP or Ethernet) and want to mount files residing
- on that computer (the NFS server) using the Network File Sharing
- protocol, say Y. "Mounting files" means that the client can access
- the files with usual UNIX commands as if they were sitting on the
- client's hard disk. For this to work, the server must run the
- programs nfsd and mountd (but does not need to have NFS file system
- support enabled in its kernel). NFS is explained in the Network
- Administrator's Guide, available from
- <http://www.tldp.org/docs.html#guide>, on its man page: "man
- nfs", and in the NFS-HOWTO.
-
- A superior but less widely used alternative to NFS is provided by
- the Coda file system; see "Coda file system support" below.
+ Choose Y here if you want to access files residing on other
+ computers using Sun's Network File System protocol. To compile
+ this file system support as a module, choose M here: the module
+ will be called nfs.

- If you say Y here, you should have said Y to TCP/IP networking also.
- This option would enlarge your kernel by about 27 KB.
+ To mount file systems exported by NFS servers, you also need to
+ install the user space mount.nfs command which can be found in
+ the Linux nfs-utils package, available from http://linux-nfs.org/.
+ Information about using the mount command is available in the
+ mount(8) man page. More detail about the Linux NFS client
+ implementation is available via the nfs(5) man page.

- To compile this file system support as a module, choose M here: the
- module will be called nfs.
+ Below you can choose which versions of the NFS protocol are
+ available in the kernel to mount NFS servers. Support for NFS
+ version 2 (RFC 1094) is always available when NFS_FS is selected.

- If you are configuring a diskless machine which will mount its root
- file system over NFS at boot time, say Y here and to "Kernel
- level IP autoconfiguration" above and to "Root file system on NFS"
- below. You cannot compile this driver as a module in this case.
- There are two packages designed for booting diskless machines over
- the net: netboot, available from
- <http://ftp1.sourceforge.net/netboot/>, and Etherboot,
- available from <http://ftp1.sourceforge.net/etherboot/>.
+ To configure a system which mounts its root file system via NFS
+ at boot time, say Y here, select "Kernel level IP
+ autoconfiguration" in the NETWORK menu, and select "Root file
+ system on NFS" below. You cannot compile this file system as a
+ module in this case.

- If you don't know what all this is about, say N.
+ If unsure, say N.

config NFS_V3
- bool "Provide NFSv3 client support"
+ bool "NFS client support for NFS version 3"
depends on NFS_FS
help
- Say Y here if you want your NFS client to be able to speak version
- 3 of the NFS protocol.
+ This option enables support for version 3 of the NFS protocol
+ (RFC 1813) in the kernel's NFS client.

If unsure, say Y.

config NFS_V3_ACL
- bool "Provide client support for the NFSv3 ACL protocol extension"
+ bool "NFS client support for the NFSv3 ACL protocol extension"
depends on NFS_V3
help
- Implement the NFSv3 ACL protocol extension for manipulating POSIX
- Access Control Lists. The server should also be compiled with
- the NFSv3 ACL protocol extension; see the CONFIG_NFSD_V3_ACL option.
+ Some NFS servers support an auxiliary NFSv3 ACL protocol that
+ Sun added to Solaris but never became an official part of the
+ NFS version 3 protocol. This protocol extension allows
+ applications on NFS clients to manipulate POSIX Access Control
+ Lists on files residing on NFS servers. NFS servers enforce
+ ACLs on local files whether this protocol is available or not.
+
+ Choose Y here if your NFS server supports the Solaris NFSv3 ACL
+ protocol extension and you want your NFS client to allow
+ applications to access and modify ACLs on files on the server.
+
+ Most NFS servers don't support the Solaris NFSv3 ACL protocol
+ extension. You can choose N here or specify the "noacl" mount
+ option to prevent your NFS client from trying to use the NFSv3
+ ACL protocol.

If unsure, say N.

config NFS_V4
- bool "Provide NFSv4 client support (EXPERIMENTAL)"
+ bool "NFS client support for NFS version 4 (EXPERIMENTAL)"
depends on NFS_FS && EXPERIMENTAL
select RPCSEC_GSS_KRB5
help
- Say Y here if you want your NFS client to be able to speak the newer
- version 4 of the NFS protocol.
+ This option enables support for version 4 of the NFS protocol
+ (RFC 3530) in the kernel's NFS client.

- Note: Requires auxiliary userspace daemons which may be found on
- http://www.citi.umich.edu/projects/nfsv4/
+ To mount NFS servers using NFSv4, you also need to install user
+ space programs which can be found in the Linux nfs-utils package,
+ available from http://linux-nfs.org/.

If unsure, say N.

+config ROOT_NFS
+ bool "Root file system on NFS"
+ depends on NFS_FS=y && IP_PNP
+ help
+ If you want your system to mount its root file system via NFS,
+ choose Y here. This is common practice for managing systems
+ without local permanent storage. For details, read
+ <file:Documentation/filesystems/nfsroot.txt>.
+
+ Most people say N here.
+
config NFSD
tristate "NFS server support"
depends on INET
@@ -1746,20 +1759,6 @@ config NFSD_V4

If unsure, say N.

-config ROOT_NFS
- bool "Root file system on NFS"
- depends on NFS_FS=y && IP_PNP
- help
- If you want your Linux box to mount its whole root file system (the
- one containing the directory /) from some other computer over the
- net via NFS (presumably because your box doesn't have a hard disk),
- say Y. Read <file:Documentation/filesystems/nfsroot.txt> for
- details. It is likely that in this case, you also want to say Y to
- "Kernel level IP autoconfiguration" so that your box can discover
- its network address at boot time.
-
- Most people say N here.
-
config LOCKD
tristate



2008-05-21 18:16:26

by Chuck Lever

[permalink] [raw]
Subject: [PATCH 3/6] SUNRPC: Rename "call_" functions that are no longer FSM states

The RPC client uses a finite state machine to move RPC tasks through each
step of an RPC request. Each state is contained in a function in
net/sunrpc/clnt.c, and named call_foo.

Some of the functions named call_foo have changed over the past few years and
are no longer states in the FSM. These include: call_encode, call_header,
and call_verify. As a clean up, rename the functions that have changed.

Signed-off-by: Chuck Lever <[email protected]>
---

net/sunrpc/clnt.c | 35 ++++++++++++++---------------------
1 files changed, 14 insertions(+), 21 deletions(-)


diff --git a/net/sunrpc/clnt.c b/net/sunrpc/clnt.c
index b20638b..619e4ea 100644
--- a/net/sunrpc/clnt.c
+++ b/net/sunrpc/clnt.c
@@ -58,7 +58,6 @@ static void call_start(struct rpc_task *task);
static void call_reserve(struct rpc_task *task);
static void call_reserveresult(struct rpc_task *task);
static void call_allocate(struct rpc_task *task);
-static void call_encode(struct rpc_task *task);
static void call_decode(struct rpc_task *task);
static void call_bind(struct rpc_task *task);
static void call_bind_status(struct rpc_task *task);
@@ -70,9 +69,9 @@ static void call_refreshresult(struct rpc_task *task);
static void call_timeout(struct rpc_task *task);
static void call_connect(struct rpc_task *task);
static void call_connect_status(struct rpc_task *task);
-static __be32 * call_header(struct rpc_task *task);
-static __be32 * call_verify(struct rpc_task *task);

+static __be32 *rpc_encode_header(struct rpc_task *task);
+static __be32 *rpc_verify_header(struct rpc_task *task);
static int rpc_ping(struct rpc_clnt *clnt, int flags);

static void rpc_register_client(struct rpc_clnt *clnt)
@@ -876,7 +875,7 @@ rpc_xdr_buf_init(struct xdr_buf *buf, void *start, size_t len)
* 3. Encode arguments of an RPC call
*/
static void
-call_encode(struct rpc_task *task)
+rpc_xdr_encode(struct rpc_task *task)
{
struct rpc_rqst *req = task->tk_rqstp;
kxdrproc_t encode;
@@ -891,13 +890,14 @@ call_encode(struct rpc_task *task)
(char *)req->rq_buffer + req->rq_callsize,
req->rq_rcvsize);

- /* Encode header and provided arguments */
- encode = task->tk_msg.rpc_proc->p_encode;
- if (!(p = call_header(task))) {
- printk(KERN_INFO "RPC: call_header failed, exit EIO\n");
+ p = rpc_encode_header(task);
+ if (p == NULL) {
+ printk(KERN_INFO "RPC: couldn't encode RPC header, exit EIO\n");
rpc_exit(task, -EIO);
return;
}
+
+ encode = task->tk_msg.rpc_proc->p_encode;
if (encode == NULL)
return;

@@ -1061,7 +1061,7 @@ call_transmit(struct rpc_task *task)
/* Encode here so that rpcsec_gss can use correct sequence number. */
if (rpc_task_need_encode(task)) {
BUG_ON(task->tk_rqstp->rq_bytes_sent != 0);
- call_encode(task);
+ rpc_xdr_encode(task);
/* Did the encode result in an error condition? */
if (task->tk_status != 0)
return;
@@ -1239,8 +1239,7 @@ call_decode(struct rpc_task *task)
goto out_retry;
}

- /* Verify the RPC header */
- p = call_verify(task);
+ p = rpc_verify_header(task);
if (IS_ERR(p)) {
if (p == ERR_PTR(-EAGAIN))
goto out_retry;
@@ -1258,7 +1257,7 @@ call_decode(struct rpc_task *task)
return;
out_retry:
task->tk_status = 0;
- /* Note: call_verify() may have freed the RPC slot */
+ /* Note: rpc_verify_header() may have freed the RPC slot */
if (task->tk_rqstp == req) {
req->rq_received = req->rq_rcv_buf.len = 0;
if (task->tk_client->cl_discrtry)
@@ -1305,11 +1304,8 @@ call_refreshresult(struct rpc_task *task)
return;
}

-/*
- * Call header serialization
- */
static __be32 *
-call_header(struct rpc_task *task)
+rpc_encode_header(struct rpc_task *task)
{
struct rpc_clnt *clnt = task->tk_client;
struct rpc_rqst *req = task->tk_rqstp;
@@ -1329,11 +1325,8 @@ call_header(struct rpc_task *task)
return p;
}

-/*
- * Reply header verification
- */
static __be32 *
-call_verify(struct rpc_task *task)
+rpc_verify_header(struct rpc_task *task)
{
struct kvec *iov = &task->tk_rqstp->rq_rcv_buf.head[0];
int len = task->tk_rqstp->rq_rcv_buf.len >> 2;
@@ -1407,7 +1400,7 @@ call_verify(struct rpc_task *task)
task->tk_action = call_bind;
goto out_retry;
case RPC_AUTH_TOOWEAK:
- printk(KERN_NOTICE "call_verify: server %s requires stronger "
+ printk(KERN_NOTICE "RPC: server %s requires stronger "
"authentication.\n", task->tk_client->cl_server);
break;
default:


2008-05-21 18:16:31

by Chuck Lever

[permalink] [raw]
Subject: [PATCH 4/6] SUNRPC: Don't display the rpc_show_tasks header if there are no tasks

Clean up: don't display the rpc_show_tasks column header unless there is at
least one task to display. As far as I can tell, it is safe to let the
list_for_each_entry macro decide that each list is empty.

scripts/checkpatch.pl also wants a KERN_FOO at the start of any newly added
printk() calls, so this and subsequent patches will also add KERN_INFO.

Signed-off-by: Chuck Lever <[email protected]>
---

net/sunrpc/clnt.c | 19 ++++++++++++-------
1 files changed, 12 insertions(+), 7 deletions(-)


diff --git a/net/sunrpc/clnt.c b/net/sunrpc/clnt.c
index 619e4ea..e763725 100644
--- a/net/sunrpc/clnt.c
+++ b/net/sunrpc/clnt.c
@@ -1525,24 +1525,30 @@ struct rpc_task *rpc_call_null(struct rpc_clnt *clnt, struct rpc_cred *cred, int
EXPORT_SYMBOL_GPL(rpc_call_null);

#ifdef RPC_DEBUG
+static void rpc_show_header(void)
+{
+ printk(KERN_INFO "-pid- proc flgs status -client- -prog- --rqstp- "
+ "-timeout -rpcwait -action- ---ops--\n");
+}
+
void rpc_show_tasks(void)
{
struct rpc_clnt *clnt;
struct rpc_task *t;
+ int header = 0;

spin_lock(&rpc_client_lock);
- if (list_empty(&all_clients))
- goto out;
- printk("-pid- proc flgs status -client- -prog- --rqstp- -timeout "
- "-rpcwait -action- ---ops--\n");
list_for_each_entry(clnt, &all_clients, cl_clients) {
- if (list_empty(&clnt->cl_tasks))
- continue;
spin_lock(&clnt->cl_lock);
list_for_each_entry(t, &clnt->cl_tasks, tk_task) {
const char *rpc_waitq = "none";
int proc;

+ if (!header) {
+ rpc_show_header();
+ header++;
+ }
+
if (t->tk_msg.rpc_proc)
proc = t->tk_msg.rpc_proc->p_proc;
else
@@ -1562,7 +1568,6 @@ void rpc_show_tasks(void)
}
spin_unlock(&clnt->cl_lock);
}
-out:
spin_unlock(&rpc_client_lock);
}
#endif


2008-05-21 18:16:44

by Chuck Lever

[permalink] [raw]
Subject: [PATCH 6/6] SUNRPC: Display some debugging information as text rather than numbers

In rpc_show_tasks(), display the program name, version number, procedure
name and tk_action as human-readable variable-length text fields rather
than columnar numbers.

Doing the symbol lookup here helps in cases where we have actual
debugging output from a kernel log, but don't have access to the kernel
image or RPC module that generated the output.

Sample output:

-pid- flgs status -client- --rqstp- -timeout ---ops--
5608 0001 -11 eeb42690 f6d93710 0 f8fa1764 nfsv3 WRITE a:call_transmit_status q:none
5609 0001 -11 eeb42690 f6d937e0 0 f8fa1764 nfsv3 WRITE a:call_status q:xprt_sending
5610 0001 -11 eeb42690 f6d93230 0 f8fa1764 nfsv3 WRITE a:call_status q:xprt_sending
5611 0001 -11 eeb42690 f6d93300 0 f8fa1764 nfsv3 WRITE a:call_status q:xprt_sending
5612 0001 -11 eeb42690 f6d93090 0 f8fa1764 nfsv3 WRITE a:call_status q:xprt_sending
5613 0001 -11 eeb42690 f6d933d0 0 f8fa1764 nfsv3 WRITE a:call_status q:xprt_sending
5614 0001 -11 eeb42690 f6d93cc0 0 f8fa1764 nfsv3 WRITE a:call_status q:xprt_sending
5615 0001 -11 eeb42690 f6d93a50 0 f8fa1764 nfsv3 WRITE a:call_status q:xprt_sending
5616 0001 -11 eeb42690 f6d93640 0 f8fa1764 nfsv3 WRITE a:call_status q:xprt_sending
5617 0001 -11 eeb42690 f6d93b20 0 f8fa1764 nfsv3 WRITE a:call_status q:xprt_sending
5618 0001 -11 eeb42690 f6d93160 0 f8fa1764 nfsv3 WRITE a:call_status q:xprt_sending

Signed-off-by: Chuck Lever <[email protected]>
---

net/sunrpc/clnt.c | 29 ++++++++++++++++-------------
1 files changed, 16 insertions(+), 13 deletions(-)


diff --git a/net/sunrpc/clnt.c b/net/sunrpc/clnt.c
index 68b08d4..878752c 100644
--- a/net/sunrpc/clnt.c
+++ b/net/sunrpc/clnt.c
@@ -25,6 +25,7 @@

#include <linux/module.h>
#include <linux/types.h>
+#include <linux/kallsyms.h>
#include <linux/mm.h>
#include <linux/slab.h>
#include <linux/smp_lock.h>
@@ -1527,29 +1528,31 @@ EXPORT_SYMBOL_GPL(rpc_call_null);
#ifdef RPC_DEBUG
static void rpc_show_header(void)
{
- printk(KERN_INFO "-pid- proc flgs status -client- -prog- --rqstp- "
- "-timeout -rpcwait -action- ---ops--\n");
+ printk(KERN_INFO "-pid- flgs status -client- --rqstp- "
+ "-timeout ---ops--\n");
}

static void rpc_show_task(const struct rpc_clnt *clnt,
const struct rpc_task *task)
{
const char *rpc_waitq = "none";
- int proc = -1;
-
- if (task->tk_msg.rpc_proc)
- proc = task->tk_msg.rpc_proc->p_proc;
+ char *p, action[KSYM_SYMBOL_LEN];

if (RPC_IS_QUEUED(task))
rpc_waitq = rpc_qname(task->tk_waitqueue);

- printk(KERN_INFO "%5u %04d %04x %6d %8p %6d %8p %8ld %8s %8p %8p\n",
- task->tk_pid, proc,
- task->tk_flags, task->tk_status,
- clnt, clnt->cl_prog,
- task->tk_rqstp, task->tk_timeout,
- rpc_waitq,
- task->tk_action, task->tk_ops);
+ /* map tk_action pointer to a function name; then trim off
+ * the "+0x0 [sunrpc]" */
+ sprint_symbol(action, (unsigned long)task->tk_action);
+ p = strchr(action, '+');
+ if (p)
+ *p = '\0';
+
+ printk(KERN_INFO "%5u %04x %6d %8p %8p %8ld %8p %sv%u %s a:%s q:%s\n",
+ task->tk_pid, task->tk_flags, task->tk_status,
+ clnt, task->tk_rqstp, task->tk_timeout, task->tk_ops,
+ clnt->cl_protname, clnt->cl_vers, rpc_proc_name(task),
+ action, queue);
}

void rpc_show_tasks(void)


2008-05-21 18:21:31

by Chuck Lever

[permalink] [raw]
Subject: [PATCH 5/6] SUNRPC: Refactor rpc_show_tasks

Clean up: move the logic that displays each task to its own function.
This removes indentation and makes future changes easier.

Signed-off-by: Chuck Lever <[email protected]>
---

net/sunrpc/clnt.c | 46 ++++++++++++++++++++++++----------------------
1 files changed, 24 insertions(+), 22 deletions(-)


diff --git a/net/sunrpc/clnt.c b/net/sunrpc/clnt.c
index e763725..68b08d4 100644
--- a/net/sunrpc/clnt.c
+++ b/net/sunrpc/clnt.c
@@ -1531,40 +1531,42 @@ static void rpc_show_header(void)
"-timeout -rpcwait -action- ---ops--\n");
}

+static void rpc_show_task(const struct rpc_clnt *clnt,
+ const struct rpc_task *task)
+{
+ const char *rpc_waitq = "none";
+ int proc = -1;
+
+ if (task->tk_msg.rpc_proc)
+ proc = task->tk_msg.rpc_proc->p_proc;
+
+ if (RPC_IS_QUEUED(task))
+ rpc_waitq = rpc_qname(task->tk_waitqueue);
+
+ printk(KERN_INFO "%5u %04d %04x %6d %8p %6d %8p %8ld %8s %8p %8p\n",
+ task->tk_pid, proc,
+ task->tk_flags, task->tk_status,
+ clnt, clnt->cl_prog,
+ task->tk_rqstp, task->tk_timeout,
+ rpc_waitq,
+ task->tk_action, task->tk_ops);
+}
+
void rpc_show_tasks(void)
{
struct rpc_clnt *clnt;
- struct rpc_task *t;
+ struct rpc_task *task;
int header = 0;

spin_lock(&rpc_client_lock);
list_for_each_entry(clnt, &all_clients, cl_clients) {
spin_lock(&clnt->cl_lock);
- list_for_each_entry(t, &clnt->cl_tasks, tk_task) {
- const char *rpc_waitq = "none";
- int proc;
-
+ list_for_each_entry(task, &clnt->cl_tasks, tk_task) {
if (!header) {
rpc_show_header();
header++;
}
-
- if (t->tk_msg.rpc_proc)
- proc = t->tk_msg.rpc_proc->p_proc;
- else
- proc = -1;
-
- if (RPC_IS_QUEUED(t))
- rpc_waitq = rpc_qname(t->tk_waitqueue);
-
- printk("%5u %04d %04x %6d %8p %6d %8p %8ld %8s %8p %8p\n",
- t->tk_pid, proc,
- t->tk_flags, t->tk_status,
- t->tk_client,
- (t->tk_client ? t->tk_client->cl_prog : 0),
- t->tk_rqstp, t->tk_timeout,
- rpc_waitq,
- t->tk_action, t->tk_ops);
+ rpc_show_task(clnt, task);
}
spin_unlock(&clnt->cl_lock);
}


2008-05-21 19:16:06

by J. Bruce Fields

[permalink] [raw]
Subject: Re: [PATCH 0/6] Initial set of 2.6.27 patches, take 3

On Wed, May 21, 2008 at 02:15:33PM -0400, Chuck Lever wrote:
> Hi Trond-
>
> Resending the first batch of 2.6.27 patches, with additional fixes.
>
> Using the RPC procedure name in debugging messages should no longer add a
> risk of a segmentation fault.
>
> I've also done a third re-implementation of the tk_action function name
> patch. I finally managed to find an interface that will perform the symbol
> table lookup, and can be called from a module or from built-in code.
>
> Oddly this API has been around for a while; I'm not sure how I missed it
> originally. But it should implement the nice function-name-rather-than-
> memory-address feature without a wonky table, and without requiring any
> additional changes when adding a new FSM state function. It will display
> the function name if the lookup succeeds; otherwise it will display a hex
> memory address. It works for any arbitrary pointer stored in the
> tk_action field.

Neat-o.--b.

>
> I've thought of a couple of other ways rpc_show_tasks() could be improved.
> First, it could display the IP address of the server handling each request;
> and it should have a different column layout for systems with 64-bit
> addresses. All for another day, I suppose.
>
> ---
>
> Chuck Lever (6):
> SUNRPC: Display some debugging information as text rather than numbers
> SUNRPC: Refactor rpc_show_tasks
> SUNRPC: Don't display the rpc_show_tasks header if there are no tasks
> SUNRPC: Rename "call_" functions that are no longer FSM states
> SUNRPC: Add a function to display the name of an RPC procedure
> NFS: Update help text for CONFIG_NFS_FS
>
>
> fs/Kconfig | 115 ++++++++++++++++++++++++-------------------------
> net/sunrpc/clnt.c | 124 ++++++++++++++++++++++++++++++-----------------------
> 2 files changed, 128 insertions(+), 111 deletions(-)
>
> --
> Signature
> --
> To unsubscribe from this list: send the line "unsubscribe linux-nfs" in
> the body of a message to [email protected]
> More majordomo info at http://vger.kernel.org/majordomo-info.html

2008-05-21 19:50:43

by J. Bruce Fields

[permalink] [raw]
Subject: Re: [PATCH 6/6] SUNRPC: Display some debugging information as text rather than numbers

On Wed, May 21, 2008 at 02:16:20PM -0400, Chuck Lever wrote:
> In rpc_show_tasks(), display the program name, version number, proced=
ure
> name and tk_action as human-readable variable-length text fields rath=
er
> than columnar numbers.
>=20
> Doing the symbol lookup here helps in cases where we have actual
> debugging output from a kernel log, but don't have access to the kern=
el
> image or RPC module that generated the output.
>=20
> Sample output:
>=20
> -pid- flgs status -client- --rqstp- -timeout ---ops--
> 5608 0001 -11 eeb42690 f6d93710 0 f8fa1764 nfsv3 WRITE a:=
call_transmit_status q:none
> 5609 0001 -11 eeb42690 f6d937e0 0 f8fa1764 nfsv3 WRITE a:=
call_status q:xprt_sending
> 5610 0001 -11 eeb42690 f6d93230 0 f8fa1764 nfsv3 WRITE a:=
call_status q:xprt_sending
> 5611 0001 -11 eeb42690 f6d93300 0 f8fa1764 nfsv3 WRITE a:=
call_status q:xprt_sending
> 5612 0001 -11 eeb42690 f6d93090 0 f8fa1764 nfsv3 WRITE a:=
call_status q:xprt_sending
> 5613 0001 -11 eeb42690 f6d933d0 0 f8fa1764 nfsv3 WRITE a:=
call_status q:xprt_sending
> 5614 0001 -11 eeb42690 f6d93cc0 0 f8fa1764 nfsv3 WRITE a:=
call_status q:xprt_sending
> 5615 0001 -11 eeb42690 f6d93a50 0 f8fa1764 nfsv3 WRITE a:=
call_status q:xprt_sending
> 5616 0001 -11 eeb42690 f6d93640 0 f8fa1764 nfsv3 WRITE a:=
call_status q:xprt_sending
> 5617 0001 -11 eeb42690 f6d93b20 0 f8fa1764 nfsv3 WRITE a:=
call_status q:xprt_sending
> 5618 0001 -11 eeb42690 f6d93160 0 f8fa1764 nfsv3 WRITE a:=
call_status q:xprt_sending
>=20
> Signed-off-by: Chuck Lever <[email protected]>
> ---
>=20
> net/sunrpc/clnt.c | 29 ++++++++++++++++-------------
> 1 files changed, 16 insertions(+), 13 deletions(-)
>=20
>=20
> diff --git a/net/sunrpc/clnt.c b/net/sunrpc/clnt.c
> index 68b08d4..878752c 100644
> --- a/net/sunrpc/clnt.c
> +++ b/net/sunrpc/clnt.c
> @@ -25,6 +25,7 @@
> =20
> #include <linux/module.h>
> #include <linux/types.h>
> +#include <linux/kallsyms.h>
> #include <linux/mm.h>
> #include <linux/slab.h>
> #include <linux/smp_lock.h>
> @@ -1527,29 +1528,31 @@ EXPORT_SYMBOL_GPL(rpc_call_null);
> #ifdef RPC_DEBUG
> static void rpc_show_header(void)
> {
> - printk(KERN_INFO "-pid- proc flgs status -client- -prog- --rqstp- "
> - "-timeout -rpcwait -action- ---ops--\n");
> + printk(KERN_INFO "-pid- flgs status -client- --rqstp- "
> + "-timeout ---ops--\n");
> }
> =20
> static void rpc_show_task(const struct rpc_clnt *clnt,
> const struct rpc_task *task)
> {
> const char *rpc_waitq =3D "none";
> - int proc =3D -1;
> -
> - if (task->tk_msg.rpc_proc)
> - proc =3D task->tk_msg.rpc_proc->p_proc;
> + char *p, action[KSYM_SYMBOL_LEN];
> =20
> if (RPC_IS_QUEUED(task))
> rpc_waitq =3D rpc_qname(task->tk_waitqueue);
> =20
> - printk(KERN_INFO "%5u %04d %04x %6d %8p %6d %8p %8ld %8s %8p %8p\n"=
,
> - task->tk_pid, proc,
> - task->tk_flags, task->tk_status,
> - clnt, clnt->cl_prog,
> - task->tk_rqstp, task->tk_timeout,
> - rpc_waitq,
> - task->tk_action, task->tk_ops);
> + /* map tk_action pointer to a function name; then trim off
> + * the "+0x0 [sunrpc]" */
> + sprint_symbol(action, (unsigned long)task->tk_action);
> + p =3D strchr(action, '+');
> + if (p)
> + *p =3D '\0';
> +
> + printk(KERN_INFO "%5u %04x %6d %8p %8p %8ld %8p %sv%u %s a:%s q:%s\=
n",
> + task->tk_pid, task->tk_flags, task->tk_status,
> + clnt, task->tk_rqstp, task->tk_timeout, task->tk_ops,
> + clnt->cl_protname, clnt->cl_vers, rpc_proc_name(task),
> + action, queue);

"net/sunrpc/clnt.c: In function =E2=80=98rpc_show_task=E2=80=99:
net/sunrpc/clnt.c:1555: error: =E2=80=98queue=E2=80=99 undeclared (fir=
st use in this function)
net/sunrpc/clnt.c:1555: error: (Each undeclared identifier is reported=
only once
net/sunrpc/clnt.c:1555: error: for each function it appears in.)"

Is that last "queue" supposed to be "rpc_waitq"???

--b.

> }
> =20
> void rpc_show_tasks(void)
>=20
> --
> To unsubscribe from this list: send the line "unsubscribe linux-nfs" =
in
> the body of a message to [email protected]
> More majordomo info at http://vger.kernel.org/majordomo-info.html

2008-05-21 20:38:52

by Chuck Lever

[permalink] [raw]
Subject: Re: [PATCH 6/6] SUNRPC: Display some debugging information as text rather than numbers


On May 21, 2008, at 3:50 PM, J. Bruce Fields wrote:

> On Wed, May 21, 2008 at 02:16:20PM -0400, Chuck Lever wrote:
>> In rpc_show_tasks(), display the program name, version number, =20
>> procedure
>> name and tk_action as human-readable variable-length text fields =20
>> rather
>> than columnar numbers.
>>
>> Doing the symbol lookup here helps in cases where we have actual
>> debugging output from a kernel log, but don't have access to the =20
>> kernel
>> image or RPC module that generated the output.
>>
>> Sample output:
>>
>> -pid- flgs status -client- --rqstp- -timeout ---ops--
>> 5608 0001 -11 eeb42690 f6d93710 0 f8fa1764 nfsv3 WRITE =20
>> a:call_transmit_status q:none
>> 5609 0001 -11 eeb42690 f6d937e0 0 f8fa1764 nfsv3 WRITE =20
>> a:call_status q:xprt_sending
>> 5610 0001 -11 eeb42690 f6d93230 0 f8fa1764 nfsv3 WRITE =20
>> a:call_status q:xprt_sending
>> 5611 0001 -11 eeb42690 f6d93300 0 f8fa1764 nfsv3 WRITE =20
>> a:call_status q:xprt_sending
>> 5612 0001 -11 eeb42690 f6d93090 0 f8fa1764 nfsv3 WRITE =20
>> a:call_status q:xprt_sending
>> 5613 0001 -11 eeb42690 f6d933d0 0 f8fa1764 nfsv3 WRITE =20
>> a:call_status q:xprt_sending
>> 5614 0001 -11 eeb42690 f6d93cc0 0 f8fa1764 nfsv3 WRITE =20
>> a:call_status q:xprt_sending
>> 5615 0001 -11 eeb42690 f6d93a50 0 f8fa1764 nfsv3 WRITE =20
>> a:call_status q:xprt_sending
>> 5616 0001 -11 eeb42690 f6d93640 0 f8fa1764 nfsv3 WRITE =20
>> a:call_status q:xprt_sending
>> 5617 0001 -11 eeb42690 f6d93b20 0 f8fa1764 nfsv3 WRITE =20
>> a:call_status q:xprt_sending
>> 5618 0001 -11 eeb42690 f6d93160 0 f8fa1764 nfsv3 WRITE =20
>> a:call_status q:xprt_sending
>>
>> Signed-off-by: Chuck Lever <[email protected]>
>> ---
>>
>> net/sunrpc/clnt.c | 29 ++++++++++++++++-------------
>> 1 files changed, 16 insertions(+), 13 deletions(-)
>>
>>
>> diff --git a/net/sunrpc/clnt.c b/net/sunrpc/clnt.c
>> index 68b08d4..878752c 100644
>> --- a/net/sunrpc/clnt.c
>> +++ b/net/sunrpc/clnt.c
>> @@ -25,6 +25,7 @@
>>
>> #include <linux/module.h>
>> #include <linux/types.h>
>> +#include <linux/kallsyms.h>
>> #include <linux/mm.h>
>> #include <linux/slab.h>
>> #include <linux/smp_lock.h>
>> @@ -1527,29 +1528,31 @@ EXPORT_SYMBOL_GPL(rpc_call_null);
>> #ifdef RPC_DEBUG
>> static void rpc_show_header(void)
>> {
>> - printk(KERN_INFO "-pid- proc flgs status -client- -prog- --rqstp- =
"
>> - "-timeout -rpcwait -action- ---ops--\n");
>> + printk(KERN_INFO "-pid- flgs status -client- --rqstp- "
>> + "-timeout ---ops--\n");
>> }
>>
>> static void rpc_show_task(const struct rpc_clnt *clnt,
>> const struct rpc_task *task)
>> {
>> const char *rpc_waitq =3D "none";
>> - int proc =3D -1;
>> -
>> - if (task->tk_msg.rpc_proc)
>> - proc =3D task->tk_msg.rpc_proc->p_proc;
>> + char *p, action[KSYM_SYMBOL_LEN];
>>
>> if (RPC_IS_QUEUED(task))
>> rpc_waitq =3D rpc_qname(task->tk_waitqueue);
>>
>> - printk(KERN_INFO "%5u %04d %04x %6d %8p %6d %8p %8ld %8s %8p %8p=20
>> \n",
>> - task->tk_pid, proc,
>> - task->tk_flags, task->tk_status,
>> - clnt, clnt->cl_prog,
>> - task->tk_rqstp, task->tk_timeout,
>> - rpc_waitq,
>> - task->tk_action, task->tk_ops);
>> + /* map tk_action pointer to a function name; then trim off
>> + * the "+0x0 [sunrpc]" */
>> + sprint_symbol(action, (unsigned long)task->tk_action);
>> + p =3D strchr(action, '+');
>> + if (p)
>> + *p =3D '\0';
>> +
>> + printk(KERN_INFO "%5u %04x %6d %8p %8p %8ld %8p %sv%u %s a:%s q:%s=
=20
>> \n",
>> + task->tk_pid, task->tk_flags, task->tk_status,
>> + clnt, task->tk_rqstp, task->tk_timeout, task->tk_ops,
>> + clnt->cl_protname, clnt->cl_vers, rpc_proc_name(task),
>> + action, queue);
>
> "net/sunrpc/clnt.c: In function =91rpc_show_task=92:
> net/sunrpc/clnt.c:1555: error: =91queue=92 undeclared (first use in t=
his =20
> function)
> net/sunrpc/clnt.c:1555: error: (Each undeclared identifier is =20
> reported only once
> net/sunrpc/clnt.c:1555: error: for each function it appears in.)"
>
> Is that last "queue" supposed to be "rpc_waitq"???

Yes... I fixed that already... was that in the version I sent out this =
=20
afternoon?

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

2008-05-21 20:40:38

by Myklebust, Trond

[permalink] [raw]
Subject: Re: [PATCH 6/6] SUNRPC: Display some debugging information as text rather than numbers

On Wed, 2008-05-21 at 16:37 -0400, Chuck Lever wrote:
> >> + task->tk_pid, task->tk_flags, task->tk_status,
> >> + clnt, task->tk_rqstp, task->tk_timeout, task->tk_ops,
> >> + clnt->cl_protname, clnt->cl_vers, rpc_proc_name(task),
> >> + action, queue);
> >
> > "net/sunrpc/clnt.c: In function =E2=80=98rpc_show_task=E2=80=99:
> > net/sunrpc/clnt.c:1555: error: =E2=80=98queue=E2=80=99 undeclared (=
first use in this =20
> > function)
> > net/sunrpc/clnt.c:1555: error: (Each undeclared identifier is =20
> > reported only once
> > net/sunrpc/clnt.c:1555: error: for each function it appears in.)"
> >
> > Is that last "queue" supposed to be "rpc_waitq"???
>=20
> Yes... I fixed that already... was that in the version I sent out thi=
s =20
> afternoon?

Yep. Shall I fix it up, or do you want to resend?

--=20
Trond Myklebust
Linux NFS client maintainer

NetApp
[email protected]
http://www.netapp.com

2008-05-21 20:42:38

by J. Bruce Fields

[permalink] [raw]
Subject: Re: [PATCH 6/6] SUNRPC: Display some debugging information as text rather than numbers

On Wed, May 21, 2008 at 04:37:23PM -0400, Chuck Lever wrote:
>
> On May 21, 2008, at 3:50 PM, J. Bruce Fields wrote:
>
>> On Wed, May 21, 2008 at 02:16:20PM -0400, Chuck Lever wrote:
=2E..
>>> + printk(KERN_INFO "%5u %04x %6d %8p %8p %8ld %8p %sv%u %s a:%s q:%=
s=20
>>> \n",
>>> + task->tk_pid, task->tk_flags, task->tk_status,
>>> + clnt, task->tk_rqstp, task->tk_timeout, task->tk_ops,
>>> + clnt->cl_protname, clnt->cl_vers, rpc_proc_name(task),
>>> + action, queue);
>>
>> "net/sunrpc/clnt.c: In function =E2=80=98rpc_show_task=E2=80=99:
>> net/sunrpc/clnt.c:1555: error: =E2=80=98queue=E2=80=99 undeclared (f=
irst use in this =20
>> function)
>> net/sunrpc/clnt.c:1555: error: (Each undeclared identifier is report=
ed=20
>> only once
>> net/sunrpc/clnt.c:1555: error: for each function it appears in.)"
>>
>> Is that last "queue" supposed to be "rpc_waitq"???
>
> Yes... I fixed that already... was that in the version I sent out thi=
s =20
> afternoon?

Yup. See the attribution above, or the "In-Reply-To" header, or
http://marc.info/?l=3Dlinux-nfs&m=3D121139389532042&w=3D2.

--b.

2008-05-21 20:58:15

by Chuck Lever

[permalink] [raw]
Subject: Re: [PATCH 6/6] SUNRPC: Display some debugging information as text rather than numbers

On May 21, 2008, at 4:42 PM, J. Bruce Fields wrote:
> On Wed, May 21, 2008 at 04:37:23PM -0400, Chuck Lever wrote:
>>
>> On May 21, 2008, at 3:50 PM, J. Bruce Fields wrote:
>>
>>> On Wed, May 21, 2008 at 02:16:20PM -0400, Chuck Lever wrote:
> ...
>>>> + printk(KERN_INFO "%5u %04x %6d %8p %8p %8ld %8p %sv%u %s a:%s q:=
=20
>>>> %s
>>>> \n",
>>>> + task->tk_pid, task->tk_flags, task->tk_status,
>>>> + clnt, task->tk_rqstp, task->tk_timeout, task->tk_ops,
>>>> + clnt->cl_protname, clnt->cl_vers, rpc_proc_name(task),
>>>> + action, queue);
>>>
>>> "net/sunrpc/clnt.c: In function =91rpc_show_task=92:
>>> net/sunrpc/clnt.c:1555: error: =91queue=92 undeclared (first use in=
this
>>> function)
>>> net/sunrpc/clnt.c:1555: error: (Each undeclared identifier is =20
>>> reported
>>> only once
>>> net/sunrpc/clnt.c:1555: error: for each function it appears in.)"
>>>
>>> Is that last "queue" supposed to be "rpc_waitq"???
>>
>> Yes... I fixed that already... was that in the version I sent out =20
>> this
>> afternoon?
>
> Yup. See the attribution above, or the "In-Reply-To" header, or
> http://marc.info/?l=3Dlinux-nfs&m=3D121139389532042&w=3D2.

That's exceedingly odd. I mailed these out *after* I had build-tested =
=20
and run against ying2 this afternoon.

I will send another set.

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