Received-SPF: pass (google.com: best guess record for domain of linux-kernel-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) client-ip=209.132.180.67;
Content-Type: text/plain; charset="us-ascii"
Content-Disposition: inline
Date:   Wed, 11 Dec 2019 09:50:21 +0800
From:   Huang Shijie <sjhuang@iluvatar.ai>
To:     Jason Baron <jbaron@akamai.com>
CC:     <linux-kernel@vger.kernel.org>, <1537577747@qq.com>,
        Jim Cromie <jim.cromie@gmail.com>
Subject: Re: [PATCH V2] lib/dynamic_debug: make better dynamic log output
Message-ID: <20191211015021.GA2693@hsj-Precision-5520>
References: <20191209094437.14866-1-sjhuang@iluvatar.ai>
 <20191210063820.26766-1-sjhuang@iluvatar.ai>
 <f6ec7ce2-278c-4795-6f19-c31592b8868f@akamai.com>
MIME-Version: 1.0
In-Reply-To: <f6ec7ce2-278c-4795-6f19-c31592b8868f@akamai.com>
User-Agent: Mutt/1.9.4 (2018-02-28)
Sender: linux-kernel-owner@vger.kernel.org
Precedence: bulk

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