[v3,6/7] venus: Make debug infrastructure more flexible

Message ID 20200609104604.1594-7-stanimir.varbanov@linaro.org
State New
Headers show
Series
  • Venus dynamic debug
Related show

Commit Message

Stanimir Varbanov June 9, 2020, 10:46 a.m.
Here we introduce few debug macros with levels (low, medium and
high) and debug macro for firmware. Enabling the particular level
will be done by dynamic debug with levels.

For example to enable debug messages with low level:
echo 'module venus_dec level 0x01 +p' > debugfs/dynamic_debug/control

If you want to enable all levels:
echo 'module venus_dec level 0x07 +p' > debugfs/dynamic_debug/control

All the features which dynamic debugging provide are preserved.

And finaly all dev_dbg are translated to VDBGX with appropriate
debug levels.

Signed-off-by: Stanimir Varbanov <stanimir.varbanov@linaro.org>

---
 drivers/media/platform/qcom/venus/core.h      |  5 ++
 drivers/media/platform/qcom/venus/helpers.c   |  2 +-
 drivers/media/platform/qcom/venus/hfi_msgs.c  | 30 ++++-----
 drivers/media/platform/qcom/venus/hfi_venus.c | 20 ++++--
 .../media/platform/qcom/venus/pm_helpers.c    |  3 +-
 drivers/media/platform/qcom/venus/vdec.c      | 63 +++++++++++++++++--
 drivers/media/platform/qcom/venus/venc.c      |  4 ++
 7 files changed, 96 insertions(+), 31 deletions(-)

-- 
2.17.1

Comments

Greg Kroah-Hartman June 9, 2020, 11:14 a.m. | #1
On Tue, Jun 09, 2020 at 01:46:03PM +0300, Stanimir Varbanov wrote:
> Here we introduce few debug macros with levels (low, medium and

> high) and debug macro for firmware. Enabling the particular level

> will be done by dynamic debug with levels.

> 

> For example to enable debug messages with low level:

> echo 'module venus_dec level 0x01 +p' > debugfs/dynamic_debug/control

> 

> If you want to enable all levels:

> echo 'module venus_dec level 0x07 +p' > debugfs/dynamic_debug/control

> 

> All the features which dynamic debugging provide are preserved.

> 

> And finaly all dev_dbg are translated to VDBGX with appropriate

> debug levels.

> 

> Signed-off-by: Stanimir Varbanov <stanimir.varbanov@linaro.org>

> ---

>  drivers/media/platform/qcom/venus/core.h      |  5 ++

>  drivers/media/platform/qcom/venus/helpers.c   |  2 +-

>  drivers/media/platform/qcom/venus/hfi_msgs.c  | 30 ++++-----

>  drivers/media/platform/qcom/venus/hfi_venus.c | 20 ++++--

>  .../media/platform/qcom/venus/pm_helpers.c    |  3 +-

>  drivers/media/platform/qcom/venus/vdec.c      | 63 +++++++++++++++++--

>  drivers/media/platform/qcom/venus/venc.c      |  4 ++

>  7 files changed, 96 insertions(+), 31 deletions(-)

> 

> diff --git a/drivers/media/platform/qcom/venus/core.h b/drivers/media/platform/qcom/venus/core.h

> index b48782f9aa95..63eabf5ff96d 100644

> --- a/drivers/media/platform/qcom/venus/core.h

> +++ b/drivers/media/platform/qcom/venus/core.h

> @@ -15,6 +15,11 @@

>  #include "dbgfs.h"

>  #include "hfi.h"

>  

> +#define VDBGL(fmt, args...)	pr_debug_level(0x01, fmt, ##args)

> +#define VDBGM(fmt, args...)	pr_debug_level(0x02, fmt, ##args)

> +#define VDBGH(fmt, args...)	pr_debug_level(0x04, fmt, ##args)

> +#define VDBGFW(fmt, args...)	pr_debug_level(0x08, fmt, ##args)

> +

>  #define VIDC_CLKS_NUM_MAX		4

>  #define VIDC_VCODEC_CLKS_NUM_MAX	2

>  #define VIDC_PMDOMAINS_NUM_MAX		3

> diff --git a/drivers/media/platform/qcom/venus/helpers.c b/drivers/media/platform/qcom/venus/helpers.c

> index 0143af7822b2..115a9a2af1d6 100644

> --- a/drivers/media/platform/qcom/venus/helpers.c

> +++ b/drivers/media/platform/qcom/venus/helpers.c

> @@ -396,7 +396,7 @@ put_ts_metadata(struct venus_inst *inst, struct vb2_v4l2_buffer *vbuf)

>  	}

>  

>  	if (slot == -1) {

> -		dev_dbg(inst->core->dev, "%s: no free slot\n", __func__);

> +		VDBGH("no free slot for timestamp\n");


So you just lost the information that dev_dbg() gave you with regards to
the device/driver/instance creating that message?

Ick, no, don't do that.

And why is this driver somehow "special" compared to all the rest of
the kernel?  Why is the current dev_dbg() control not sufficient that
you need to change the core for just this tiny thing?

thanks,

greg k-h
Greg Kroah-Hartman June 10, 2020, 1:37 p.m. | #2
On Wed, Jun 10, 2020 at 04:29:27PM +0300, Stanimir Varbanov wrote:
> 

> 

> On 6/9/20 2:14 PM, Greg Kroah-Hartman wrote:

> > On Tue, Jun 09, 2020 at 01:46:03PM +0300, Stanimir Varbanov wrote:

> >> Here we introduce few debug macros with levels (low, medium and

> >> high) and debug macro for firmware. Enabling the particular level

> >> will be done by dynamic debug with levels.

> >>

> >> For example to enable debug messages with low level:

> >> echo 'module venus_dec level 0x01 +p' > debugfs/dynamic_debug/control

> >>

> >> If you want to enable all levels:

> >> echo 'module venus_dec level 0x07 +p' > debugfs/dynamic_debug/control

> >>

> >> All the features which dynamic debugging provide are preserved.

> >>

> >> And finaly all dev_dbg are translated to VDBGX with appropriate

> >> debug levels.

> >>

> >> Signed-off-by: Stanimir Varbanov <stanimir.varbanov@linaro.org>

> >> ---

> >>  drivers/media/platform/qcom/venus/core.h      |  5 ++

> >>  drivers/media/platform/qcom/venus/helpers.c   |  2 +-

> >>  drivers/media/platform/qcom/venus/hfi_msgs.c  | 30 ++++-----

> >>  drivers/media/platform/qcom/venus/hfi_venus.c | 20 ++++--

> >>  .../media/platform/qcom/venus/pm_helpers.c    |  3 +-

> >>  drivers/media/platform/qcom/venus/vdec.c      | 63 +++++++++++++++++--

> >>  drivers/media/platform/qcom/venus/venc.c      |  4 ++

> >>  7 files changed, 96 insertions(+), 31 deletions(-)

> >>

> >> diff --git a/drivers/media/platform/qcom/venus/core.h b/drivers/media/platform/qcom/venus/core.h

> >> index b48782f9aa95..63eabf5ff96d 100644

> >> --- a/drivers/media/platform/qcom/venus/core.h

> >> +++ b/drivers/media/platform/qcom/venus/core.h

> >> @@ -15,6 +15,11 @@

> >>  #include "dbgfs.h"

> >>  #include "hfi.h"

> >>  

> >> +#define VDBGL(fmt, args...)	pr_debug_level(0x01, fmt, ##args)

> >> +#define VDBGM(fmt, args...)	pr_debug_level(0x02, fmt, ##args)

> >> +#define VDBGH(fmt, args...)	pr_debug_level(0x04, fmt, ##args)

> >> +#define VDBGFW(fmt, args...)	pr_debug_level(0x08, fmt, ##args)

> >> +

> >>  #define VIDC_CLKS_NUM_MAX		4

> >>  #define VIDC_VCODEC_CLKS_NUM_MAX	2

> >>  #define VIDC_PMDOMAINS_NUM_MAX		3

> >> diff --git a/drivers/media/platform/qcom/venus/helpers.c b/drivers/media/platform/qcom/venus/helpers.c

> >> index 0143af7822b2..115a9a2af1d6 100644

> >> --- a/drivers/media/platform/qcom/venus/helpers.c

> >> +++ b/drivers/media/platform/qcom/venus/helpers.c

> >> @@ -396,7 +396,7 @@ put_ts_metadata(struct venus_inst *inst, struct vb2_v4l2_buffer *vbuf)

> >>  	}

> >>  

> >>  	if (slot == -1) {

> >> -		dev_dbg(inst->core->dev, "%s: no free slot\n", __func__);

> >> +		VDBGH("no free slot for timestamp\n");

> > 

> > So you just lost the information that dev_dbg() gave you with regards to

> > the device/driver/instance creating that message?

> 

> No, I don't lose anything.  When I do debug I know that all debug

> messages comes from my driver.  dev_dbg will give me few device

> identifiers which I don't care so much.


No, you need/want that, trust me.

> IMO, the device information makes more sense to dev_err/warn/err

> variants.  On the other side we will have dev_dbg_level(group) if

> still someone needs the device information.


You really want those "gerneric identifiers" as tools today are built to
properly parse and handle them to be able to match and filter on what
device/driver is causing what issue.

Please do not try to create driver-specific prefixes instead, use the
standard the rest of the kernel uses, your driver is not "special" in
this case at all.

> > Ick, no, don't do that.

> > 

> > And why is this driver somehow "special" compared to all the rest of

> 

> Of course it is special ... to me ;-)


Yes, "special and unique" like all other drivers in the kernel :)

Please work with the infrastructure we have, we have spent a lot of time
and effort to make it uniform to make it easier for users and
developers.  Don't regress and try to make driver-specific ways of doing
things, that way lies madness...

thanks,

greg k-h
Joe Perches June 10, 2020, 7:49 p.m. | #3
On Wed, 2020-06-10 at 15:37 +0200, Greg Kroah-Hartman wrote:
> Please work with the infrastructure we have, we have spent a lot of time
> and effort to make it uniform to make it easier for users and
> developers.

Not quite.

This lack of debug grouping by type has been a
_long_ standing issue with drivers.

> Don't regress and try to make driver-specific ways of doing
> things, that way lies madness...

It's not driver specific, it allows driver developers to
better isolate various debug states instead of keeping
lists of specific debug messages and enabling them
individually.
Joe Perches June 10, 2020, 8:23 p.m. | #4
On Wed, 2020-06-10 at 12:49 -0700, Joe Perches wrote:
> On Wed, 2020-06-10 at 15:37 +0200, Greg Kroah-Hartman wrote:

> > Please work with the infrastructure we have, we have spent a lot of time

> > and effort to make it uniform to make it easier for users and

> > developers.

> 

> Not quite.

> 

> This lack of debug grouping by type has been a

> _long_ standing issue with drivers.

> 

> > Don't regress and try to make driver-specific ways of doing

> > things, that way lies madness...

> 

> It's not driver specific, it allows driver developers to

> better isolate various debug states instead of keeping

> lists of specific debug messages and enabling them

> individually.


For instance, look at the homebrew content in
drivers/gpu/drm/drm_print.c that does _not_ use
dynamic_debug.

MODULE_PARM_DESC(debug, "Enable debug output, where each bit enables a debug category.\n"
"\t\tBit 0 (0x01)  will enable CORE messages (drm core code)\n"
"\t\tBit 1 (0x02)  will enable DRIVER messages (drm controller code)\n"
"\t\tBit 2 (0x04)  will enable KMS messages (modesetting code)\n"
"\t\tBit 3 (0x08)  will enable PRIME messages (prime code)\n"
"\t\tBit 4 (0x10)  will enable ATOMIC messages (atomic code)\n"
"\t\tBit 5 (0x20)  will enable VBL messages (vblank code)\n"
"\t\tBit 7 (0x80)  will enable LEASE messages (leasing code)\n"
"\t\tBit 8 (0x100) will enable DP messages (displayport code)");
module_param_named(debug, __drm_debug, int, 0600);

void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
		 const char *format, ...)
{
	struct va_format vaf;
	va_list args;

	if (!drm_debug_enabled(category))
		return;
Greg Kroah-Hartman June 11, 2020, 6:26 a.m. | #5
On Wed, Jun 10, 2020 at 01:23:56PM -0700, Joe Perches wrote:
> On Wed, 2020-06-10 at 12:49 -0700, Joe Perches wrote:
> > On Wed, 2020-06-10 at 15:37 +0200, Greg Kroah-Hartman wrote:
> > > Please work with the infrastructure we have, we have spent a lot of time
> > > and effort to make it uniform to make it easier for users and
> > > developers.
> > 
> > Not quite.
> > 
> > This lack of debug grouping by type has been a
> > _long_ standing issue with drivers.
> > 
> > > Don't regress and try to make driver-specific ways of doing
> > > things, that way lies madness...
> > 
> > It's not driver specific, it allows driver developers to
> > better isolate various debug states instead of keeping
> > lists of specific debug messages and enabling them
> > individually.
> 
> For instance, look at the homebrew content in
> drivers/gpu/drm/drm_print.c that does _not_ use
> dynamic_debug.
> 
> MODULE_PARM_DESC(debug, "Enable debug output, where each bit enables a debug category.\n"
> "\t\tBit 0 (0x01)  will enable CORE messages (drm core code)\n"
> "\t\tBit 1 (0x02)  will enable DRIVER messages (drm controller code)\n"
> "\t\tBit 2 (0x04)  will enable KMS messages (modesetting code)\n"
> "\t\tBit 3 (0x08)  will enable PRIME messages (prime code)\n"
> "\t\tBit 4 (0x10)  will enable ATOMIC messages (atomic code)\n"
> "\t\tBit 5 (0x20)  will enable VBL messages (vblank code)\n"
> "\t\tBit 7 (0x80)  will enable LEASE messages (leasing code)\n"
> "\t\tBit 8 (0x100) will enable DP messages (displayport code)");
> module_param_named(debug, __drm_debug, int, 0600);
> 
> void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> 		 const char *format, ...)
> {
> 	struct va_format vaf;
> 	va_list args;
> 
> 	if (!drm_debug_enabled(category))
> 		return;
> 
> 

Ok, and will this proposal be able to handle stuff like this?  If not,
then it is yet another way for driver authors to think that they need to
come up with something unique to themselves. :(

greg k-h
Stanimir Varbanov June 11, 2020, 11:31 a.m. | #6
On 6/11/20 1:52 PM, Daniel Thompson wrote:
> On Wed, Jun 10, 2020 at 11:42:43PM -0700, Joe Perches wrote:
>> On Thu, 2020-06-11 at 08:26 +0200, Greg Kroah-Hartman wrote:
>>> On Wed, Jun 10, 2020 at 01:23:56PM -0700, Joe Perches wrote:
>>>> On Wed, 2020-06-10 at 12:49 -0700, Joe Perches wrote:
>>>>> On Wed, 2020-06-10 at 15:37 +0200, Greg Kroah-Hartman wrote:
>>>>>> Please work with the infrastructure we have, we have spent a lot of time
>>>>>> and effort to make it uniform to make it easier for users and
>>>>>> developers.
>>>>>
>>>>> Not quite.
>>>>>
>>>>> This lack of debug grouping by type has been a
>>>>> _long_ standing issue with drivers.
>>>>>
>>>>>> Don't regress and try to make driver-specific ways of doing
>>>>>> things, that way lies madness...
>>>>>
>>>>> It's not driver specific, it allows driver developers to
>>>>> better isolate various debug states instead of keeping
>>>>> lists of specific debug messages and enabling them
>>>>> individually.
>>>>
>>>> For instance, look at the homebrew content in
>>>> drivers/gpu/drm/drm_print.c that does _not_ use
>>>> dynamic_debug.
>>>>
>>>> MODULE_PARM_DESC(debug, "Enable debug output, where each bit enables a debug category.\n"
>>>> "\t\tBit 0 (0x01)  will enable CORE messages (drm core code)\n"
>>>> "\t\tBit 1 (0x02)  will enable DRIVER messages (drm controller code)\n"
>>>> "\t\tBit 2 (0x04)  will enable KMS messages (modesetting code)\n"
>>>> "\t\tBit 3 (0x08)  will enable PRIME messages (prime code)\n"
>>>> "\t\tBit 4 (0x10)  will enable ATOMIC messages (atomic code)\n"
>>>> "\t\tBit 5 (0x20)  will enable VBL messages (vblank code)\n"
>>>> "\t\tBit 7 (0x80)  will enable LEASE messages (leasing code)\n"
>>>> "\t\tBit 8 (0x100) will enable DP messages (displayport code)");
>>>> module_param_named(debug, __drm_debug, int, 0600);
>>>>
>>>> void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
>>>> 		 const char *format, ...)
>>>> {
>>>> 	struct va_format vaf;
>>>> 	va_list args;
>>>>
>>>> 	if (!drm_debug_enabled(category))
>>>> 		return;
>>>
>>> Ok, and will this proposal be able to handle stuff like this?
>>
>> Yes, that's the entire point.
> 
> Currently I think there not enough "levels" to map something like
> drm.debug to the new dyn dbg feature. I don't think it is intrinsic
> but I couldn't find the bit of the code where the 5-bit level in struct
> _ddebug is converted from a mask to a bit number and vice-versa.

Here [1] is Joe's initial suggestion. But I decided that bitmask is a
good start for the discussion.

I guess we can add new member uint "level" in struct _ddebug so that we
can cover more "levels" (types, groups).
Daniel Thompson June 11, 2020, 12:18 p.m. | #7
On Thu, Jun 11, 2020 at 02:31:07PM +0300, Stanimir Varbanov wrote:
> On 6/11/20 1:52 PM, Daniel Thompson wrote:
> > On Wed, Jun 10, 2020 at 11:42:43PM -0700, Joe Perches wrote:
> >> On Thu, 2020-06-11 at 08:26 +0200, Greg Kroah-Hartman wrote:
> >>> On Wed, Jun 10, 2020 at 01:23:56PM -0700, Joe Perches wrote:
> >>>> On Wed, 2020-06-10 at 12:49 -0700, Joe Perches wrote:
> >>>>> On Wed, 2020-06-10 at 15:37 +0200, Greg Kroah-Hartman wrote:
> >>>>>> Please work with the infrastructure we have, we have spent a lot of time
> >>>>>> and effort to make it uniform to make it easier for users and
> >>>>>> developers.
> >>>>>
> >>>>> Not quite.
> >>>>>
> >>>>> This lack of debug grouping by type has been a
> >>>>> _long_ standing issue with drivers.
> >>>>>
> >>>>>> Don't regress and try to make driver-specific ways of doing
> >>>>>> things, that way lies madness...
> >>>>>
> >>>>> It's not driver specific, it allows driver developers to
> >>>>> better isolate various debug states instead of keeping
> >>>>> lists of specific debug messages and enabling them
> >>>>> individually.
> >>>>
> >>>> For instance, look at the homebrew content in
> >>>> drivers/gpu/drm/drm_print.c that does _not_ use
> >>>> dynamic_debug.
> >>>>
> >>>> MODULE_PARM_DESC(debug, "Enable debug output, where each bit enables a debug category.\n"
> >>>> "\t\tBit 0 (0x01)  will enable CORE messages (drm core code)\n"
> >>>> "\t\tBit 1 (0x02)  will enable DRIVER messages (drm controller code)\n"
> >>>> "\t\tBit 2 (0x04)  will enable KMS messages (modesetting code)\n"
> >>>> "\t\tBit 3 (0x08)  will enable PRIME messages (prime code)\n"
> >>>> "\t\tBit 4 (0x10)  will enable ATOMIC messages (atomic code)\n"
> >>>> "\t\tBit 5 (0x20)  will enable VBL messages (vblank code)\n"
> >>>> "\t\tBit 7 (0x80)  will enable LEASE messages (leasing code)\n"
> >>>> "\t\tBit 8 (0x100) will enable DP messages (displayport code)");
> >>>> module_param_named(debug, __drm_debug, int, 0600);
> >>>>
> >>>> void drm_dev_dbg(const struct device *dev, enum drm_debug_category category,
> >>>> 		 const char *format, ...)
> >>>> {
> >>>> 	struct va_format vaf;
> >>>> 	va_list args;
> >>>>
> >>>> 	if (!drm_debug_enabled(category))
> >>>> 		return;
> >>>
> >>> Ok, and will this proposal be able to handle stuff like this?
> >>
> >> Yes, that's the entire point.
> > 
> > Currently I think there not enough "levels" to map something like
> > drm.debug to the new dyn dbg feature. I don't think it is intrinsic
> > but I couldn't find the bit of the code where the 5-bit level in struct
> > _ddebug is converted from a mask to a bit number and vice-versa.
> 
> Here [1] is Joe's initial suggestion. But I decided that bitmask is a
> good start for the discussion.
> 
> I guess we can add new member uint "level" in struct _ddebug so that we
> can cover more "levels" (types, groups).

I don't think it is allocating only 5 bits that is the problem!

The problem is that those 5 bits need not be encoded as a bitmask by
dyndbg, that can simply be the category code for the message. They only
need be converted into a mask when we compare them to the mask provided
by the user.


Daniel.
jim.cromie@gmail.com June 11, 2020, 9:19 p.m. | #8
trimmed..

> > > Currently I think there not enough "levels" to map something like

> > > drm.debug to the new dyn dbg feature. I don't think it is intrinsic

> > > but I couldn't find the bit of the code where the 5-bit level in struct

> > > _ddebug is converted from a mask to a bit number and vice-versa.

> >

> > Here [1] is Joe's initial suggestion. But I decided that bitmask is a

> > good start for the discussion.

> >

> > I guess we can add new member uint "level" in struct _ddebug so that we

> > can cover more "levels" (types, groups).

>

> I don't think it is allocating only 5 bits that is the problem!

>

> The problem is that those 5 bits need not be encoded as a bitmask by

> dyndbg, that can simply be the category code for the message. They only

> need be converted into a mask when we compare them to the mask provided

> by the user.

>

>

> Daniel.



heres what I have in mind.  whats described here is working.
I'll send it out soon

commit 20298ec88cc2ed64269c8be7b287a24e60a5347e
Author: Jim Cromie <jim.cromie@gmail.com>
Date:   Wed Jun 10 12:55:08 2020 -0600

    dyndbg: WIP towards module->debugflags based callsite controls

    There are *lots* of ad-hoc debug printing solutions in kernel,
    this is a 1st attempt at providing a common mechanism for many of them.

    Basically, there are 2 styles of debug printing:
    - levels, with increasing verbosity, 1-10 forex
    - bits/flags, independently controlling separate groups of dprints

    This patch does bits/flags (with no distinction made yet between 2)

    API:

    - change pr_debug(...)  -->  pr_debug_typed(type_id=0, ...)
    - all existing uses have type_id=0
    - developer creates exclusive types of log messages with type_id>0
      1, 2, 3 are disjoint groups, for example: hi, mid, low

    - !!type_id is just an additional callsite selection criterion

      Qfoo() { echo module foo $* >/proc/dynamic_debug/control }
      Qfoo +p               # all groups, including default 0
      Qfoo mflags 1 +p      # only group 1
      Qfoo mflags 12 +p     # TBD[1]: groups 1 or 2
      Qfoo mflags 0 +p      # ignored atm TBD[2]
      Qfoo mflags af +p     # TBD[3]: groups a or f (10 or 15)

    so patch does:

    - add u32 debugflags to struct module. Each bit is a separate print-class.

    - add unsigned int mflags into struct ddebug_query
      mflags matched in ddebug_change

    - add unsigned int type_id:5 to struct _ddebug
      picks a single debugflag bit.  No subclass or multitype nonsense.
      nice and dense, packs with other members.
      we will have a lot of struct _ddebugs.

    - in ddebug_change()
      filter on !! module->debugflags,
      IFF query->module is given, and matches dt->mod_name
      and query->mflags is given, and bitmatches module->debugflags

    - in parse_query()
      accept new query term: mflags $arg
      populate query->mflags
      arg-type needs some attention, but basic plumbing is there

    WIP: not included:

    - pr_debug_typed( bitpos=0, ....)
      aka: pr_debug_class() or pr_debug_id()
      the bitpos is 1<<shift, allowing a single type. no ISA relations.
      this covers OP's high,mid,low case, many others

    - no way to exersize new code in ddebug_change
      need pr_debug_typed() to make a (not-null) typed callsite.
      also no way to set module->debugflags

    Im relying on:
    cdf6d00696 dynamic_debug: don't duplicate modname in ddebug_add_module

    which copies the ptr-val from module->name to dt->mod_name, which
    allowed == tests instead of strcmp.

    That equivalence and a (void*) cast in use of container_of() seem to
    do the trick to get the module, then module->debugflags.

    Notes:

    1- A query ANDs all its query terms together, so Qfoo() above
    requires both "module foo" AND all additional query terms given in $*

    But since callsite type_id creates disjoint groups, "mflags 12" is
    nonsense if it means groups 1 AND 2.  Here, 1 OR 2 is meaningful, if
    its not judged to be too confusing.

    2- im not sure what this does atm, or should do
       Qfoo mflags 0 +p      # select only untyped ? or no flags check at all ?

    3- since modflags has 32 bits, [1-9a-v] could select any single type_id
       it is succinct, but arcane.
       its a crude alphanumeric map for developers to make flags mnemonic
       maybe query keyword should be mbits
Joe Perches June 11, 2020, 10:33 p.m. | #9
On Thu, 2020-06-11 at 17:59 -0400, Jason Baron wrote:
> 
> On 6/11/20 5:19 PM, jim.cromie@gmail.com wrote:
> > trimmed..
> > 
> > > > > Currently I think there not enough "levels" to map something like
> > > > > drm.debug to the new dyn dbg feature. I don't think it is intrinsic
> > > > > but I couldn't find the bit of the code where the 5-bit level in struct
> > > > > _ddebug is converted from a mask to a bit number and vice-versa.
> > > > 
> > > > Here [1] is Joe's initial suggestion. But I decided that bitmask is a
> > > > good start for the discussion.
> > > > 
> > > > I guess we can add new member uint "level" in struct _ddebug so that we
> > > > can cover more "levels" (types, groups).
> > > 
> > > I don't think it is allocating only 5 bits that is the problem!

There were 6 unused bits in struct _ddebug;

The original idea was to avoid expanding the already somewhat
large struct _ddebug uses and the __verbose/__dyndbg section
that can have quite a lot of these structs.

I imagine adding another int or long wouldn't be too bad.

> > > The problem is that those 5 bits need not be encoded as a bitmask by
> > > dyndbg, that can simply be the category code for the message. They only
> > > need be converted into a mask when we compare them to the mask provided
> > > by the user.
> > > 

I also suggested adding a pointer to whatever is provided
by the developer so the address of something like
MODULE_PARM_DESC(variable, ...) can be also be used.

> > heres what I have in mind.  whats described here is working.
> > I'll send it out soon
> 
> Cool. thanks for working on this!

Truly, thank you both Jim and Stanimir.

Please remember that dynamic_debug is not required and
pr_debug should still work.

> >     API:
> > 
> >     - change pr_debug(...)  -->  pr_debug_typed(type_id=0, ...)
> >     - all existing uses have type_id=0
> >     - developer creates exclusive types of log messages with type_id>0
> >       1, 2, 3 are disjoint groups, for example: hi, mid, low

You could have a u8 for type if there are to be 3 classes

	bitmask
	level
	group by value

though I believe group by value might as well just be bitmask
and bool is_bitmask is enough (!is_bitmask would be level)

cheers, Joe

Patch

diff --git a/drivers/media/platform/qcom/venus/core.h b/drivers/media/platform/qcom/venus/core.h
index b48782f9aa95..63eabf5ff96d 100644
--- a/drivers/media/platform/qcom/venus/core.h
+++ b/drivers/media/platform/qcom/venus/core.h
@@ -15,6 +15,11 @@ 
 #include "dbgfs.h"
 #include "hfi.h"
 
+#define VDBGL(fmt, args...)	pr_debug_level(0x01, fmt, ##args)
+#define VDBGM(fmt, args...)	pr_debug_level(0x02, fmt, ##args)
+#define VDBGH(fmt, args...)	pr_debug_level(0x04, fmt, ##args)
+#define VDBGFW(fmt, args...)	pr_debug_level(0x08, fmt, ##args)
+
 #define VIDC_CLKS_NUM_MAX		4
 #define VIDC_VCODEC_CLKS_NUM_MAX	2
 #define VIDC_PMDOMAINS_NUM_MAX		3
diff --git a/drivers/media/platform/qcom/venus/helpers.c b/drivers/media/platform/qcom/venus/helpers.c
index 0143af7822b2..115a9a2af1d6 100644
--- a/drivers/media/platform/qcom/venus/helpers.c
+++ b/drivers/media/platform/qcom/venus/helpers.c
@@ -396,7 +396,7 @@  put_ts_metadata(struct venus_inst *inst, struct vb2_v4l2_buffer *vbuf)
 	}
 
 	if (slot == -1) {
-		dev_dbg(inst->core->dev, "%s: no free slot\n", __func__);
+		VDBGH("no free slot for timestamp\n");
 		return;
 	}
 
diff --git a/drivers/media/platform/qcom/venus/hfi_msgs.c b/drivers/media/platform/qcom/venus/hfi_msgs.c
index 279a9d6fe737..36986d402c96 100644
--- a/drivers/media/platform/qcom/venus/hfi_msgs.c
+++ b/drivers/media/platform/qcom/venus/hfi_msgs.c
@@ -138,10 +138,9 @@  static void event_sys_error(struct venus_core *core, u32 event,
 			    struct hfi_msg_event_notify_pkt *pkt)
 {
 	if (pkt)
-		dev_dbg(core->dev,
-			"sys error (session id:%x, data1:%x, data2:%x)\n",
-			pkt->shdr.session_id, pkt->event_data1,
-			pkt->event_data2);
+		VDBGH("sys error (session id: %x, data1: %x, data2: %x)\n",
+		      pkt->shdr.session_id, pkt->event_data1,
+		      pkt->event_data2);
 
 	core->core_ops->event_notify(core, event);
 }
@@ -152,8 +151,8 @@  event_session_error(struct venus_core *core, struct venus_inst *inst,
 {
 	struct device *dev = core->dev;
 
-	dev_dbg(dev, "session error: event id:%x, session id:%x\n",
-		pkt->event_data1, pkt->shdr.session_id);
+	VDBGH("session error: event id: %x, session id: %x\n",
+	      pkt->event_data1, pkt->shdr.session_id);
 
 	if (!inst)
 		return;
@@ -236,8 +235,7 @@  static void hfi_sys_init_done(struct venus_core *core, struct venus_inst *inst,
 }
 
 static void
-sys_get_prop_image_version(struct device *dev,
-			   struct hfi_msg_sys_property_info_pkt *pkt)
+sys_get_prop_image_version(struct hfi_msg_sys_property_info_pkt *pkt)
 {
 	int req_bytes;
 
@@ -247,26 +245,25 @@  sys_get_prop_image_version(struct device *dev,
 		/* bad packet */
 		return;
 
-	dev_dbg(dev, "F/W version: %s\n", (u8 *)&pkt->data[1]);
+	VDBGL("F/W version: %s\n", (u8 *)&pkt->data[1]);
 }
 
 static void hfi_sys_property_info(struct venus_core *core,
 				  struct venus_inst *inst, void *packet)
 {
 	struct hfi_msg_sys_property_info_pkt *pkt = packet;
-	struct device *dev = core->dev;
 
 	if (!pkt->num_properties) {
-		dev_dbg(dev, "%s: no properties\n", __func__);
+		VDBGM("no properties\n");
 		return;
 	}
 
 	switch (pkt->data[0]) {
 	case HFI_PROPERTY_SYS_IMAGE_VERSION:
-		sys_get_prop_image_version(dev, pkt);
+		sys_get_prop_image_version(pkt);
 		break;
 	default:
-		dev_dbg(dev, "%s: unknown property data\n", __func__);
+		VDBGM("unknown property data\n");
 		break;
 	}
 }
@@ -297,7 +294,7 @@  static void hfi_sys_ping_done(struct venus_core *core, struct venus_inst *inst,
 static void hfi_sys_idle_done(struct venus_core *core, struct venus_inst *inst,
 			      void *packet)
 {
-	dev_dbg(core->dev, "sys idle\n");
+	VDBGL("sys idle\n");
 }
 
 static void hfi_sys_pc_prepare_done(struct venus_core *core,
@@ -305,7 +302,7 @@  static void hfi_sys_pc_prepare_done(struct venus_core *core,
 {
 	struct hfi_msg_sys_pc_prep_done_pkt *pkt = packet;
 
-	dev_dbg(core->dev, "pc prepare done (error %x)\n", pkt->error_type);
+	VDBGL("pc prepare done (error %x)\n", pkt->error_type);
 }
 
 static unsigned int
@@ -387,8 +384,7 @@  static void hfi_session_prop_info(struct venus_core *core,
 	case HFI_PROPERTY_CONFIG_VDEC_ENTROPY:
 		break;
 	default:
-		dev_dbg(dev, "%s: unknown property id:%x\n", __func__,
-			pkt->data[0]);
+		VDBGH("unknown property id: %x\n", pkt->data[0]);
 		return;
 	}
 
diff --git a/drivers/media/platform/qcom/venus/hfi_venus.c b/drivers/media/platform/qcom/venus/hfi_venus.c
index 3a04b08ab85a..9aef62f9b59a 100644
--- a/drivers/media/platform/qcom/venus/hfi_venus.c
+++ b/drivers/media/platform/qcom/venus/hfi_venus.c
@@ -467,7 +467,6 @@  static int venus_boot_core(struct venus_hfi_device *hdev)
 
 static u32 venus_hwversion(struct venus_hfi_device *hdev)
 {
-	struct device *dev = hdev->core->dev;
 	u32 ver = venus_readl(hdev, WRAPPER_HW_VERSION);
 	u32 major, minor, step;
 
@@ -477,7 +476,7 @@  static u32 venus_hwversion(struct venus_hfi_device *hdev)
 	minor = minor >> WRAPPER_HW_VERSION_MINOR_VERSION_SHIFT;
 	step = ver & WRAPPER_HW_VERSION_STEP_VERSION_MASK;
 
-	dev_dbg(dev, "venus hw version %x.%x.%x\n", major, minor, step);
+	VDBGL("venus hw version %x.%x.%x\n", major, minor, step);
 
 	return major;
 }
@@ -897,7 +896,6 @@  static int venus_session_cmd(struct venus_inst *inst, u32 pkt_type)
 
 static void venus_flush_debug_queue(struct venus_hfi_device *hdev)
 {
-	struct device *dev = hdev->core->dev;
 	void *packet = hdev->dbg_buf;
 
 	while (!venus_iface_dbgq_read(hdev, packet)) {
@@ -906,7 +904,7 @@  static void venus_flush_debug_queue(struct venus_hfi_device *hdev)
 		if (pkt->hdr.pkt_type != HFI_MSG_SYS_COV) {
 			struct hfi_msg_sys_debug_pkt *pkt = packet;
 
-			dev_dbg(dev, "%s", pkt->msg_data);
+			VDBGFW("%s", pkt->msg_data);
 		}
 	}
 }
@@ -1230,6 +1228,11 @@  static int venus_session_etb(struct venus_inst *inst,
 		ret = -EINVAL;
 	}
 
+	VDBGM("etb: %s: itag: %u, flen: %u, addr: %x\n",
+	      session_type == VIDC_SESSION_TYPE_DEC ? "dec" : "enc",
+	      in_frame->clnt_data, in_frame->filled_len,
+	      in_frame->device_addr);
+
 	return ret;
 }
 
@@ -1244,7 +1247,14 @@  static int venus_session_ftb(struct venus_inst *inst,
 	if (ret)
 		return ret;
 
-	return venus_iface_cmdq_write(hdev, &pkt);
+	ret = venus_iface_cmdq_write(hdev, &pkt);
+
+	VDBGM("ftb: %s: otag: %u, flen: %u, addr: %x\n",
+	      inst->session_type == VIDC_SESSION_TYPE_DEC ? "dec" : "enc",
+	      out_frame->clnt_data, out_frame->filled_len,
+	      out_frame->device_addr);
+
+	return ret;
 }
 
 static int venus_session_set_buffers(struct venus_inst *inst,
diff --git a/drivers/media/platform/qcom/venus/pm_helpers.c b/drivers/media/platform/qcom/venus/pm_helpers.c
index abf93158857b..ec7394615ef8 100644
--- a/drivers/media/platform/qcom/venus/pm_helpers.c
+++ b/drivers/media/platform/qcom/venus/pm_helpers.c
@@ -212,8 +212,7 @@  static int load_scale_bw(struct venus_core *core)
 	}
 	mutex_unlock(&core->lock);
 
-	dev_dbg(core->dev, "total: avg_bw: %u, peak_bw: %u\n",
-		total_avg, total_peak);
+	VDBGL("total: avg_bw: %u, peak_bw: %u\n", total_avg, total_peak);
 
 	return icc_set_bw(core->video_path, total_avg, total_peak);
 }
diff --git a/drivers/media/platform/qcom/venus/vdec.c b/drivers/media/platform/qcom/venus/vdec.c
index 7c4c483d5438..7959e452fbf3 100644
--- a/drivers/media/platform/qcom/venus/vdec.c
+++ b/drivers/media/platform/qcom/venus/vdec.c
@@ -225,7 +225,7 @@  static int vdec_check_src_change(struct venus_inst *inst)
 
 	if (!(inst->codec_state == VENUS_DEC_STATE_CAPTURE_SETUP) ||
 	    !inst->reconfig)
-		dev_dbg(inst->core->dev, "%s: wrong state\n", __func__);
+		VDBGM("wrong codec state %u\n", inst->codec_state);
 
 done:
 	return 0;
@@ -790,6 +790,10 @@  static int vdec_queue_setup(struct vb2_queue *q,
 	unsigned int in_num, out_num;
 	int ret = 0;
 
+	VDBGM("vb2: queue_setup: %s: begin (codec_state: %u)\n",
+	      V4L2_TYPE_IS_OUTPUT(q->type) ? "out" : "cap",
+	      inst->codec_state);
+
 	if (*num_planes) {
 		unsigned int output_buf_size = venus_helper_get_opb_size(inst);
 
@@ -859,6 +863,10 @@  static int vdec_queue_setup(struct vb2_queue *q,
 		break;
 	}
 
+	VDBGM("vb2: queue_setup: %s: end (codec_state: %u, ret: %d)\n",
+	      V4L2_TYPE_IS_OUTPUT(q->type) ? "out" : "cap",
+	      inst->codec_state, ret);
+
 	return ret;
 
 put_power:
@@ -897,6 +905,8 @@  static int vdec_start_capture(struct venus_inst *inst)
 {
 	int ret;
 
+	VDBGM("on: cap: begin (codec_state: %u)\n", inst->codec_state);
+
 	if (!inst->streamon_out)
 		return 0;
 
@@ -955,11 +965,16 @@  static int vdec_start_capture(struct venus_inst *inst)
 	inst->sequence_cap = 0;
 	inst->reconfig = false;
 
+	VDBGM("on: cap: end (codec_state: %u)\n", inst->codec_state);
+
 	return 0;
 
 free_dpb_bufs:
 	venus_helper_free_dpb_bufs(inst);
 err:
+	VDBGM("on: cap: end (codec_state: %u, ret: %d)\n",
+	      inst->codec_state, ret);
+
 	return ret;
 }
 
@@ -967,6 +982,8 @@  static int vdec_start_output(struct venus_inst *inst)
 {
 	int ret;
 
+	VDBGM("on: out: begin (codec_state: %u)\n", inst->codec_state);
+
 	if (inst->codec_state == VENUS_DEC_STATE_SEEK) {
 		ret = venus_helper_process_initial_out_bufs(inst);
 		inst->codec_state = VENUS_DEC_STATE_DECODING;
@@ -1015,6 +1032,10 @@  static int vdec_start_output(struct venus_inst *inst)
 
 done:
 	inst->streamon_out = 1;
+
+	VDBGM("on: out: end (codec_state: %u, ret: %d)\n",
+	      inst->codec_state, ret);
+
 	return ret;
 }
 
@@ -1069,6 +1090,8 @@  static int vdec_stop_capture(struct venus_inst *inst)
 {
 	int ret = 0;
 
+	VDBGM("off: cap: begin (codec_state: %u)\n", inst->codec_state);
+
 	switch (inst->codec_state) {
 	case VENUS_DEC_STATE_DECODING:
 		ret = hfi_session_flush(inst, HFI_FLUSH_ALL, true);
@@ -1090,6 +1113,9 @@  static int vdec_stop_capture(struct venus_inst *inst)
 
 	INIT_LIST_HEAD(&inst->registeredbufs);
 
+	VDBGM("off: cap: end (codec_state: %u, ret: %d)\n",
+	      inst->codec_state, ret);
+
 	return ret;
 }
 
@@ -1097,6 +1123,8 @@  static int vdec_stop_output(struct venus_inst *inst)
 {
 	int ret = 0;
 
+	VDBGM("off: out: begin (codec_state: %u)\n", inst->codec_state);
+
 	switch (inst->codec_state) {
 	case VENUS_DEC_STATE_DECODING:
 	case VENUS_DEC_STATE_DRAIN:
@@ -1112,6 +1140,9 @@  static int vdec_stop_output(struct venus_inst *inst)
 		break;
 	}
 
+	VDBGM("off: out: end (codec_state: %u, ret %d)\n",
+	      inst->codec_state, ret);
+
 	return ret;
 }
 
@@ -1146,6 +1177,8 @@  static void vdec_session_release(struct venus_inst *inst)
 	struct venus_core *core = inst->core;
 	int ret, abort = 0;
 
+	VDBGM("rel: begin (codec_state: %u)\n", inst->codec_state);
+
 	vdec_pm_get(inst);
 
 	mutex_lock(&inst->lock);
@@ -1175,15 +1208,23 @@  static void vdec_session_release(struct venus_inst *inst)
 
 	venus_pm_release_core(inst);
 	vdec_pm_put(inst, false);
+
+	VDBGM("rel: end (codec_state: %u)\n", inst->codec_state);
 }
 
 static int vdec_buf_init(struct vb2_buffer *vb)
 {
 	struct venus_inst *inst = vb2_get_drv_priv(vb->vb2_queue);
+	int ret;
 
 	inst->buf_count++;
 
-	return venus_helper_vb2_buf_init(vb);
+	ret = venus_helper_vb2_buf_init(vb);
+
+	VDBGM("vb2: buf_init: %s: done (codec_state: %u)\n",
+	      V4L2_TYPE_IS_OUTPUT(vb->type) ? "out" : "cap", inst->codec_state);
+
+	return ret;
 }
 
 static void vdec_buf_cleanup(struct vb2_buffer *vb)
@@ -1193,6 +1234,9 @@  static void vdec_buf_cleanup(struct vb2_buffer *vb)
 	inst->buf_count--;
 	if (!inst->buf_count)
 		vdec_session_release(inst);
+
+	VDBGM("vb2: buf_cleanup: %s: done (codec_state: %u)\n",
+	      V4L2_TYPE_IS_OUTPUT(vb->type) ? "out" : "cap", inst->codec_state);
 }
 
 static void vdec_vb2_buf_queue(struct vb2_buffer *vb)
@@ -1281,6 +1325,10 @@  static void vdec_buf_done(struct venus_inst *inst, unsigned int buf_type,
 	}
 
 	v4l2_m2m_buf_done(vbuf, state);
+
+	VDBGH("done: %s, idx: %02u, flen: %08u, flags: hfi: %08x, v4l2: %08x\n",
+	      V4L2_TYPE_IS_OUTPUT(type) ? "out" : "cap",
+	      vbuf->vb2_buf.index, bytesused, hfi_flags, vbuf->flags);
 }
 
 static void vdec_event_change(struct venus_inst *inst,
@@ -1289,7 +1337,6 @@  static void vdec_event_change(struct venus_inst *inst,
 	static const struct v4l2_event ev = {
 		.type = V4L2_EVENT_SOURCE_CHANGE,
 		.u.src_change.changes = V4L2_EVENT_SRC_CH_RESOLUTION };
-	struct device *dev = inst->core->dev_dec;
 	struct v4l2_format format = {};
 
 	mutex_lock(&inst->lock);
@@ -1310,8 +1357,12 @@  static void vdec_event_change(struct venus_inst *inst,
 	if (inst->bit_depth != ev_data->bit_depth)
 		inst->bit_depth = ev_data->bit_depth;
 
-	dev_dbg(dev, "event %s sufficient resources (%ux%u)\n",
-		sufficient ? "" : "not", ev_data->width, ev_data->height);
+	VDBGH("event: %s sufficient resources (%ux%u)\n",
+	      sufficient ? "" : "not", ev_data->width, ev_data->height);
+
+	if (ev_data->buf_count)
+		VDBGH("event: buf_count: %u, old: %u\n",
+		      ev_data->buf_count, inst->num_output_bufs);
 
 	if (sufficient) {
 		hfi_session_continue(inst);
@@ -1344,7 +1395,7 @@  static void vdec_event_change(struct venus_inst *inst,
 
 		ret = hfi_session_flush(inst, HFI_FLUSH_OUTPUT, false);
 		if (ret)
-			dev_dbg(dev, "flush output error %d\n", ret);
+			VDBGH("flush output error (%d)\n", ret);
 	}
 
 	inst->reconfig = true;
diff --git a/drivers/media/platform/qcom/venus/venc.c b/drivers/media/platform/qcom/venus/venc.c
index feed648550d1..c591d00ee0a7 100644
--- a/drivers/media/platform/qcom/venus/venc.c
+++ b/drivers/media/platform/qcom/venus/venc.c
@@ -1074,6 +1074,10 @@  static void venc_buf_done(struct venus_inst *inst, unsigned int buf_type,
 	}
 
 	v4l2_m2m_buf_done(vbuf, VB2_BUF_STATE_DONE);
+
+	VDBGH("done: %s, idx: %02u, flen: %08u, flags: hfi: %08x, v4l2: %08x\n",
+	      V4L2_TYPE_IS_OUTPUT(type) ? "out" : "cap",
+	      vbuf->vb2_buf.index, bytesused, hfi_flags, vbuf->flags);
 }
 
 static void venc_event_notify(struct venus_inst *inst, u32 event,