Commit 77b4d2c6 authored by David Howells's avatar David Howells
Browse files

netfs: Add tracepoints 



Add three tracepoints to track the activity of the read helpers:

 (1) netfs/netfs_read

     This logs entry to the read helpers and also expansion of the range in
     a readahead request.

 (2) netfs/netfs_rreq

     This logs the progress of netfs_read_request objects which track
     read requests.  A read request may be a compound of multiple
     subrequests.

 (3) netfs/netfs_sreq

     This logs the progress of netfs_read_subrequest objects, which track
     the contributions from various sources to a read request.

Signed-off-by: default avatarDavid Howells <dhowells@redhat.com>
Reviewed-and-tested-by: default avatarJeff Layton <jlayton@kernel.org>
Tested-by: default avatarDave Wysochanski <dwysocha@redhat.com>
Tested-By: default avatarMarc Dionne <marc.dionne@auristor.com>
cc: Matthew Wilcox <willy@infradead.org>
cc: linux-mm@kvack.org
cc: linux-cachefs@redhat.com
cc: linux-afs@lists.infradead.org
cc: linux-nfs@vger.kernel.org
cc: linux-cifs@vger.kernel.org
cc: ceph-devel@vger.kernel.org
cc: v9fs-developer@lists.sourceforge.net
cc: linux-fsdevel@vger.kernel.org
Link: https://lore.kernel.org/r/161118138060.1232039.5353374588021776217.stgit@warthog.procyon.org.uk/ # rfc
Link: https://lore.kernel.org/r/161161033468.2537118.14021843889844001905.stgit@warthog.procyon.org.uk/ # v2
Link: https://lore.kernel.org/r/161340395843.1303470.7355519662919639648.stgit@warthog.procyon.org.uk/ # v3
Link: https://lore.kernel.org/r/161539538693.286939.10171713520419106334.stgit@warthog.procyon.org.uk/ # v4
Link: https://lore.kernel.org/r/161653796447.2770958.1870655382450862155.stgit@warthog.procyon.org.uk/ # v5
Link: https://lore.kernel.org/r/161789078003.6155.17814844411672989942.stgit@warthog.procyon.org.uk/ # v6
parent 3d3c9504

fs/netfs/read_helper.c

+26 −0
Original line number Diff line number Diff line
@@ -16,6 +16,8 @@ 
#include <linux/task_io_accounting_ops.h>

#include <linux/netfs.h>

#include "internal.h"

#define CREATE_TRACE_POINTS

#include <trace/events/netfs.h>



MODULE_DESCRIPTION("Network fs support");

MODULE_AUTHOR("Red Hat, Inc.");
@@ -84,6 +86,7 @@ static void netfs_free_read_request(struct work_struct *work) 
	netfs_rreq_clear_subreqs(rreq, false);

	if (rreq->netfs_priv)

		rreq->netfs_ops->cleanup(rreq->mapping, rreq->netfs_priv);

	trace_netfs_rreq(rreq, netfs_rreq_trace_free);

	kfree(rreq);

}
@@ -129,6 +132,7 @@ static void __netfs_put_subrequest(struct netfs_read_subrequest *subreq, 
{

	struct netfs_read_request *rreq = subreq->rreq;



	trace_netfs_sreq(subreq, netfs_sreq_trace_free);

	kfree(subreq);

	netfs_put_read_request(rreq, was_async);

}
@@ -183,6 +187,7 @@ static void netfs_read_from_server(struct netfs_read_request *rreq, 
 */

static void netfs_rreq_completed(struct netfs_read_request *rreq, bool was_async)

{

	trace_netfs_rreq(rreq, netfs_rreq_trace_done);

	netfs_rreq_clear_subreqs(rreq, was_async);

	netfs_put_read_request(rreq, was_async);

}
@@ -221,6 +226,8 @@ static void netfs_rreq_unlock(struct netfs_read_request *rreq) 
	iopos = 0;

	subreq_failed = (subreq->error < 0);



	trace_netfs_rreq(rreq, netfs_rreq_trace_unlock);



	rcu_read_lock();

	xas_for_each(&xas, page, last_page) {

		unsigned int pgpos = (page->index - start_page) * PAGE_SIZE;
@@ -281,6 +288,8 @@ static void netfs_rreq_short_read(struct netfs_read_request *rreq, 
	__clear_bit(NETFS_SREQ_SHORT_READ, &subreq->flags);

	__set_bit(NETFS_SREQ_SEEK_DATA_READ, &subreq->flags);



	trace_netfs_sreq(subreq, netfs_sreq_trace_resubmit_short);



	netfs_get_read_subrequest(subreq);

	atomic_inc(&rreq->nr_rd_ops);

	netfs_read_from_server(rreq, subreq);
@@ -296,6 +305,8 @@ static bool netfs_rreq_perform_resubmissions(struct netfs_read_request *rreq) 


	WARN_ON(in_interrupt());



	trace_netfs_rreq(rreq, netfs_rreq_trace_resubmit);



	/* We don't want terminating submissions trying to wake us up whilst

	 * we're still going through the list.

	 */
@@ -308,6 +319,7 @@ static bool netfs_rreq_perform_resubmissions(struct netfs_read_request *rreq) 
				break;

			subreq->source = NETFS_DOWNLOAD_FROM_SERVER;

			subreq->error = 0;

			trace_netfs_sreq(subreq, netfs_sreq_trace_download_instead);

			netfs_get_read_subrequest(subreq);

			atomic_inc(&rreq->nr_rd_ops);

			netfs_read_from_server(rreq, subreq);
@@ -332,6 +344,8 @@ static bool netfs_rreq_perform_resubmissions(struct netfs_read_request *rreq) 
 */

static void netfs_rreq_assess(struct netfs_read_request *rreq, bool was_async)

{

	trace_netfs_rreq(rreq, netfs_rreq_trace_assess);



again:

	if (!test_bit(NETFS_RREQ_FAILED, &rreq->flags) &&

	    test_bit(NETFS_RREQ_INCOMPLETE_IO, &rreq->flags)) {
@@ -422,6 +436,8 @@ void netfs_subreq_terminated(struct netfs_read_subrequest *subreq, 
		set_bit(NETFS_RREQ_WRITE_TO_CACHE, &rreq->flags);



out:

	trace_netfs_sreq(subreq, netfs_sreq_trace_terminated);



	/* If we decrement nr_rd_ops to 0, the ref belongs to us. */

	u = atomic_dec_return(&rreq->nr_rd_ops);

	if (u == 0)
@@ -510,6 +526,7 @@ netfs_rreq_prepare_read(struct netfs_read_request *rreq, 


out:

	subreq->source = source;

	trace_netfs_sreq(subreq, netfs_sreq_trace_prepare);

	return source;

}
@@ -549,6 +566,7 @@ static bool netfs_rreq_submit_slice(struct netfs_read_request *rreq, 


	rreq->submitted += subreq->len;



	trace_netfs_sreq(subreq, netfs_sreq_trace_submit);

	switch (source) {

	case NETFS_FILL_WITH_ZEROES:

		netfs_fill_with_zeroes(rreq, subreq);
@@ -591,6 +609,9 @@ static void netfs_rreq_expand(struct netfs_read_request *rreq, 
		readahead_expand(ractl, rreq->start, rreq->len);

		rreq->start  = readahead_pos(ractl);

		rreq->len = readahead_length(ractl);



		trace_netfs_read(rreq, readahead_pos(ractl), readahead_length(ractl),

				 netfs_read_trace_expanded);

	}

}
@@ -632,6 +653,9 @@ void netfs_readahead(struct readahead_control *ractl, 
	rreq->start	= readahead_pos(ractl);

	rreq->len	= readahead_length(ractl);



	trace_netfs_read(rreq, readahead_pos(ractl), readahead_length(ractl),

			 netfs_read_trace_readahead);



	netfs_rreq_expand(rreq, ractl);



	atomic_set(&rreq->nr_rd_ops, 1);
@@ -698,6 +722,8 @@ int netfs_readpage(struct file *file, 
	rreq->start	= page_index(page) * PAGE_SIZE;

	rreq->len	= thp_size(page);



	trace_netfs_read(rreq, rreq->start, rreq->len, netfs_read_trace_readpage);



	netfs_get_read_request(rreq);



	atomic_set(&rreq->nr_rd_ops, 1);

include/linux/netfs.h

+1 −0
Original line number Diff line number Diff line
@@ -124,6 +124,7 @@ struct netfs_read_request { 
	struct list_head	subrequests;	/* Requests to fetch I/O from disk or net */

	void			*netfs_priv;	/* Private data for the netfs */

	unsigned int		debug_id;

	unsigned int		cookie_debug_id;

	atomic_t		nr_rd_ops;	/* Number of read ops in progress */

	size_t			submitted;	/* Amount submitted for I/O so far */

	size_t			len;		/* Length of the request */

include/trace/events/netfs.h

0 → 100644
+199 −0
Original line number Diff line number Diff line 
/* SPDX-License-Identifier: GPL-2.0-or-later */

/* Network filesystem support module tracepoints

 *

 * Copyright (C) 2021 Red Hat, Inc. All Rights Reserved.

 * Written by David Howells (dhowells@redhat.com)

 */

#undef TRACE_SYSTEM

#define TRACE_SYSTEM netfs



#if !defined(_TRACE_NETFS_H) || defined(TRACE_HEADER_MULTI_READ)

#define _TRACE_NETFS_H



#include <linux/tracepoint.h>



/*

 * Define enums for tracing information.

 */

#ifndef __NETFS_DECLARE_TRACE_ENUMS_ONCE_ONLY

#define __NETFS_DECLARE_TRACE_ENUMS_ONCE_ONLY



enum netfs_read_trace {

	netfs_read_trace_expanded,

	netfs_read_trace_readahead,

	netfs_read_trace_readpage,

};



enum netfs_rreq_trace {

	netfs_rreq_trace_assess,

	netfs_rreq_trace_done,

	netfs_rreq_trace_free,

	netfs_rreq_trace_resubmit,

	netfs_rreq_trace_unlock,

	netfs_rreq_trace_unmark,

	netfs_rreq_trace_write,

};



enum netfs_sreq_trace {

	netfs_sreq_trace_download_instead,

	netfs_sreq_trace_free,

	netfs_sreq_trace_prepare,

	netfs_sreq_trace_resubmit_short,

	netfs_sreq_trace_submit,

	netfs_sreq_trace_terminated,

	netfs_sreq_trace_write,

	netfs_sreq_trace_write_term,

};



#endif



#define netfs_read_traces					\

	EM(netfs_read_trace_expanded,		"EXPANDED ")	\

	EM(netfs_read_trace_readahead,		"READAHEAD")	\

	E_(netfs_read_trace_readpage,		"READPAGE ")



#define netfs_rreq_traces					\

	EM(netfs_rreq_trace_assess,		"ASSESS")	\

	EM(netfs_rreq_trace_done,		"DONE  ")	\

	EM(netfs_rreq_trace_free,		"FREE  ")	\

	EM(netfs_rreq_trace_resubmit,		"RESUBM")	\

	EM(netfs_rreq_trace_unlock,		"UNLOCK")	\

	EM(netfs_rreq_trace_unmark,		"UNMARK")	\

	E_(netfs_rreq_trace_write,		"WRITE ")



#define netfs_sreq_sources					\

	EM(NETFS_FILL_WITH_ZEROES,		"ZERO")		\

	EM(NETFS_DOWNLOAD_FROM_SERVER,		"DOWN")		\

	EM(NETFS_READ_FROM_CACHE,		"READ")		\

	E_(NETFS_INVALID_READ,			"INVL")		\



#define netfs_sreq_traces					\

	EM(netfs_sreq_trace_download_instead,	"RDOWN")	\

	EM(netfs_sreq_trace_free,		"FREE ")	\

	EM(netfs_sreq_trace_prepare,		"PREP ")	\

	EM(netfs_sreq_trace_resubmit_short,	"SHORT")	\

	EM(netfs_sreq_trace_submit,		"SUBMT")	\

	EM(netfs_sreq_trace_terminated,		"TERM ")	\

	EM(netfs_sreq_trace_write,		"WRITE")	\

	E_(netfs_sreq_trace_write_term,		"WTERM")





/*

 * Export enum symbols via userspace.

 */

#undef EM

#undef E_

#define EM(a, b) TRACE_DEFINE_ENUM(a);

#define E_(a, b) TRACE_DEFINE_ENUM(a);



netfs_read_traces;

netfs_rreq_traces;

netfs_sreq_sources;

netfs_sreq_traces;



/*

 * Now redefine the EM() and E_() macros to map the enums to the strings that

 * will be printed in the output.

 */

#undef EM

#undef E_

#define EM(a, b)	{ a, b },

#define E_(a, b)	{ a, b }



TRACE_EVENT(netfs_read,

	    TP_PROTO(struct netfs_read_request *rreq,

		     loff_t start, size_t len,

		     enum netfs_read_trace what),



	    TP_ARGS(rreq, start, len, what),



	    TP_STRUCT__entry(

		    __field(unsigned int,		rreq		)

		    __field(unsigned int,		cookie		)

		    __field(loff_t,			start		)

		    __field(size_t,			len		)

		    __field(enum netfs_read_trace,	what		)

			     ),



	    TP_fast_assign(

		    __entry->rreq	= rreq->debug_id;

		    __entry->cookie	= rreq->cookie_debug_id;

		    __entry->start	= start;

		    __entry->len	= len;

		    __entry->what	= what;

			   ),



	    TP_printk("R=%08x %s c=%08x s=%llx %zx",

		      __entry->rreq,

		      __print_symbolic(__entry->what, netfs_read_traces),

		      __entry->cookie,

		      __entry->start, __entry->len)

	    );



TRACE_EVENT(netfs_rreq,

	    TP_PROTO(struct netfs_read_request *rreq,

		     enum netfs_rreq_trace what),



	    TP_ARGS(rreq, what),



	    TP_STRUCT__entry(

		    __field(unsigned int,		rreq		)

		    __field(unsigned short,		flags		)

		    __field(enum netfs_rreq_trace,	what		)

			     ),



	    TP_fast_assign(

		    __entry->rreq	= rreq->debug_id;

		    __entry->flags	= rreq->flags;

		    __entry->what	= what;

			   ),



	    TP_printk("R=%08x %s f=%02x",

		      __entry->rreq,

		      __print_symbolic(__entry->what, netfs_rreq_traces),

		      __entry->flags)

	    );



TRACE_EVENT(netfs_sreq,

	    TP_PROTO(struct netfs_read_subrequest *sreq,

		     enum netfs_sreq_trace what),



	    TP_ARGS(sreq, what),



	    TP_STRUCT__entry(

		    __field(unsigned int,		rreq		)

		    __field(unsigned short,		index		)

		    __field(short,			error		)

		    __field(unsigned short,		flags		)

		    __field(enum netfs_read_source,	source		)

		    __field(enum netfs_sreq_trace,	what		)

		    __field(size_t,			len		)

		    __field(size_t,			transferred	)

		    __field(loff_t,			start		)

			     ),



	    TP_fast_assign(

		    __entry->rreq	= sreq->rreq->debug_id;

		    __entry->index	= sreq->debug_index;

		    __entry->error	= sreq->error;

		    __entry->flags	= sreq->flags;

		    __entry->source	= sreq->source;

		    __entry->what	= what;

		    __entry->len	= sreq->len;

		    __entry->transferred = sreq->transferred;

		    __entry->start	= sreq->start;

			   ),



	    TP_printk("R=%08x[%u] %s %s f=%02x s=%llx %zx/%zx e=%d",

		      __entry->rreq, __entry->index,

		      __print_symbolic(__entry->what, netfs_sreq_traces),

		      __print_symbolic(__entry->source, netfs_sreq_sources),

		      __entry->flags,

		      __entry->start, __entry->transferred, __entry->len,

		      __entry->error)

	    );



#endif /* _TRACE_NETFS_H */



/* This part must be outside protection */

#include <trace/define_trace.h>