[PATCH] lib/dynamic_debug: make better dynamic log output

[PATCH] lib/dynamic_debug: make better dynamic log output

[Huang Shijie]

The driver strings and device name is not changed for the driver's dynamic
log output. But the dynamic_emit_prefix() which contains the function names
may changed when the function names are changed.

So the patch makes the better dynamic log output.

Signed-off-by: Huang Shijie <sjhuang@iluvatar.ai>
---
 lib/dynamic_debug.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index c60409138e13..8cfcdd5bd1ff 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -590,8 +590,8 @@ void __dynamic_dev_dbg(struct _ddebug *descriptor,
 		char buf[PREFIX_SIZE];
 
 		dev_printk_emit(LOGLEVEL_DEBUG, dev, "%s%s %s: %pV",
-				dynamic_emit_prefix(descriptor, buf),
 				dev_driver_string(dev), dev_name(dev),
+				dynamic_emit_prefix(descriptor, buf),
 				&vaf);
 	}
 
-- 
2.17.1

[PATCH V2] lib/dynamic_debug: make better dynamic log output

[Huang Shijie]

The driver strings and device name is not changed for the driver's dynamic
log output. But the dynamic_emit_prefix() which contains the function names
may change when the function names change.

So the patch makes the better dynamic log output.

Signed-off-by: Huang Shijie <sjhuang@iluvatar.ai>
---
v1 -- >v2
   Add a whitespace between driver strings and dev name.
---
 lib/dynamic_debug.c | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index c60409138e13..f6665af6abd4 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -589,9 +589,9 @@ void __dynamic_dev_dbg(struct _ddebug *descriptor,
 	} else {
 		char buf[PREFIX_SIZE];
 
-		dev_printk_emit(LOGLEVEL_DEBUG, dev, "%s%s %s: %pV",
-				dynamic_emit_prefix(descriptor, buf),
+		dev_printk_emit(LOGLEVEL_DEBUG, dev, "%s %s %s: %pV",
 				dev_driver_string(dev), dev_name(dev),
+				dynamic_emit_prefix(descriptor, buf),
 				&vaf);
 	}
 
-- 
2.17.1

Re: [PATCH V2] lib/dynamic_debug: make better dynamic log output

[Jason Baron]

On 12/10/19 1:38 AM, Huang Shijie wrote:
> The driver strings and device name is not changed for the driver's dynamic
> log output. But the dynamic_emit_prefix() which contains the function names
> may change when the function names change.
> 
> So the patch makes the better dynamic log output.
> 
> Signed-off-by: Huang Shijie <sjhuang@iluvatar.ai>
> ---
> v1 -- >v2
>    Add a whitespace between driver strings and dev name.
> ---
>  lib/dynamic_debug.c | 4 ++--
>  1 file changed, 2 insertions(+), 2 deletions(-)
> 
> diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
> index c60409138e13..f6665af6abd4 100644
> --- a/lib/dynamic_debug.c
> +++ b/lib/dynamic_debug.c
> @@ -589,9 +589,9 @@ void __dynamic_dev_dbg(struct _ddebug *descriptor,
>  	} else {
>  		char buf[PREFIX_SIZE];
>  
> -		dev_printk_emit(LOGLEVEL_DEBUG, dev, "%s%s %s: %pV",
> -				dynamic_emit_prefix(descriptor, buf),
> +		dev_printk_emit(LOGLEVEL_DEBUG, dev, "%s %s %s: %pV",
>  				dev_driver_string(dev), dev_name(dev),
> +				dynamic_emit_prefix(descriptor, buf),
>  				&vaf);
>  	}
>  
> 


Hi Huang,

So this is just reversing the order of output. All the other dynamic
debug calls emit the 'prefix' first, so if we were to change this it
seems like we'd also want to change the other ones to be consistent.

That said, I'm not sure why reversing things here is better?

Thanks,

-Jason

Re: [PATCH V2] lib/dynamic_debug: make better dynamic log output

[Huang Shijie]

On Tue, Dec 10, 2019 at 01:16:10PM -0500, Jason Baron wrote:
> 
> 
> On 12/10/19 1:38 AM, Huang Shijie wrote:
> > The driver strings and device name is not changed for the driver's dynamic
> > log output. But the dynamic_emit_prefix() which contains the function names
> > may change when the function names change.
> > 
> > So the patch makes the better dynamic log output.
> > 
> > Signed-off-by: Huang Shijie <sjhuang@iluvatar.ai>
> > ---
> > v1 -- >v2
> >    Add a whitespace between driver strings and dev name.
> > ---
> >  lib/dynamic_debug.c | 4 ++--
> >  1 file changed, 2 insertions(+), 2 deletions(-)
> > 
> > diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
> > index c60409138e13..f6665af6abd4 100644
> > --- a/lib/dynamic_debug.c
> > +++ b/lib/dynamic_debug.c
> > @@ -589,9 +589,9 @@ void __dynamic_dev_dbg(struct _ddebug *descriptor,
> >  	} else {
> >  		char buf[PREFIX_SIZE];
> >  
> > -		dev_printk_emit(LOGLEVEL_DEBUG, dev, "%s%s %s: %pV",
> > -				dynamic_emit_prefix(descriptor, buf),
> > +		dev_printk_emit(LOGLEVEL_DEBUG, dev, "%s %s %s: %pV",
> >  				dev_driver_string(dev), dev_name(dev),
> > +				dynamic_emit_prefix(descriptor, buf),
> >  				&vaf);
> >  	}
> >  
> > 
> 
> 
> Hi Huang,
> 
> So this is just reversing the order of output. All the other dynamic
> debug calls emit the 'prefix' first, so if we were to change this it
> seems like we'd also want to change the other ones to be consistent.
okay, I will check that.

> 
> That said, I'm not sure why reversing things here is better?
I quote the some output log here:

Before this patch:
        ------------------------------------------------------------
	[   66.159851] [1412] bi_ioctl: iluvatar-bi 0000:00:03.0: ioctl : AIP_MEM_CREATE
	[   66.159855] [1412] bi_ioctl_aip_mem_create: iluvatar-bi 0000:00:03.0: start bi_ioctl_aip_mem_create
	[   66.159874] [1412] __mem_handle_dump: iluvatar-bi 0000:00:03.0: [mem_handle: 0xffff88814ff56000](bi_ioctl_aip_mem_create) vdev:0xffff888157951200:8
	[   66.159877] [1412] __mem_handle_dump: iluvatar-bi 0000:00:03.0: 	ctx           : 0xffff888157950d80
	[   66.159879] [1412] __mem_handle_dump: iluvatar-bi 0000:00:03.0: 	heap          : host
	[   66.159882] [1412] __mem_handle_dump: iluvatar-bi 0000:00:03.0: 	flags         : user ptr:0, fence:1, exe:0
	[   66.159886] [1412] mem_handle_print_submit_refcnt: iluvatar-bi 0000:00:03.0: mem_handle_print_submit_refcnt:532[mem_handle_get_submit_refcnt] mem ffff88814ff56000, ref_cnt 0
	[   66.159888] [1412] __mem_handle_dump: iluvatar-bi 0000:00:03.0: 	status        : free
	[   66.159890] [1412] __mem_handle_dump: iluvatar-bi 0000:00:03.0: 	location      : un set
	[   66.159893] [1412] __mem_handle_dump: iluvatar-bi 0000:00:03.0: 	size          : 0x64, pg num 0x0
	[   66.159895] [1412] __mem_handle_dump: iluvatar-bi 0000:00:03.0: 	sys va (user) : 0x0
	[   66.159898] [1412] mem_handle_dump_pte: iluvatar-bi 0000:00:03.0: 		invld_host_ava[0]   : 0x0
	[   66.159900] [1412] mem_handle_dump_pte: iluvatar-bi 0000:00:03.0: 		invld_host_ava[1]   : 0x0
	[   66.159902] [1412] mem_handle_dump_pte: iluvatar-bi 0000:00:03.0: 		invld_host_ava[2]   : 0x0
	[   66.159905] [1412] mem_handle_dump_pte: iluvatar-bi 0000:00:03.0: 		invld_host_ava[3]   : 0x0
	[   66.159907] [1412] mem_handle_dump_pte: iluvatar-bi 0000:00:03.0: 		invld_host_ava[4]   : 0x0
	[   66.159909] [1412] mem_handle_dump_pte: iluvatar-bi 0000:00:03.0: 		invld_host_ava[5]   : 0x0
	[   66.159911] [1412] mem_handle_dump_pte: iluvatar-bi 0000:00:03.0: 		invld_host_ava[6]   : 0x0
	[   66.159914] [1412] mem_handle_dump_pte: iluvatar-bi 0000:00:03.0: 		invld_host_ava[7]   : 0x0
	[   66.159916] [1412] __mem_handle_dump: iluvatar-bi 0000:00:03.0: 	dev_va        : 0x0
	[   66.159918] [1412] __mem_handle_dump: iluvatar-bi 0000:00:03.0: 	dev_pa        : 0x0
	[   66.159920] [1412] __mem_handle_dump: iluvatar-bi 0000:00:03.0: 	refcount      : 0x0
	[   66.159923] [1412] __mem_handle_dump: iluvatar-bi 0000:00:03.0: 	destroy delay : false
	[   66.159925] [1412] __mem_handle_dump: iluvatar-bi 0000:00:03.0: 	pinned pages  : 0x0 (0, 0)
        ------------------------------------------------------------

After this patch, the log looks like this:
        ------------------------------------------------------------
	[ 8523.289844] iluvatar-bi 0000:00:03.0 [1491] bi_ioctl: : ioctl : AIP_MEM_CREATE
	[ 8523.290494] iluvatar-bi 0000:00:03.0 [1491] bi_ioctl_aip_mem_create: : start bi_ioctl_aip_mem_create
	[ 8523.290646] iluvatar-bi 0000:00:03.0 [1491] __mem_handle_dump: : [mem_handle: 0xffff888158b7ec80](bi_ioctl_aip_mem_create) vdev:0xffff8881574d9b00:8
	[ 8523.290649] iluvatar-bi 0000:00:03.0 [1491] __mem_handle_dump: : 	ctx           : 0xffff888150b3a880
	[ 8523.290651] iluvatar-bi 0000:00:03.0 [1491] __mem_handle_dump: : 	heap          : device
	[ 8523.290654] iluvatar-bi 0000:00:03.0 [1491] __mem_handle_dump: : 	flags         : user ptr:0, fence:0, exe:0
	[ 8523.290659] iluvatar-bi 0000:00:03.0 [1491] mem_handle_print_submit_refcnt: : mem_handle_print_submit_refcnt:532[mem_handle_get_submit_refcnt] mem ffff888158b7ec80, ref_cnt 0
	[ 8523.290661] iluvatar-bi 0000:00:03.0 [1491] __mem_handle_dump: : 	status        : free
	[ 8523.290664] iluvatar-bi 0000:00:03.0 [1491] __mem_handle_dump: : 	location      : un set
	[ 8523.290666] iluvatar-bi 0000:00:03.0 [1491] __mem_handle_dump: : 	size          : 0x10000, pg num 0x10
	[ 8523.290669] iluvatar-bi 0000:00:03.0 [1491] __mem_handle_dump: : 	sys va (user) : 0x0
	[ 8523.290671] iluvatar-bi 0000:00:03.0 [1491] mem_handle_dump_pte: : 		invld_host_ava[0]   : 0x0
	[ 8523.290674] iluvatar-bi 0000:00:03.0 [1491] mem_handle_dump_pte: : 		invld_host_ava[1]   : 0x0
	[ 8523.290676] iluvatar-bi 0000:00:03.0 [1491] mem_handle_dump_pte: : 		invld_host_ava[2]   : 0x0
	[ 8523.290678] iluvatar-bi 0000:00:03.0 [1491] mem_handle_dump_pte: : 		invld_host_ava[3]   : 0x0
	[ 8523.290681] iluvatar-bi 0000:00:03.0 [1491] mem_handle_dump_pte: : 		invld_host_ava[4]   : 0x0
	[ 8523.290683] iluvatar-bi 0000:00:03.0 [1491] mem_handle_dump_pte: : 		invld_host_ava[5]   : 0x0
	[ 8523.290685] iluvatar-bi 0000:00:03.0 [1491] mem_handle_dump_pte: : 		invld_host_ava[6]   : 0x0
	[ 8523.290688] iluvatar-bi 0000:00:03.0 [1491] mem_handle_dump_pte: : 		invld_host_ava[7]   : 0x0
	[ 8523.290690] iluvatar-bi 0000:00:03.0 [1491] __mem_handle_dump: : 	dev_va        : 0x0
	[ 8523.290692] iluvatar-bi 0000:00:03.0 [1491] __mem_handle_dump: : 	dev_pa        : 0x0
	[ 8523.290694] iluvatar-bi 0000:00:03.0 [1491] __mem_handle_dump: : 	refcount      : 0x0
	[ 8523.290697] iluvatar-bi 0000:00:03.0 [1491] __mem_handle_dump: : 	destroy delay : false
	[ 8523.290699] iluvatar-bi 0000:00:03.0 [1491] __mem_handle_dump: : 	pinned pages  : 0x0 (0, 0)
        ------------------------------------------------------------

IMHO, I think the log become more tidy after the patch.

Thanks
Huang Shijie

[PATCH v3] lib/dynamic_debug: make better dynamic log output

[Huang Shijie]

The driver strings, device name and net device name are not changed for
the driver's dynamic log output. But dynamic_emit_prefix() which contains
the function names may change when the function names are changed.

So the patch makes the better dynamic log output.

Signed-off-by: Huang Shijie <sjhuang@iluvatar.ai>
---
v2 -- > v3:
	change the net log and ibdev log
---
 lib/dynamic_debug.c | 12 ++++++------
 1 file changed, 6 insertions(+), 6 deletions(-)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index c60409138e13..762f718fecd9 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -589,9 +589,9 @@ void __dynamic_dev_dbg(struct _ddebug *descriptor,
 	} else {
 		char buf[PREFIX_SIZE];
 
-		dev_printk_emit(LOGLEVEL_DEBUG, dev, "%s%s %s: %pV",
-				dynamic_emit_prefix(descriptor, buf),
+		dev_printk_emit(LOGLEVEL_DEBUG, dev, "%s %s %s: %pV",
 				dev_driver_string(dev), dev_name(dev),
+				dynamic_emit_prefix(descriptor, buf),
 				&vaf);
 	}
 
@@ -619,11 +619,11 @@ void __dynamic_netdev_dbg(struct _ddebug *descriptor,
 		char buf[PREFIX_SIZE];
 
 		dev_printk_emit(LOGLEVEL_DEBUG, dev->dev.parent,
-				"%s%s %s %s%s: %pV",
-				dynamic_emit_prefix(descriptor, buf),
+				"%s %s %s %s %s: %pV",
 				dev_driver_string(dev->dev.parent),
 				dev_name(dev->dev.parent),
 				netdev_name(dev), netdev_reg_state(dev),
+				dynamic_emit_prefix(descriptor, buf),
 				&vaf);
 	} else if (dev) {
 		printk(KERN_DEBUG "%s%s: %pV", netdev_name(dev),
@@ -655,11 +655,11 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
 		char buf[PREFIX_SIZE];
 
 		dev_printk_emit(LOGLEVEL_DEBUG, ibdev->dev.parent,
-				"%s%s %s %s: %pV",
-				dynamic_emit_prefix(descriptor, buf),
+				"%s %s %s %s: %pV",
 				dev_driver_string(ibdev->dev.parent),
 				dev_name(ibdev->dev.parent),
 				dev_name(&ibdev->dev),
+				dynamic_emit_prefix(descriptor, buf),
 				&vaf);
 	} else if (ibdev) {
 		printk(KERN_DEBUG "%s: %pV", dev_name(&ibdev->dev), &vaf);
-- 
2.17.1

[PATCH v4] lib/dynamic_debug: make better dynamic log output

[Huang Shijie]

The driver strings, device name and net device name are not changed for
the driver's dynamic log output. But the dynamic_emit_prefix() which contains
the function names may change when the function names are changed.

So the patch makes the better dynamic log output.

Signed-off-by: Huang Shijie <sjhuang@iluvatar.ai>
---
v3 -- > v4:
	remove the duplicated colon.
---
 lib/dynamic_debug.c | 12 ++++++------
 1 file changed, 6 insertions(+), 6 deletions(-)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index c60409138e13..e375253c0c22 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -589,9 +589,9 @@ void __dynamic_dev_dbg(struct _ddebug *descriptor,
 	} else {
 		char buf[PREFIX_SIZE];
 
-		dev_printk_emit(LOGLEVEL_DEBUG, dev, "%s%s %s: %pV",
-				dynamic_emit_prefix(descriptor, buf),
+		dev_printk_emit(LOGLEVEL_DEBUG, dev, "%s %s %s %pV",
 				dev_driver_string(dev), dev_name(dev),
+				dynamic_emit_prefix(descriptor, buf),
 				&vaf);
 	}
 
@@ -619,11 +619,11 @@ void __dynamic_netdev_dbg(struct _ddebug *descriptor,
 		char buf[PREFIX_SIZE];
 
 		dev_printk_emit(LOGLEVEL_DEBUG, dev->dev.parent,
-				"%s%s %s %s%s: %pV",
-				dynamic_emit_prefix(descriptor, buf),
+				"%s %s %s %s %s %pV",
 				dev_driver_string(dev->dev.parent),
 				dev_name(dev->dev.parent),
 				netdev_name(dev), netdev_reg_state(dev),
+				dynamic_emit_prefix(descriptor, buf),
 				&vaf);
 	} else if (dev) {
 		printk(KERN_DEBUG "%s%s: %pV", netdev_name(dev),
@@ -655,11 +655,11 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
 		char buf[PREFIX_SIZE];
 
 		dev_printk_emit(LOGLEVEL_DEBUG, ibdev->dev.parent,
-				"%s%s %s %s: %pV",
-				dynamic_emit_prefix(descriptor, buf),
+				"%s %s %s %s %pV",
 				dev_driver_string(ibdev->dev.parent),
 				dev_name(ibdev->dev.parent),
 				dev_name(&ibdev->dev),
+				dynamic_emit_prefix(descriptor, buf),
 				&vaf);
 	} else if (ibdev) {
 		printk(KERN_DEBUG "%s: %pV", dev_name(&ibdev->dev), &vaf);
-- 
2.17.1

[PATCH v5] lib/dynamic_debug: make better dynamic log output

[Huang Shijie]

The driver strings, device name and net device name are not changed for
the driver's dynamic log output. But the dynamic_emit_prefix() which contains
the function names may change when the function names are changed.

So the patch makes the better dynamic log output.

Signed-off-by: Huang Shijie <sjhuang@iluvatar.ai>
---
v4 --> v5:
	remove the redundant whitespce in the tail.
---
 lib/dynamic_debug.c | 12 ++++++------
 1 file changed, 6 insertions(+), 6 deletions(-)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index c60409138e13..bfc3b386d603 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -589,9 +589,9 @@ void __dynamic_dev_dbg(struct _ddebug *descriptor,
 	} else {
 		char buf[PREFIX_SIZE];
 
-		dev_printk_emit(LOGLEVEL_DEBUG, dev, "%s%s %s: %pV",
-				dynamic_emit_prefix(descriptor, buf),
+		dev_printk_emit(LOGLEVEL_DEBUG, dev, "%s %s %s%pV",
 				dev_driver_string(dev), dev_name(dev),
+				dynamic_emit_prefix(descriptor, buf),
 				&vaf);
 	}
 
@@ -619,11 +619,11 @@ void __dynamic_netdev_dbg(struct _ddebug *descriptor,
 		char buf[PREFIX_SIZE];
 
 		dev_printk_emit(LOGLEVEL_DEBUG, dev->dev.parent,
-				"%s%s %s %s%s: %pV",
-				dynamic_emit_prefix(descriptor, buf),
+				"%s %s %s %s %s%pV",
 				dev_driver_string(dev->dev.parent),
 				dev_name(dev->dev.parent),
 				netdev_name(dev), netdev_reg_state(dev),
+				dynamic_emit_prefix(descriptor, buf),
 				&vaf);
 	} else if (dev) {
 		printk(KERN_DEBUG "%s%s: %pV", netdev_name(dev),
@@ -655,11 +655,11 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
 		char buf[PREFIX_SIZE];
 
 		dev_printk_emit(LOGLEVEL_DEBUG, ibdev->dev.parent,
-				"%s%s %s %s: %pV",
-				dynamic_emit_prefix(descriptor, buf),
+				"%s %s %s %s%pV",
 				dev_driver_string(ibdev->dev.parent),
 				dev_name(ibdev->dev.parent),
 				dev_name(&ibdev->dev),
+				dynamic_emit_prefix(descriptor, buf),
 				&vaf);
 	} else if (ibdev) {
 		printk(KERN_DEBUG "%s: %pV", dev_name(&ibdev->dev), &vaf);
-- 
2.17.1

Re: [PATCH v5] lib/dynamic_debug: make better dynamic log output

[Jason Baron]

On 12/19/19 2:47 AM, Huang Shijie wrote:
> The driver strings, device name and net device name are not changed for
> the driver's dynamic log output. But the dynamic_emit_prefix() which contains
> the function names may change when the function names are changed.
> 
> So the patch makes the better dynamic log output.

Another point here is that currently the output precisely matches the
non-dynamic debug counterpart strings if not prefix is emitted. So that
changes with this patch. I think its nice to say that the output is the
same as the non dynamic debug output except it may have an optional
prefix....


> 
> Signed-off-by: Huang Shijie <sjhuang@iluvatar.ai>
> ---
> v4 --> v5:
> 	remove the redundant whitespce in the tail.
> ---
>  lib/dynamic_debug.c | 12 ++++++------
>  1 file changed, 6 insertions(+), 6 deletions(-)
> 
> diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
> index c60409138e13..bfc3b386d603 100644
> --- a/lib/dynamic_debug.c
> +++ b/lib/dynamic_debug.c
> @@ -589,9 +589,9 @@ void __dynamic_dev_dbg(struct _ddebug *descriptor,
>  	} else {
>  		char buf[PREFIX_SIZE];
>  
> -		dev_printk_emit(LOGLEVEL_DEBUG, dev, "%s%s %s: %pV",
> -				dynamic_emit_prefix(descriptor, buf),
> +		dev_printk_emit(LOGLEVEL_DEBUG, dev, "%s %s %s%pV",
>  				dev_driver_string(dev), dev_name(dev),
> +				dynamic_emit_prefix(descriptor, buf),
>  				&vaf);
>  	}
>  
> @@ -619,11 +619,11 @@ void __dynamic_netdev_dbg(struct _ddebug *descriptor,
>  		char buf[PREFIX_SIZE];
>  
>  		dev_printk_emit(LOGLEVEL_DEBUG, dev->dev.parent,
> -				"%s%s %s %s%s: %pV",
> -				dynamic_emit_prefix(descriptor, buf),
> +				"%s %s %s %s %s%pV",
>  				dev_driver_string(dev->dev.parent),
>  				dev_name(dev->dev.parent),
>  				netdev_name(dev), netdev_reg_state(dev),
> +				dynamic_emit_prefix(descriptor, buf),
>  				&vaf);
>  	} else if (dev) {
>  		printk(KERN_DEBUG "%s%s: %pV", netdev_name(dev),
> @@ -655,11 +655,11 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
>  		char buf[PREFIX_SIZE];
>  
>  		dev_printk_emit(LOGLEVEL_DEBUG, ibdev->dev.parent,
> -				"%s%s %s %s: %pV",
> -				dynamic_emit_prefix(descriptor, buf),
> +				"%s %s %s %s%pV",
>  				dev_driver_string(ibdev->dev.parent),
>  				dev_name(ibdev->dev.parent),
>  				dev_name(&ibdev->dev),
> +				dynamic_emit_prefix(descriptor, buf),
>  				&vaf);
>  	} else if (ibdev) {
>  		printk(KERN_DEBUG "%s: %pV", dev_name(&ibdev->dev), &vaf);
> 

Re: [PATCH v5] lib/dynamic_debug: make better dynamic log output

[Huang Shijie]

On Thu, Dec 19, 2019 at 05:10:49PM -0500, Jason Baron wrote:
> 
> 
> On 12/19/19 2:47 AM, Huang Shijie wrote:
> > The driver strings, device name and net device name are not changed for
> > the driver's dynamic log output. But the dynamic_emit_prefix() which contains
> > the function names may change when the function names are changed.
> > 
> > So the patch makes the better dynamic log output.
> 
> Another point here is that currently the output precisely matches the
> non-dynamic debug counterpart strings if not prefix is emitted. So that
> changes with this patch. I think its nice to say that the output is the
> same as the non dynamic debug output except it may have an optional
> prefix....
okay. I will add it in the next version.

Thanks
Huang Shijie

[PATCH v6] lib/dynamic_debug: make better dynamic log output

[Huang Shijie]

The driver strings, device name and net device name are not changed for
the driver's dynamic log output. But dynamic_emit_prefix() which contains
the function names may change when the function names are changed.

So the patch makes the better dynamic log output.

And after this patch, the output is the same as the non dynamic debug output
except it may have an optional prefix.

Signed-off-by: Huang Shijie <sjhuang@iluvatar.ai>
---
v5 --> v6:
	Add more comment from Jason Baron.
---
 lib/dynamic_debug.c | 12 ++++++------
 1 file changed, 6 insertions(+), 6 deletions(-)

diff --git a/lib/dynamic_debug.c b/lib/dynamic_debug.c
index c60409138e13..bfc3b386d603 100644
--- a/lib/dynamic_debug.c
+++ b/lib/dynamic_debug.c
@@ -589,9 +589,9 @@ void __dynamic_dev_dbg(struct _ddebug *descriptor,
 	} else {
 		char buf[PREFIX_SIZE];
 
-		dev_printk_emit(LOGLEVEL_DEBUG, dev, "%s%s %s: %pV",
-				dynamic_emit_prefix(descriptor, buf),
+		dev_printk_emit(LOGLEVEL_DEBUG, dev, "%s %s %s%pV",
 				dev_driver_string(dev), dev_name(dev),
+				dynamic_emit_prefix(descriptor, buf),
 				&vaf);
 	}
 
@@ -619,11 +619,11 @@ void __dynamic_netdev_dbg(struct _ddebug *descriptor,
 		char buf[PREFIX_SIZE];
 
 		dev_printk_emit(LOGLEVEL_DEBUG, dev->dev.parent,
-				"%s%s %s %s%s: %pV",
-				dynamic_emit_prefix(descriptor, buf),
+				"%s %s %s %s %s%pV",
 				dev_driver_string(dev->dev.parent),
 				dev_name(dev->dev.parent),
 				netdev_name(dev), netdev_reg_state(dev),
+				dynamic_emit_prefix(descriptor, buf),
 				&vaf);
 	} else if (dev) {
 		printk(KERN_DEBUG "%s%s: %pV", netdev_name(dev),
@@ -655,11 +655,11 @@ void __dynamic_ibdev_dbg(struct _ddebug *descriptor,
 		char buf[PREFIX_SIZE];
 
 		dev_printk_emit(LOGLEVEL_DEBUG, ibdev->dev.parent,
-				"%s%s %s %s: %pV",
-				dynamic_emit_prefix(descriptor, buf),
+				"%s %s %s %s%pV",
 				dev_driver_string(ibdev->dev.parent),
 				dev_name(ibdev->dev.parent),
 				dev_name(&ibdev->dev),
+				dynamic_emit_prefix(descriptor, buf),
 				&vaf);
 	} else if (ibdev) {
 		printk(KERN_DEBUG "%s: %pV", dev_name(&ibdev->dev), &vaf);
-- 
2.17.1