f2fs: fix the assign logic of iocb

Message ID 1666196277-27014-1-git-send-email-quic_mojha@quicinc.com
State New
Headers
Series f2fs: fix the assign logic of iocb |

Commit Message

Mukesh Ojha Oct. 19, 2022, 4:17 p.m. UTC
  commit 18ae8d12991b ("f2fs: show more DIO information in tracepoint")
introduces iocb field in 'f2fs_direct_IO_enter' trace event
And it only assigns the pointer and later it accesses its field
in trace print log.

Fix it by correcting data type and memcpy the content of iocb.

Fixes: 18ae8d12991b ("f2fs: show more DIO information in tracepoint")
Signed-off-by: Mukesh Ojha <quic_mojha@quicinc.com>
---
 include/trace/events/f2fs.h | 10 +++++-----
 1 file changed, 5 insertions(+), 5 deletions(-)
  

Comments

Chao Yu Oct. 20, 2022, 9:01 a.m. UTC | #1
On 2022/10/20 0:17, Mukesh Ojha wrote:
> commit 18ae8d12991b ("f2fs: show more DIO information in tracepoint")
> introduces iocb field in 'f2fs_direct_IO_enter' trace event
> And it only assigns the pointer and later it accesses its field
> in trace print log.
> 
> Fix it by correcting data type and memcpy the content of iocb.

So the implementation below is wrong, right? since it just assign __entry->name
with dentry->d_name.name rather than copyiny entirely, so that, during printing
of tracepoint, __entry->name may be invalid.

TRACE_EVENT(f2fs_unlink_enter,

	TP_PROTO(struct inode *dir, struct dentry *dentry),

	TP_ARGS(dir, dentry),

	TP_STRUCT__entry(
		__field(dev_t,	dev)
		__field(ino_t,	ino)
		__field(loff_t,	size)
		__field(blkcnt_t, blocks)
		__field(const char *,	name)
	),

	TP_fast_assign(
		__entry->dev	= dir->i_sb->s_dev;
		__entry->ino	= dir->i_ino;
		__entry->size	= dir->i_size;
		__entry->blocks	= dir->i_blocks;
		__entry->name	= dentry->d_name.name;
	),

> 
> Fixes: 18ae8d12991b ("f2fs: show more DIO information in tracepoint")
> Signed-off-by: Mukesh Ojha <quic_mojha@quicinc.com>
> ---
>   include/trace/events/f2fs.h | 10 +++++-----
>   1 file changed, 5 insertions(+), 5 deletions(-)
> 
> diff --git a/include/trace/events/f2fs.h b/include/trace/events/f2fs.h
> index c6b3724..7727ec9 100644
> --- a/include/trace/events/f2fs.h
> +++ b/include/trace/events/f2fs.h
> @@ -940,7 +940,7 @@ TRACE_EVENT(f2fs_direct_IO_enter,
>   	TP_STRUCT__entry(
>   		__field(dev_t,	dev)
>   		__field(ino_t,	ino)
> -		__field(struct kiocb *,	iocb)
> +		__field_struct(struct kiocb,	iocb)
>   		__field(unsigned long,	len)
>   		__field(int,	rw)
>   	),
> @@ -948,17 +948,17 @@ TRACE_EVENT(f2fs_direct_IO_enter,
>   	TP_fast_assign(
>   		__entry->dev	= inode->i_sb->s_dev;
>   		__entry->ino	= inode->i_ino;
> -		__entry->iocb	= iocb;
> +		 memcpy(&__entry->iocb, iocb, sizeof(*iocb));
>   		__entry->len	= len;
>   		__entry->rw	= rw;
>   	),
>   
>   	TP_printk("dev = (%d,%d), ino = %lu pos = %lld len = %lu ki_flags = %x ki_ioprio = %x rw = %d",
>   		show_dev_ino(__entry),
> -		__entry->iocb->ki_pos,
> +		__entry->iocb.ki_pos,
>   		__entry->len,
> -		__entry->iocb->ki_flags,
> -		__entry->iocb->ki_ioprio,
> +		__entry->iocb.ki_flags,
> +		__entry->iocb.ki_ioprio,
>   		__entry->rw)
>   );
>
  
Mukesh Ojha Oct. 20, 2022, 9:27 a.m. UTC | #2
Hi,

On 10/20/2022 2:31 PM, Chao Yu wrote:
> On 2022/10/20 0:17, Mukesh Ojha wrote:
>> commit 18ae8d12991b ("f2fs: show more DIO information in tracepoint")
>> introduces iocb field in 'f2fs_direct_IO_enter' trace event
>> And it only assigns the pointer and later it accesses its field
>> in trace print log.
>>
>> Fix it by correcting data type and memcpy the content of iocb.
> 
> So the implementation below is wrong, right? since it just assign 
> __entry->name
> with dentry->d_name.name rather than copyiny entirely, so that, during 
> printing

I think, yes.

About the patch, we were getting error as below on doing

echo 51200 > /d/tracing/buffer_size_kb
echo 1 > /d/tracing/events/f2fs/f2fs_direct_IO_enter/enable
echo 1 > /d/tracing/tracing_on
cat /d/tracing/trace_pipe > ftrace.log

Run something which exercise this path.

Unable to handle kernel paging request at virtual address ffffffc04cef3d30
Mem abort info:
ESR = 0x96000007
EC = 0x25: DABT (current EL), IL = 32 bits

  pc : trace_raw_output_f2fs_direct_IO_enter+0x54/0xa4
  lr : trace_raw_output_f2fs_direct_IO_enter+0x2c/0xa4
  sp : ffffffc0443cbbd0
  x29: ffffffc0443cbbf0 x28: ffffff8935b120d0 x27: ffffff8935b12108
  x26: ffffff8935b120f0 x25: ffffff8935b12100 x24: ffffff8935b110c0
  x23: ffffff8935b10000 x22: ffffff88859a936c x21: ffffff88859a936c
  x20: ffffff8935b110c0 x19: ffffff8935b10000 x18: ffffffc03b195060
  x17: ffffff8935b11e76 x16: 00000000000000cc x15: ffffffef855c4f2c
  x14: 0000000000000001 x13: 000000000000004e x12: ffff0000ffffff00
  x11: ffffffef86c350d0 x10: 00000000000010c0 x9 : 000000000fe0002c
  x8 : ffffffc04cef3d28 x7 : 7f7f7f7f7f7f7f7f x6 : 0000000002000000
  x5 : ffffff8935b11e9a x4 : 0000000000006250 x3 : ffff0a00ffffff04
  x2 : 0000000000000002 x1 : ffffffef86a0a31f x0 : ffffff8935b10000
  Call trace:
   trace_raw_output_f2fs_direct_IO_enter+0x54/0xa4
   print_trace_fmt+0x9c/0x138
   print_trace_line+0x154/0x254
   tracing_read_pipe+0x21c/0x380
   vfs_read+0x108/0x3ac
   ksys_read+0x7c/0xec
   __arm64_sys_read+0x20/0x30
   invoke_syscall+0x60/0x150
   el0_svc_common.llvm.1237943816091755067+0xb8/0xf8
   do_el0_svc+0x28/0xa0

-Mukesh
  
Chao Yu Oct. 20, 2022, 10:26 a.m. UTC | #3
On 2022/10/20 17:27, Mukesh Ojha wrote:
> Hi,
> 
> On 10/20/2022 2:31 PM, Chao Yu wrote:
>> On 2022/10/20 0:17, Mukesh Ojha wrote:
>>> commit 18ae8d12991b ("f2fs: show more DIO information in tracepoint")
>>> introduces iocb field in 'f2fs_direct_IO_enter' trace event
>>> And it only assigns the pointer and later it accesses its field
>>> in trace print log.
>>>
>>> Fix it by correcting data type and memcpy the content of iocb.
>>
>> So the implementation below is wrong, right? since it just assign __entry->name
>> with dentry->d_name.name rather than copyiny entirely, so that, during printing
> 
> I think, yes.
> 
> About the patch, we were getting error as below on doing

Thanks for the explanation. :)

What do you think of adding below info into commit message? and fixing all
similar issues of include/trace/events/f2fs.h in one patch?

Thanks,

> 
> echo 51200 > /d/tracing/buffer_size_kb
> echo 1 > /d/tracing/events/f2fs/f2fs_direct_IO_enter/enable
> echo 1 > /d/tracing/tracing_on
> cat /d/tracing/trace_pipe > ftrace.log
> 
> Run something which exercise this path.
> 
> Unable to handle kernel paging request at virtual address ffffffc04cef3d30
> Mem abort info:
> ESR = 0x96000007
> EC = 0x25: DABT (current EL), IL = 32 bits
> 
>   pc : trace_raw_output_f2fs_direct_IO_enter+0x54/0xa4
>   lr : trace_raw_output_f2fs_direct_IO_enter+0x2c/0xa4
>   sp : ffffffc0443cbbd0
>   x29: ffffffc0443cbbf0 x28: ffffff8935b120d0 x27: ffffff8935b12108
>   x26: ffffff8935b120f0 x25: ffffff8935b12100 x24: ffffff8935b110c0
>   x23: ffffff8935b10000 x22: ffffff88859a936c x21: ffffff88859a936c
>   x20: ffffff8935b110c0 x19: ffffff8935b10000 x18: ffffffc03b195060
>   x17: ffffff8935b11e76 x16: 00000000000000cc x15: ffffffef855c4f2c
>   x14: 0000000000000001 x13: 000000000000004e x12: ffff0000ffffff00
>   x11: ffffffef86c350d0 x10: 00000000000010c0 x9 : 000000000fe0002c
>   x8 : ffffffc04cef3d28 x7 : 7f7f7f7f7f7f7f7f x6 : 0000000002000000
>   x5 : ffffff8935b11e9a x4 : 0000000000006250 x3 : ffff0a00ffffff04
>   x2 : 0000000000000002 x1 : ffffffef86a0a31f x0 : ffffff8935b10000
>   Call trace:
>    trace_raw_output_f2fs_direct_IO_enter+0x54/0xa4
>    print_trace_fmt+0x9c/0x138
>    print_trace_line+0x154/0x254
>    tracing_read_pipe+0x21c/0x380
>    vfs_read+0x108/0x3ac
>    ksys_read+0x7c/0xec
>    __arm64_sys_read+0x20/0x30
>    invoke_syscall+0x60/0x150
>    el0_svc_common.llvm.1237943816091755067+0xb8/0xf8
>    do_el0_svc+0x28/0xa0
> 
> -Mukesh
  
Pavan Kondeti Oct. 21, 2022, 5 a.m. UTC | #4
Hi Mukesh,

On Wed, Oct 19, 2022 at 09:47:57PM +0530, Mukesh Ojha wrote:
> commit 18ae8d12991b ("f2fs: show more DIO information in tracepoint")
> introduces iocb field in 'f2fs_direct_IO_enter' trace event
> And it only assigns the pointer and later it accesses its field
> in trace print log.
> 
> Fix it by correcting data type and memcpy the content of iocb.
> 
> Fixes: 18ae8d12991b ("f2fs: show more DIO information in tracepoint")
> Signed-off-by: Mukesh Ojha <quic_mojha@quicinc.com>
> ---
>  include/trace/events/f2fs.h | 10 +++++-----
>  1 file changed, 5 insertions(+), 5 deletions(-)
> 
> diff --git a/include/trace/events/f2fs.h b/include/trace/events/f2fs.h
> index c6b3724..7727ec9 100644
> --- a/include/trace/events/f2fs.h
> +++ b/include/trace/events/f2fs.h
> @@ -940,7 +940,7 @@ TRACE_EVENT(f2fs_direct_IO_enter,
>  	TP_STRUCT__entry(
>  		__field(dev_t,	dev)
>  		__field(ino_t,	ino)
> -		__field(struct kiocb *,	iocb)
> +		__field_struct(struct kiocb,	iocb)
>  		__field(unsigned long,	len)
>  		__field(int,	rw)
>  	),
> @@ -948,17 +948,17 @@ TRACE_EVENT(f2fs_direct_IO_enter,
>  	TP_fast_assign(
>  		__entry->dev	= inode->i_sb->s_dev;
>  		__entry->ino	= inode->i_ino;
> -		__entry->iocb	= iocb;
> +		 memcpy(&__entry->iocb, iocb, sizeof(*iocb));
>  		__entry->len	= len;
>  		__entry->rw	= rw;
>  	),
>  

Why copy the whole structure (48 bytes)? cache the three members you
need.

Thanks,
Pavan
  
Masami Hiramatsu (Google) Oct. 24, 2022, 5:07 a.m. UTC | #5
On Fri, 21 Oct 2022 10:30:46 +0530
Pavan Kondeti <quic_pkondeti@quicinc.com> wrote:

> Hi Mukesh,
> 
> On Wed, Oct 19, 2022 at 09:47:57PM +0530, Mukesh Ojha wrote:
> > commit 18ae8d12991b ("f2fs: show more DIO information in tracepoint")
> > introduces iocb field in 'f2fs_direct_IO_enter' trace event
> > And it only assigns the pointer and later it accesses its field
> > in trace print log.
> > 
> > Fix it by correcting data type and memcpy the content of iocb.
> > 
> > Fixes: 18ae8d12991b ("f2fs: show more DIO information in tracepoint")
> > Signed-off-by: Mukesh Ojha <quic_mojha@quicinc.com>
> > ---
> >  include/trace/events/f2fs.h | 10 +++++-----
> >  1 file changed, 5 insertions(+), 5 deletions(-)
> > 
> > diff --git a/include/trace/events/f2fs.h b/include/trace/events/f2fs.h
> > index c6b3724..7727ec9 100644
> > --- a/include/trace/events/f2fs.h
> > +++ b/include/trace/events/f2fs.h
> > @@ -940,7 +940,7 @@ TRACE_EVENT(f2fs_direct_IO_enter,
> >  	TP_STRUCT__entry(
> >  		__field(dev_t,	dev)
> >  		__field(ino_t,	ino)
> > -		__field(struct kiocb *,	iocb)
> > +		__field_struct(struct kiocb,	iocb)
> >  		__field(unsigned long,	len)
> >  		__field(int,	rw)
> >  	),
> > @@ -948,17 +948,17 @@ TRACE_EVENT(f2fs_direct_IO_enter,
> >  	TP_fast_assign(
> >  		__entry->dev	= inode->i_sb->s_dev;
> >  		__entry->ino	= inode->i_ino;
> > -		__entry->iocb	= iocb;
> > +		 memcpy(&__entry->iocb, iocb, sizeof(*iocb));
> >  		__entry->len	= len;
> >  		__entry->rw	= rw;
> >  	),
> >  
> 
> Why copy the whole structure (48 bytes)? cache the three members you
> need.

+1. If this only prints ki_pos, ki_flags and ki_ioprio, I recommend you
to save those 3 fields to the entry. It should not expose in-kernel
data structure because it can be changed.

Thank you,

> 
> Thanks,
> Pavan
  

Patch

diff --git a/include/trace/events/f2fs.h b/include/trace/events/f2fs.h
index c6b3724..7727ec9 100644
--- a/include/trace/events/f2fs.h
+++ b/include/trace/events/f2fs.h
@@ -940,7 +940,7 @@  TRACE_EVENT(f2fs_direct_IO_enter,
 	TP_STRUCT__entry(
 		__field(dev_t,	dev)
 		__field(ino_t,	ino)
-		__field(struct kiocb *,	iocb)
+		__field_struct(struct kiocb,	iocb)
 		__field(unsigned long,	len)
 		__field(int,	rw)
 	),
@@ -948,17 +948,17 @@  TRACE_EVENT(f2fs_direct_IO_enter,
 	TP_fast_assign(
 		__entry->dev	= inode->i_sb->s_dev;
 		__entry->ino	= inode->i_ino;
-		__entry->iocb	= iocb;
+		 memcpy(&__entry->iocb, iocb, sizeof(*iocb));
 		__entry->len	= len;
 		__entry->rw	= rw;
 	),
 
 	TP_printk("dev = (%d,%d), ino = %lu pos = %lld len = %lu ki_flags = %x ki_ioprio = %x rw = %d",
 		show_dev_ino(__entry),
-		__entry->iocb->ki_pos,
+		__entry->iocb.ki_pos,
 		__entry->len,
-		__entry->iocb->ki_flags,
-		__entry->iocb->ki_ioprio,
+		__entry->iocb.ki_flags,
+		__entry->iocb.ki_ioprio,
 		__entry->rw)
 );