[PATCH 1/2] ext4: fix symbolic enum printing in trace output

[PATCH 1/2] ext4: fix symbolic enum printing in trace output

[Dmitry Monakhov]

Trace's macro __print_flags() produce raw event's decraration w/o knowing actual
flags value

cat /sys/kernel/debug/tracing/events/ext4/ext4_ext_map_blocks_exit/format
..
__print_flags(REC->mflags, "", { (1 << BH_New),

For that reason we have to explicitly define it via special macro TRACE_DEFINE_ENUM()
Also add missed EXTENT_STATUS_REFERENCED flag.

#Before patch
ext4:ext4_ext_map_blocks_exit: dev 253,0 ino 2 flags  lblk 0 pblk 4177 len 1 mflags 0x20 ret 1
ext4:ext4_ext_map_blocks_exit: dev 253,0 ino 12 flags CREATE lblk 0 pblk 34304 len 1 mflags 0x60 ret 1

#With patch
ext4:ext4_ext_map_blocks_exit: dev 253,0 ino 2 flags  lblk 0 pblk 4177 len 1 mflags M ret 1
ext4:ext4_ext_map_blocks_exit: dev 253,0 ino 12 flags CREATE lblk 0 pblk 34816 len 1 mflags NM ret 1

Signed-off-by: Dmitry Monakhov <dmonakhov@gmail.com>
---
 include/trace/events/ext4.h | 19 ++++++++++++++++++-
 1 file changed, 18 insertions(+), 1 deletion(-)

diff --git a/include/trace/events/ext4.h b/include/trace/events/ext4.h
index 182c9fe..3bf7128 100644
--- a/include/trace/events/ext4.h
+++ b/include/trace/events/ext4.h
@@ -48,6 +48,16 @@ struct partial_cluster;
 	{ EXT4_GET_BLOCKS_KEEP_SIZE,		"KEEP_SIZE" },		\
 	{ EXT4_GET_BLOCKS_ZERO,			"ZERO" })
 
+/*
+ * __print_flags() requires that all enum values be wrapped in the
+ * TRACE_DEFINE_ENUM macro so that the enum value can be encoded in the ftrace
+ * ring buffer.
+ */
+TRACE_DEFINE_ENUM(BH_New);
+TRACE_DEFINE_ENUM(BH_Mapped);
+TRACE_DEFINE_ENUM(BH_Unwritten);
+TRACE_DEFINE_ENUM(BH_Boundary);
+
 #define show_mflags(flags) __print_flags(flags, "",	\
 	{ EXT4_MAP_NEW,		"N" },			\
 	{ EXT4_MAP_MAPPED,	"M" },			\
@@ -62,11 +72,18 @@ struct partial_cluster;
 	{ EXT4_FREE_BLOCKS_NOFREE_FIRST_CLUSTER,"1ST_CLUSTER" },\
 	{ EXT4_FREE_BLOCKS_NOFREE_LAST_CLUSTER,	"LAST_CLUSTER" })
 
+TRACE_DEFINE_ENUM(ES_WRITTEN_B);
+TRACE_DEFINE_ENUM(ES_UNWRITTEN_B);
+TRACE_DEFINE_ENUM(ES_DELAYED_B);
+TRACE_DEFINE_ENUM(ES_HOLE_B);
+TRACE_DEFINE_ENUM(ES_REFERENCED_B);
+
 #define show_extent_status(status) __print_flags(status, "",	\
 	{ EXTENT_STATUS_WRITTEN,	"W" },			\
 	{ EXTENT_STATUS_UNWRITTEN,	"U" },			\
 	{ EXTENT_STATUS_DELAYED,	"D" },			\
-	{ EXTENT_STATUS_HOLE,		"H" })
+	{ EXTENT_STATUS_HOLE,		"H" },			\
+	{ EXTENT_STATUS_REFERENCED,	"R" })
 
 #define show_falloc_mode(mode) __print_flags(mode, "|",		\
 	{ FALLOC_FL_KEEP_SIZE,		"KEEP_SIZE"},		\
-- 
2.7.4

[PATCH 2/2] ext4: fix extent_status trace points

[Dmitry Monakhov]

Show pblock only if it has meaningful value.

# before
   ext4:ext4_es_lookup_extent_exit: dev 253,0 ino 12 found 1 [1/4294967294) 576460752303423487 H
   ext4:ext4_es_lookup_extent_exit: dev 253,0 ino 12 found 1 [2/4294967293) 576460752303423487 HR
# after
   ext4:ext4_es_lookup_extent_exit: dev 253,0 ino 12 found 1 [1/4294967294) 0 H
   ext4:ext4_es_lookup_extent_exit: dev 253,0 ino 12 found 1 [2/4294967293) 0 HR

Signed-off-by: Dmitry Monakhov <dmonakhov@gmail.com>
---
 fs/ext4/extents_status.h    | 6 ++++++
 include/trace/events/ext4.h | 8 ++++----
 2 files changed, 10 insertions(+), 4 deletions(-)

diff --git a/fs/ext4/extents_status.h b/fs/ext4/extents_status.h
index 825313c..4ec30a7 100644
--- a/fs/ext4/extents_status.h
+++ b/fs/ext4/extents_status.h
@@ -209,6 +209,12 @@ static inline ext4_fsblk_t ext4_es_pblock(struct extent_status *es)
 	return es->es_pblk & ~ES_MASK;
 }
 
+static inline ext4_fsblk_t ext4_es_show_pblock(struct extent_status *es)
+{
+	ext4_fsblk_t pblock = ext4_es_pblock(es);
+	return pblock == ~ES_MASK ? 0 : pblock;
+}
+
 static inline void ext4_es_store_pblock(struct extent_status *es,
 					ext4_fsblk_t pb)
 {
diff --git a/include/trace/events/ext4.h b/include/trace/events/ext4.h
index 3bf7128..19c8766 100644
--- a/include/trace/events/ext4.h
+++ b/include/trace/events/ext4.h
@@ -2282,7 +2282,7 @@ DECLARE_EVENT_CLASS(ext4__es_extent,
 		__entry->ino	= inode->i_ino;
 		__entry->lblk	= es->es_lblk;
 		__entry->len	= es->es_len;
-		__entry->pblk	= ext4_es_pblock(es);
+		__entry->pblk	= ext4_es_show_pblock(es);
 		__entry->status	= ext4_es_status(es);
 	),
 
@@ -2371,7 +2371,7 @@ TRACE_EVENT(ext4_es_find_extent_range_exit,
 		__entry->ino	= inode->i_ino;
 		__entry->lblk	= es->es_lblk;
 		__entry->len	= es->es_len;
-		__entry->pblk	= ext4_es_pblock(es);
+		__entry->pblk	= ext4_es_show_pblock(es);
 		__entry->status	= ext4_es_status(es);
 	),
 
@@ -2425,7 +2425,7 @@ TRACE_EVENT(ext4_es_lookup_extent_exit,
 		__entry->ino	= inode->i_ino;
 		__entry->lblk	= es->es_lblk;
 		__entry->len	= es->es_len;
-		__entry->pblk	= ext4_es_pblock(es);
+		__entry->pblk	= ext4_es_show_pblock(es);
 		__entry->status	= ext4_es_status(es);
 		__entry->found	= found;
 	),
@@ -2593,7 +2593,7 @@ TRACE_EVENT(ext4_es_insert_delayed_block,
 		__entry->ino		= inode->i_ino;
 		__entry->lblk		= es->es_lblk;
 		__entry->len		= es->es_len;
-		__entry->pblk		= ext4_es_pblock(es);
+		__entry->pblk		= ext4_es_show_pblock(es);
 		__entry->status		= ext4_es_status(es);
 		__entry->allocated	= allocated;
 	),
-- 
2.7.4

Re: [PATCH 1/2] ext4: fix symbolic enum printing in trace output

[Darrick J. Wong]

On Thu, Nov 14, 2019 at 08:01:46PM +0000, Dmitry Monakhov wrote:
> Trace's macro __print_flags() produce raw event's decraration w/o knowing actual
> flags value
> 
> cat /sys/kernel/debug/tracing/events/ext4/ext4_ext_map_blocks_exit/format
> ..
> __print_flags(REC->mflags, "", { (1 << BH_New),
> 
> For that reason we have to explicitly define it via special macro TRACE_DEFINE_ENUM()
> Also add missed EXTENT_STATUS_REFERENCED flag.
> 
> #Before patch
> ext4:ext4_ext_map_blocks_exit: dev 253,0 ino 2 flags  lblk 0 pblk 4177 len 1 mflags 0x20 ret 1
> ext4:ext4_ext_map_blocks_exit: dev 253,0 ino 12 flags CREATE lblk 0 pblk 34304 len 1 mflags 0x60 ret 1
> 
> #With patch
> ext4:ext4_ext_map_blocks_exit: dev 253,0 ino 2 flags  lblk 0 pblk 4177 len 1 mflags M ret 1
> ext4:ext4_ext_map_blocks_exit: dev 253,0 ino 12 flags CREATE lblk 0 pblk 34816 len 1 mflags NM ret 1
> 
> Signed-off-by: Dmitry Monakhov <dmonakhov@gmail.com>
> ---
>  include/trace/events/ext4.h | 19 ++++++++++++++++++-
>  1 file changed, 18 insertions(+), 1 deletion(-)
> 
> diff --git a/include/trace/events/ext4.h b/include/trace/events/ext4.h
> index 182c9fe..3bf7128 100644
> --- a/include/trace/events/ext4.h
> +++ b/include/trace/events/ext4.h
> @@ -48,6 +48,16 @@ struct partial_cluster;
>  	{ EXT4_GET_BLOCKS_KEEP_SIZE,		"KEEP_SIZE" },		\
>  	{ EXT4_GET_BLOCKS_ZERO,			"ZERO" })
>  
> +/*
> + * __print_flags() requires that all enum values be wrapped in the
> + * TRACE_DEFINE_ENUM macro so that the enum value can be encoded in the ftrace
> + * ring buffer.
> + */
> +TRACE_DEFINE_ENUM(BH_New);
> +TRACE_DEFINE_ENUM(BH_Mapped);
> +TRACE_DEFINE_ENUM(BH_Unwritten);
> +TRACE_DEFINE_ENUM(BH_Boundary);
> +
>  #define show_mflags(flags) __print_flags(flags, "",	\
>  	{ EXT4_MAP_NEW,		"N" },			\
>  	{ EXT4_MAP_MAPPED,	"M" },			\
> @@ -62,11 +72,18 @@ struct partial_cluster;
>  	{ EXT4_FREE_BLOCKS_NOFREE_FIRST_CLUSTER,"1ST_CLUSTER" },\
>  	{ EXT4_FREE_BLOCKS_NOFREE_LAST_CLUSTER,	"LAST_CLUSTER" })
>  
> +TRACE_DEFINE_ENUM(ES_WRITTEN_B);
> +TRACE_DEFINE_ENUM(ES_UNWRITTEN_B);
> +TRACE_DEFINE_ENUM(ES_DELAYED_B);
> +TRACE_DEFINE_ENUM(ES_HOLE_B);
> +TRACE_DEFINE_ENUM(ES_REFERENCED_B);

I wonder if it's worth leaving a comment wherever this enum is defined
warning developers to keep this TRACE_DEFINE_NUM list (and the string
mapping) up to date?

--D

>  #define show_extent_status(status) __print_flags(status, "",	\
>  	{ EXTENT_STATUS_WRITTEN,	"W" },			\
>  	{ EXTENT_STATUS_UNWRITTEN,	"U" },			\
>  	{ EXTENT_STATUS_DELAYED,	"D" },			\
> -	{ EXTENT_STATUS_HOLE,		"H" })
> +	{ EXTENT_STATUS_HOLE,		"H" },			\
> +	{ EXTENT_STATUS_REFERENCED,	"R" })
>  
>  #define show_falloc_mode(mode) __print_flags(mode, "|",		\
>  	{ FALLOC_FL_KEEP_SIZE,		"KEEP_SIZE"},		\
> -- 
> 2.7.4
> 

Re: [PATCH 1/2] ext4: fix symbolic enum printing in trace output

[Theodore Y. Ts'o]

On Thu, Nov 14, 2019 at 08:01:46PM +0000, Dmitry Monakhov wrote:
> Trace's macro __print_flags() produce raw event's decraration w/o knowing actual
> flags value
> 
> cat /sys/kernel/debug/tracing/events/ext4/ext4_ext_map_blocks_exit/format
> ..
> __print_flags(REC->mflags, "", { (1 << BH_New),
> 
> For that reason we have to explicitly define it via special macro TRACE_DEFINE_ENUM()
> Also add missed EXTENT_STATUS_REFERENCED flag.
> 
> #Before patch
> ext4:ext4_ext_map_blocks_exit: dev 253,0 ino 2 flags  lblk 0 pblk 4177 len 1 mflags 0x20 ret 1
> ext4:ext4_ext_map_blocks_exit: dev 253,0 ino 12 flags CREATE lblk 0 pblk 34304 len 1 mflags 0x60 ret 1
> 
> #With patch
> ext4:ext4_ext_map_blocks_exit: dev 253,0 ino 2 flags  lblk 0 pblk 4177 len 1 mflags M ret 1
> ext4:ext4_ext_map_blocks_exit: dev 253,0 ino 12 flags CREATE lblk 0 pblk 34816 len 1 mflags NM ret 1
> 
> Signed-off-by: Dmitry Monakhov <dmonakhov@gmail.com>

Thanks, applied.

					- Ted

Re: [PATCH 2/2] ext4: fix extent_status trace points

[Theodore Y. Ts'o]

On Thu, Nov 14, 2019 at 08:01:47PM +0000, Dmitry Monakhov wrote:
> Show pblock only if it has meaningful value.
> 
> # before
>    ext4:ext4_es_lookup_extent_exit: dev 253,0 ino 12 found 1 [1/4294967294) 576460752303423487 H
>    ext4:ext4_es_lookup_extent_exit: dev 253,0 ino 12 found 1 [2/4294967293) 576460752303423487 HR
> # after
>    ext4:ext4_es_lookup_extent_exit: dev 253,0 ino 12 found 1 [1/4294967294) 0 H
>    ext4:ext4_es_lookup_extent_exit: dev 253,0 ino 12 found 1 [2/4294967293) 0 HR
> 
> Signed-off-by: Dmitry Monakhov <dmonakhov@gmail.com>

Thanks, applied.

					- Ted