linux-kernel - Re: [PATCH 16/17] writeback: trace event writeback_single

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Date:	Fri, 13 May 2011 09:20:51 +1000
From:	Dave Chinner <david@...morbit.com>
To:	Wu Fengguang <fengguang.wu@...el.com>
Cc:	Andrew Morton <akpm@...ux-foundation.org>, Jan Kara <jack@...e.cz>,
	Christoph Hellwig <hch@...radead.org>,
	linux-fsdevel@...r.kernel.org, LKML <linux-kernel@...r.kernel.org>
Subject: Re: [PATCH 16/17] writeback: trace event writeback_single_inode

On Thu, May 12, 2011 at 09:57:22PM +0800, Wu Fengguang wrote:
> It is valuable to know how the dirty inodes are iterated and their IO size.
> 
> "writeback_single_inode: bdi 8:0: ino=134246746 state=I_DIRTY_SYNC|I_SYNC age=414 index=0 to_write=1024 wrote=0"
> 
> - "state" reflects inode->i_state at the end of writeback_single_inode()
> - "index" reflects mapping->writeback_index after the ->writepages() call
> - "to_write" is the wbc->nr_to_write at entrance of writeback_single_inode()
> - "wrote" is the number of pages actually written
> 
> Signed-off-by: Wu Fengguang <fengguang.wu@...el.com>
> ---
>  fs/fs-writeback.c                |    6 ++-
>  include/trace/events/writeback.h |   56 +++++++++++++++++++++++++++++
>  2 files changed, 61 insertions(+), 1 deletion(-)
> 
> --- linux-next.orig/include/trace/events/writeback.h	2011-05-12 11:46:27.000000000 +0800
> +++ linux-next/include/trace/events/writeback.h	2011-05-12 11:48:55.000000000 +0800
> @@ -8,6 +8,19 @@
>  #include <linux/device.h>
>  #include <linux/writeback.h>
>  
> +#define show_inode_state(state)					\
> +	__print_flags(state, "|",				\
> +		{I_DIRTY_SYNC,		"I_DIRTY_SYNC"},	\
> +		{I_DIRTY_DATASYNC,	"I_DIRTY_DATASYNC"},	\
> +		{I_DIRTY_PAGES,		"I_DIRTY_PAGES"},	\
> +		{I_NEW,			"I_NEW"},		\
> +		{I_WILL_FREE,		"I_WILL_FREE"},		\
> +		{I_FREEING,		"I_FREEING"},		\
> +		{I_CLEAR,		"I_CLEAR"},		\
> +		{I_SYNC,		"I_SYNC"},		\
> +		{I_REFERENCED,		"I_REFERENCED"}		\
> +	)
> +
>  struct wb_writeback_work;
>  
>  DECLARE_EVENT_CLASS(writeback_work_class,
> @@ -201,6 +214,49 @@ DEFINE_EVENT(writeback_congest_waited_te
>  	TP_ARGS(usec_timeout, usec_delayed)
>  );
>  
> +TRACE_EVENT(writeback_single_inode,
> +
> +	TP_PROTO(struct inode *inode,
> +		 struct writeback_control *wbc,
> +		 unsigned long nr_to_write
> +	),
> +
> +	TP_ARGS(inode, wbc, nr_to_write),
> +
> +	TP_STRUCT__entry(
> +		__array(char, name, 32)
> +		__field(unsigned long, ino)
> +		__field(unsigned long, state)
> +		__field(unsigned long, age)
> +		__field(unsigned long, writeback_index)
> +		__field(long, nr_to_write)
> +		__field(unsigned long, wrote)
> +	),
> +
> +	TP_fast_assign(
> +		strncpy(__entry->name,
> +			dev_name(inode->i_mapping->backing_dev_info->dev), 32);
> +		__entry->ino		= inode->i_ino;
> +		__entry->state		= inode->i_state;
> +		__entry->age		= (jiffies - inode->dirtied_when) *
> +								1000 / HZ;
> +		__entry->writeback_index = inode->i_mapping->writeback_index;
> +		__entry->nr_to_write	= nr_to_write;
> +		__entry->wrote		= nr_to_write - wbc->nr_to_write;
> +	),
> +
> +	TP_printk("bdi %s: ino=%lu state=%s age=%lu "
> +		  "index=%lu to_write=%ld wrote=%lu",
> +		  __entry->name,
> +		  __entry->ino,
> +		  show_inode_state(__entry->state),
> +		  __entry->age,
> +		  __entry->writeback_index,
> +		  __entry->nr_to_write,
> +		  __entry->wrote
> +	)
> +);
> +
>  #endif /* _TRACE_WRITEBACK_H */
>  
>  /* This part must be outside protection */
> --- linux-next.orig/fs/fs-writeback.c	2011-05-12 11:46:27.000000000 +0800
> +++ linux-next/fs/fs-writeback.c	2011-05-12 11:48:55.000000000 +0800
> @@ -356,6 +356,7 @@ writeback_single_inode(struct inode *ino
>  		       struct writeback_control *wbc)
>  {
>  	struct address_space *mapping = inode->i_mapping;
> +	long nr_to_write = wbc->nr_to_write;
>  	unsigned dirty;
>  	int ret;
>  
> @@ -378,7 +379,8 @@ writeback_single_inode(struct inode *ino
>  		 */
>  		if (wbc->sync_mode != WB_SYNC_ALL) {
>  			requeue_io(inode, wb);
> -			return 0;
> +			ret = 0;
> +			goto out;
>  		}
>  
>  		/*
> @@ -476,6 +478,8 @@ writeback_single_inode(struct inode *ino
>  		}
>  	}
>  	inode_sync_complete(inode);
> +out:
> +	trace_writeback_single_inode(inode, wbc, nr_to_write);
>  	return ret;
>  }

I think I'd prefer two separate trace calls rather than jumping to
one. That is, a trace_writeback_single_inode_requeue() event and a
trace_writeback_single_inode_done() event so we can see the separate
conditions in the trace....

Cheers,

Dave.

-- 
Dave Chinner
david@...morbit.com
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/