NFSD: Wrap async copy operations with trace points

Add an nfsd_copy_async_done to record the timestamp, the final
status code, and the callback stateid of an async copy.

Rename the nfsd_copy_do_async tracepoint to match that naming
convention to make it easier to enable both of these with a
single glob.

Reviewed-by: Jeff Layton <jlayton@kernel.org>
Signed-off-by: Chuck Lever <chuck.lever@oracle.com>

diff --git a/fs/nfsd/nfs4proc.c b/fs/nfsd/nfs4proc.c
index 9655acb407b728bfe7318139f79909b104e13b5f..b5a6bf4f459fb2309a0ccc9f585c5d6318ceedf1 100644 (file)
--- a/fs/nfsd/nfs4proc.c
+++ b/fs/nfsd/nfs4proc.c
@@ -1760,7 +1760,7 @@ static int nfsd4_do_async_copy(void *data)
 {
        struct nfsd4_copy *copy = (struct nfsd4_copy *)data;
 
-       trace_nfsd_copy_do_async(copy);
+       trace_nfsd_copy_async(copy);
        if (nfsd4_ssc_is_inter(copy)) {
                struct file *filp;
 
@@ -1787,6 +1787,7 @@ static int nfsd4_do_async_copy(void *data)
 
 do_callback:
        set_bit(NFSD4_COPY_F_COMPLETED, &copy->cp_flags);
+       trace_nfsd_copy_async_done(copy);
        nfsd4_send_cb_offload(copy);
        cleanup_async_copy(copy);
        return 0;

diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
index fe6716d9fad409d4472559238f84bb4fe4971623..7ab66497e26132abca8536ae5a861f595d04c69f 100644 (file)
--- a/fs/nfsd/trace.h
+++ b/fs/nfsd/trace.h
@@ -2203,7 +2203,7 @@ DEFINE_EVENT(nfsd_copy_class, nfsd_copy_##name,   \
 
 DEFINE_COPY_EVENT(inter);
 DEFINE_COPY_EVENT(intra);
-DEFINE_COPY_EVENT(do_async);
+DEFINE_COPY_EVENT(async);
 
 TRACE_EVENT(nfsd_copy_done,
        TP_PROTO(
@@ -2229,6 +2229,75 @@ TRACE_EVENT(nfsd_copy_done,
        )
 );
 
+TRACE_EVENT(nfsd_copy_async_done,
+       TP_PROTO(
+               const struct nfsd4_copy *copy
+       ),
+       TP_ARGS(copy),
+       TP_STRUCT__entry(
+               __field(int, status)
+               __field(bool, intra)
+               __field(bool, async)
+               __field(u32, src_cl_boot)
+               __field(u32, src_cl_id)
+               __field(u32, src_so_id)
+               __field(u32, src_si_generation)
+               __field(u32, dst_cl_boot)
+               __field(u32, dst_cl_id)
+               __field(u32, dst_so_id)
+               __field(u32, dst_si_generation)
+               __field(u32, cb_cl_boot)
+               __field(u32, cb_cl_id)
+               __field(u32, cb_so_id)
+               __field(u32, cb_si_generation)
+               __field(u64, src_cp_pos)
+               __field(u64, dst_cp_pos)
+               __field(u64, cp_count)
+               __sockaddr(addr, sizeof(struct sockaddr_in6))
+       ),
+       TP_fast_assign(
+               const stateid_t *src_stp = &copy->cp_src_stateid;
+               const stateid_t *dst_stp = &copy->cp_dst_stateid;
+               const stateid_t *cb_stp = &copy->cp_res.cb_stateid;
+
+               __entry->status = be32_to_cpu(copy->nfserr);
+               __entry->intra = test_bit(NFSD4_COPY_F_INTRA, &copy->cp_flags);
+               __entry->async = !test_bit(NFSD4_COPY_F_SYNCHRONOUS, &copy->cp_flags);
+               __entry->src_cl_boot = src_stp->si_opaque.so_clid.cl_boot;
+               __entry->src_cl_id = src_stp->si_opaque.so_clid.cl_id;
+               __entry->src_so_id = src_stp->si_opaque.so_id;
+               __entry->src_si_generation = src_stp->si_generation;
+               __entry->dst_cl_boot = dst_stp->si_opaque.so_clid.cl_boot;
+               __entry->dst_cl_id = dst_stp->si_opaque.so_clid.cl_id;
+               __entry->dst_so_id = dst_stp->si_opaque.so_id;
+               __entry->dst_si_generation = dst_stp->si_generation;
+               __entry->cb_cl_boot = cb_stp->si_opaque.so_clid.cl_boot;
+               __entry->cb_cl_id = cb_stp->si_opaque.so_clid.cl_id;
+               __entry->cb_so_id = cb_stp->si_opaque.so_id;
+               __entry->cb_si_generation = cb_stp->si_generation;
+               __entry->src_cp_pos = copy->cp_src_pos;
+               __entry->dst_cp_pos = copy->cp_dst_pos;
+               __entry->cp_count = copy->cp_count;
+               __assign_sockaddr(addr, &copy->cp_clp->cl_addr,
+                               sizeof(struct sockaddr_in6));
+       ),
+       TP_printk("client=%pISpc status=%d intra=%d async=%d "
+               "src_client %08x:%08x src_stateid %08x:%08x "
+               "dst_client %08x:%08x dst_stateid %08x:%08x "
+               "cb_client %08x:%08x cb_stateid %08x:%08x "
+               "cp_src_pos=%llu cp_dst_pos=%llu cp_count=%llu",
+               __get_sockaddr(addr),
+               __entry->status, __entry->intra, __entry->async,
+               __entry->src_cl_boot, __entry->src_cl_id,
+               __entry->src_so_id, __entry->src_si_generation,
+               __entry->dst_cl_boot, __entry->dst_cl_id,
+               __entry->dst_so_id, __entry->dst_si_generation,
+               __entry->cb_cl_boot, __entry->cb_cl_id,
+               __entry->cb_so_id, __entry->cb_si_generation,
+               __entry->src_cp_pos, __entry->dst_cp_pos, __entry->cp_count
+       )
+);
+
 #endif /* _NFSD_TRACE_H */
 
 #undef TRACE_INCLUDE_PATH