Age | Commit message (Collapse) | Author | Files | Lines |
|
Dropping and/or deferring requests has an impact on performance. Let's
make sure we can trace those events.
Signed-off-by: Trond Myklebust <trond.myklebust@primarydata.com>
Signed-off-by: J. Bruce Fields <bfields@redhat.com>
|
|
Add a tracepoint to track when the processing of incoming RPC data gets
deferred due to out-of-space issues on the outgoing transport.
Signed-off-by: Trond Myklebust <trond.myklebust@primarydata.com>
Signed-off-by: J. Bruce Fields <bfields@redhat.com>
|
|
We're always tracing IPv4 or IPv6 addresses, so we can save a lot
of space on the ringbuffer by allocating the correct sockaddr size.
Signed-off-by: Trond Myklebust <trond.myklebust@primarydata.com>
Cc: stable@vger.kernel.org
Fixes: 83a712e0afef "sunrpc: add some tracepoints around ..."
Signed-off-by: J. Bruce Fields <bfields@redhat.com>
|
|
`perf stat -e sunrpc:svc_xprt_do_enqueue true` results in
Warning: unknown op '->'
Warning: [sunrpc:svc_xprt_do_enqueue] unknown op '->'
Similar warning for svc_handle_xprt as well.
Actually TP_printk() should never dereference an address saved in the ring
buffer that points somewhere in the kernel. There's no guarantee that that
object still exists (with the exception of static strings).
Therefore change all the arguments for TP_printk(), so that it references
values existing in the ring buffer only.
While doing that, also fix another possible bug when argument xprt could be
NULL and TP_fast_assign() tries to access it's elements.
Signed-off-by: Pratyush Anand <panand@redhat.com>
Reviewed-by: Jeff Layton <jeff.layton@primarydata.com>
Acked-by: Steven Rostedt <rostedt@goodmis.org>
Cc: stable@vger.kernel.org
Fixes: 83a712e0afef "sunrpc: add some tracepoints around ..."
Signed-off-by: J. Bruce Fields <bfields@redhat.com>
|
|
The enums used in the tracepoints for __print_symbolic() have their
names shown in the tracepoint format files. User space tools do not know
how to convert those names into their values to be able to convert the
binary data.
Use TRACE_DEFINE_ENUM() to export the enum names to their values for
userspace to do the parsing correctly.
Link: http://lkml.kernel.org/r/20150403013802.220157513@goodmis.org
Acked-by: Trond Myklebust <trond.myklebust@primarydata.com>
Reviewed-by: Masami Hiramatsu <masami.hiramatsu.pt@hitachi.com>
Tested-by: Masami Hiramatsu <masami.hiramatsu.pt@hitachi.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
|
|
These were useful when I was tracking down a race condition between
svc_xprt_do_enqueue and svc_get_next_xprt.
Signed-off-by: Jeff Layton <jlayton@primarydata.com>
Signed-off-by: J. Bruce Fields <bfields@redhat.com>
|
|
Testing has shown that the pool->sp_lock can be a bottleneck on a busy
server. Every time data is received on a socket, the server must take
that lock in order to dequeue a thread from the sp_threads list.
Address this problem by eliminating the sp_threads list (which contains
threads that are currently idle) and replacing it with a RQ_BUSY flag in
svc_rqst. This allows us to walk the sp_all_threads list under the
rcu_read_lock and find a suitable thread for the xprt by doing a
test_and_set_bit.
Note that we do still have a potential atomicity problem however with
this approach. We don't want svc_xprt_do_enqueue to set the
rqst->rq_xprt pointer unless a test_and_set_bit of RQ_BUSY returned
zero (which indicates that the thread was idle). But, by the time we
check that, the bit could be flipped by a waking thread.
To address this, we acquire a new per-rqst spinlock (rq_lock) and take
that before doing the test_and_set_bit. If that returns false, then we
can set rq_xprt and drop the spinlock. Then, when the thread wakes up,
it must set the bit under the same spinlock and can trust that if it was
already set then the rq_xprt is also properly set.
With this scheme, the case where we have an idle thread no longer needs
to take the highly contended pool->sp_lock at all, and that removes the
bottleneck.
That still leaves one issue: What of the case where we walk the whole
sp_all_threads list and don't find an idle thread? Because the search is
lockess, it's possible for the queueing to race with a thread that is
going to sleep. To address that, we queue the xprt and then search again.
If we find an idle thread at that point, we can't attach the xprt to it
directly since that might race with a different thread waking up and
finding it. All we can do is wake the idle thread back up and let it
attempt to find the now-queued xprt.
Signed-off-by: Jeff Layton <jlayton@primarydata.com>
Tested-by: Chris Worley <chris.worley@primarydata.com>
Signed-off-by: J. Bruce Fields <bfields@redhat.com>
|
|
...also make the manipulation of sp_all_threads list use RCU-friendly
functions.
Signed-off-by: Jeff Layton <jlayton@primarydata.com>
Tested-by: Chris Worley <chris.worley@primarydata.com>
Signed-off-by: J. Bruce Fields <bfields@redhat.com>
|
|
Signed-off-by: Jeff Layton <jlayton@primarydata.com>
Signed-off-by: J. Bruce Fields <bfields@redhat.com>
|
|
Signed-off-by: Jeff Layton <jlayton@primarydata.com>
Signed-off-by: J. Bruce Fields <bfields@redhat.com>
|
|
Signed-off-by: Jeff Layton <jlayton@primarydata.com>
Signed-off-by: J. Bruce Fields <bfields@redhat.com>
|
|
Signed-off-by: Jeff Layton <jlayton@primarydata.com>
Signed-off-by: J. Bruce Fields <bfields@redhat.com>
|
|
In a later patch, we're going to need some atomic bit flags. Since that
field will need to be an unsigned long, we mitigate that space
consumption by migrating some other bitflags to the new field. Start
with the rq_secure flag.
Signed-off-by: Jeff Layton <jlayton@primarydata.com>
Signed-off-by: J. Bruce Fields <bfields@redhat.com>
|
|
Add tracepoints inside the main loop on xs_tcp_data_recv that allow
us to keep an eye on what's happening during each phase of it.
Signed-off-by: Jeff Layton <jlayton@primarydata.com>
Signed-off-by: Trond Myklebust <trond.myklebust@primarydata.com>
|
|
...so we can keep track of when calls are sent and replies received.
Signed-off-by: Jeff Layton <jlayton@primarydata.com>
Signed-off-by: Trond Myklebust <trond.myklebust@primarydata.com>
|
|
...just around svc_send, svc_recv and svc_process for now.
Signed-off-by: Jeff Layton <jlayton@primarydata.com>
Signed-off-by: Trond Myklebust <trond.myklebust@primarydata.com>
|
|
When tracking sunrpc_task events in nfs client, the clnt pointer may be NULL.
[ 139.269266] BUG: unable to handle kernel NULL pointer dereference at 0000000000000004
[ 139.269915] IP: [<ffffffffa026f216>] ftrace_raw_event_rpc_task_running+0x86/0xf0 [sunrpc]
[ 139.269915] PGD 1d293067 PUD 1d294067 PMD 0
[ 139.269915] Oops: 0000 [#1] SMP
[ 139.269915] Modules linked in: nfsv4 dns_resolver nfs lockd sunrpc fscache sg ppdev e1000
serio_raw pcspkr parport_pc parport i2c_piix4 i2c_core microcode xfs libcrc32c sd_mod sr_mod
cdrom ata_generic crc_t10dif crct10dif_common pata_acpi ahci libahci ata_piix libata dm_mirror
dm_region_hash dm_log dm_mod
[ 139.269915] CPU: 0 PID: 59 Comm: kworker/0:2 Not tainted 3.10.0-84.el7.x86_64 #1
[ 139.269915] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
[ 139.269915] Workqueue: rpciod rpc_async_schedule [sunrpc]
[ 139.269915] task: ffff88001b598000 ti: ffff88001b632000 task.ti: ffff88001b632000
[ 139.269915] RIP: 0010:[<ffffffffa026f216>] [<ffffffffa026f216>] ftrace_raw_event_rpc_task_running+0x86/0xf0 [sunrpc]
[ 139.269915] RSP: 0018:ffff88001b633d70 EFLAGS: 00010206
[ 139.269915] RAX: ffff88001dfc5338 RBX: ffff88001cc37a00 RCX: ffff88001dfc5334
[ 139.269915] RDX: ffff88001dfc5338 RSI: 0000000000000000 RDI: ffff88001dfc533c
[ 139.269915] RBP: ffff88001b633db0 R08: 000000000000002c R09: 000000000000000a
[ 139.269915] R10: 0000000000062180 R11: 00000020759fb9dc R12: ffffffffa0292c20
[ 139.269915] R13: ffff88001dfc5334 R14: 0000000000000000 R15: 0000000000000000
[ 139.269915] FS: 0000000000000000(0000) GS:ffff88001fc00000(0000) knlGS:0000000000000000
[ 139.269915] CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 139.269915] CR2: 0000000000000004 CR3: 000000001d290000 CR4: 00000000000006f0
[ 139.269915] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 139.269915] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[ 139.269915] Stack:
[ 139.269915] 000000001b633d98 0000000000000246 ffff88001df1dc00 ffff88001cc37a00
[ 139.269915] ffff88001bc35e60 0000000000000000 ffff88001ffa0a48 ffff88001bc35ee0
[ 139.269915] ffff88001b633e08 ffffffffa02704b5 0000000000010000 ffff88001cc37a70
[ 139.269915] Call Trace:
[ 139.269915] [<ffffffffa02704b5>] __rpc_execute+0x1d5/0x400 [sunrpc]
[ 139.269915] [<ffffffffa0270706>] rpc_async_schedule+0x26/0x30 [sunrpc]
[ 139.269915] [<ffffffff8107867b>] process_one_work+0x17b/0x460
[ 139.269915] [<ffffffff8107942b>] worker_thread+0x11b/0x400
[ 139.269915] [<ffffffff81079310>] ? rescuer_thread+0x3e0/0x3e0
[ 139.269915] [<ffffffff8107fc80>] kthread+0xc0/0xd0
[ 139.269915] [<ffffffff8107fbc0>] ? kthread_create_on_node+0x110/0x110
[ 139.269915] [<ffffffff815d122c>] ret_from_fork+0x7c/0xb0
[ 139.269915] [<ffffffff8107fbc0>] ? kthread_create_on_node+0x110/0x110
[ 139.269915] Code: 4c 8b 45 c8 48 8d 7d d0 89 4d c4 41 89 c9 b9 28 00 00 00 e8 9d b4 e9
e0 48 85 c0 49 89 c5 74 a2 48 89 c7 e8 9d 3f e9 e0 48 89 c2 <41> 8b 46 04 48 8b 7d d0 4c
89 e9 4c 89 e6 89 42 0c 0f b7 83 d4
[ 139.269915] RIP [<ffffffffa026f216>] ftrace_raw_event_rpc_task_running+0x86/0xf0 [sunrpc]
[ 139.269915] RSP <ffff88001b633d70>
[ 139.269915] CR2: 0000000000000004
[ 140.946406] ---[ end trace ba486328b98d7622 ]---
Signed-off-by: Ditang Chen <chendt.fnst@cn.fujitsu.com>
Signed-off-by: Trond Myklebust <trond.myklebust@primarydata.com>
|
|
Signed-off-by: Trond Myklebust <trond.myklebust@primarydata.com>
|
|
Instead of the pointer values, use the task and client identifier values
for tracing purposes.
Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com>
|
|
Add client side debugging to help trace socket connection/disconnection
and unexpected state change issues.
Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com>
|
|
This patch adds three trace points to the status routines
in the sunrpc state machine.
The goal of these trace points is to give an Admin
the ability to check on binding status or connection
status to see if there is a potential problem.
Signed-off-by: Steve Dickson <steved@redhat.com>
Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com>
|
|
The reporting of the RPC queue name needs to use the __string()
event interface.
Reported-by: Neil Horman <nhorman@redhat.com>
Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com>
|
|
Add declarations to allow tracing of RPC call creation, running, sleeping,
and destruction.
Signed-off-by: Trond Myklebust <Trond.Myklebust@netapp.com>
|