[dpdk-dev,2/2] eal: fix dynamic logs failing to print

Message ID 20171116103144.4197-2-pbhagavatula@caviumnetworks.com (mailing list archive)
State Superseded, archived
Headers

Checks

Context Check Description
ci/checkpatch success coding style OK
ci/Intel-compilation success Compilation OK

Commit Message

Pavan Nikhilesh Nov. 16, 2017, 10:31 a.m. UTC
  Dynamic logs fail to print if the global log level is less than dynamic
loglevel. Example if the global log level is set to INFO and dynamic log
level for a specific module is set to DEBUG then the log fails to print.

Check modules log level before checking the global log level.

Fixes: c1b5fa94a46f ("eal: support dynamic log types")

Signed-off-by: Pavan Nikhilesh <pbhagavatula@caviumnetworks.com>
---
 lib/librte_eal/common/eal_common_log.c | 6 +++---
 1 file changed, 3 insertions(+), 3 deletions(-)
  

Comments

Ferruh Yigit Nov. 16, 2017, 7:48 p.m. UTC | #1
On 11/16/2017 2:31 AM, Pavan Nikhilesh wrote:
> Dynamic logs fail to print if the global log level is less than dynamic
> loglevel. Example if the global log level is set to INFO and dynamic log
> level for a specific module is set to DEBUG then the log fails to print.

What is the purpose of the global log level value?

> Check modules log level before checking the global log level.
> 
> Fixes: c1b5fa94a46f ("eal: support dynamic log types")
> 
> Signed-off-by: Pavan Nikhilesh <pbhagavatula@caviumnetworks.com>

<...>
  
Pavan Nikhilesh Nov. 17, 2017, 8:47 a.m. UTC | #2
On Thu, Nov 16, 2017 at 11:48:14AM -0800, Ferruh Yigit wrote:
> On 11/16/2017 2:31 AM, Pavan Nikhilesh wrote:
> > Dynamic logs fail to print if the global log level is less than dynamic
> > loglevel. Example if the global log level is set to INFO and dynamic log
> > level for a specific module is set to DEBUG then the log fails to print.
>
> What is the purpose of the global log level value?
>

As per my understanding, If we want to filter out debug logs from all other
modules except a specific module using --log-level="<regex>,<level>" the logs
would fail to print if the global log level is lower than the specified level.

If during EAL init we want to filter out all the logs except a certain pmd's
log we can specify --log-level="pmd\..*,<level>" without modifying the global
log level. Also, this wouldnt break the previous functionality of global log
level.

> > Check modules log level before checking the global log level.
> >
> > Fixes: c1b5fa94a46f ("eal: support dynamic log types")
> >
> > Signed-off-by: Pavan Nikhilesh <pbhagavatula@caviumnetworks.com>
>
> <...>
>
  
Ferruh Yigit Nov. 20, 2017, 6:40 p.m. UTC | #3
On 11/17/2017 12:47 AM, Pavan Nikhilesh Bhagavatula wrote:
> On Thu, Nov 16, 2017 at 11:48:14AM -0800, Ferruh Yigit wrote:
>> On 11/16/2017 2:31 AM, Pavan Nikhilesh wrote:
>>> Dynamic logs fail to print if the global log level is less than dynamic
>>> loglevel. Example if the global log level is set to INFO and dynamic log
>>> level for a specific module is set to DEBUG then the log fails to print.
>>
>> What is the purpose of the global log level value?
>>
> 
> As per my understanding, If we want to filter out debug logs from all other
> modules except a specific module using --log-level="<regex>,<level>" the logs
> would fail to print if the global log level is lower than the specified level.

Yes.

> 
> If during EAL init we want to filter out all the logs except a certain pmd's
> log we can specify --log-level="pmd\..*,<level>" without modifying the global
> log level. Also, this wouldnt break the previous functionality of global log
> level.

But this overwrites the global and makes it useless.

Lets say global log level is set to "critical" (3), if module set something
bigger like "info" (7) that will set the limit, so module will be controlling
and what is the point of having global level?

It can be an option remove global level completely and let modules control what
to log, but I believe it can be useful to have a global control.


What about having a verbose global and limited module log levels:
global default: debug (8)
modules default: info (7)

so if you want get verbose log from specific module:
--log-level="<regex>,8"

for globally less verbose log:
--log-level=3

But this makes hard to enable verbose log from everything, although not sure how
practical is this. For this one it can be possible to have a new API to set
modules other than given one, like:
--log-level="eal,-4"  --> set level of all modules except "eal" to "error" (4)


Also I believe it is possible to remove RTE_LOG_LEVEL config option completely
since dynamic debug exist now. Previously it was good to have because it was
used to compile out debug functions in data path, now there is
"RTE_LOG_DP_LEVEL" for that purpose, so it can be possible to remove
RTE_LOG_LEVEL and in rte_log_init() set to DEBUG by default if you agree with
above approach.



And, since you are touching these files :),
for better regex support, it may be good to have log types hierarchical, like
"lib.mbuf", "lib.mempool", "lib.eal.malloc", as done in member library but with
"lib" prefix instead of "librte", if this makes sense and you have time would
you mind sending a patch for this as well?


Thanks,
ferruh

> 
>>> Check modules log level before checking the global log level.
>>>
>>> Fixes: c1b5fa94a46f ("eal: support dynamic log types")
>>>
>>> Signed-off-by: Pavan Nikhilesh <pbhagavatula@caviumnetworks.com>
>>
>> <...>
>>
  
Pavan Nikhilesh Nov. 21, 2017, 8:30 a.m. UTC | #4
On Mon, Nov 20, 2017 at 10:40:29AM -0800, Ferruh Yigit wrote:
> On 11/17/2017 12:47 AM, Pavan Nikhilesh Bhagavatula wrote:
> > On Thu, Nov 16, 2017 at 11:48:14AM -0800, Ferruh Yigit wrote:
> >> On 11/16/2017 2:31 AM, Pavan Nikhilesh wrote:
> >>> Dynamic logs fail to print if the global log level is less than dynamic
> >>> loglevel. Example if the global log level is set to INFO and dynamic log
> >>> level for a specific module is set to DEBUG then the log fails to print.
> >>
> >> What is the purpose of the global log level value?
> >>
> >
> > As per my understanding, If we want to filter out debug logs from all other
> > modules except a specific module using --log-level="<regex>,<level>" the logs
> > would fail to print if the global log level is lower than the specified level.
>
> Yes.
>
> >
> > If during EAL init we want to filter out all the logs except a certain pmd's
> > log we can specify --log-level="pmd\..*,<level>" without modifying the global
> > log level. Also, this wouldnt break the previous functionality of global log
> > level.
>
> But this overwrites the global and makes it useless.
>
> Lets say global log level is set to "critical" (3), if module set something
> bigger like "info" (7) that will set the limit, so module will be controlling
> and what is the point of having global level?
>
> It can be an option remove global level completely and let modules control what
> to log, but I believe it can be useful to have a global control.
>
>
> What about having a verbose global and limited module log levels:
> global default: debug (8)
> modules default: info (7)
>
> so if you want get verbose log from specific module:
> --log-level="<regex>,8"
>
> for globally less verbose log:
> --log-level=3
>
> But this makes hard to enable verbose log from everything, although not sure how
> practical is this. For this one it can be possible to have a new API to set
> modules other than given one, like:
> --log-level="eal,-4"  --> set level of all modules except "eal" to "error" (4)
>
>
> Also I believe it is possible to remove RTE_LOG_LEVEL config option completely
> since dynamic debug exist now. Previously it was good to have because it was
> used to compile out debug functions in data path, now there is
> "RTE_LOG_DP_LEVEL" for that purpose, so it can be possible to remove
> RTE_LOG_LEVEL and in rte_log_init() set to DEBUG by default if you agree with
> above approach.
>

I do agree with this approach it gives more fluid control over logging.
And for the case where we want to match everything except we could still use
regex example: https://regex101.com/r/vqGiUK/1/

>
>
> And, since you are touching these files :),
> for better regex support, it may be good to have log types hierarchical, like
> "lib.mbuf", "lib.mempool", "lib.eal.malloc", as done in member library but with
> "lib" prefix instead of "librte", if this makes sense and you have time would
> you mind sending a patch for this as well?
>

I will redo the patchset including these :).

>
> Thanks,
> ferruh
>
> >
> >>> Check modules log level before checking the global log level.
> >>>
> >>> Fixes: c1b5fa94a46f ("eal: support dynamic log types")
> >>>
> >>> Signed-off-by: Pavan Nikhilesh <pbhagavatula@caviumnetworks.com>
> >>
> >> <...>
> >>
>
  
Thomas Monjalon Nov. 21, 2017, 10:55 a.m. UTC | #5
20/11/2017 19:40, Ferruh Yigit:
> And, since you are touching these files :),
> for better regex support, it may be good to have log types hierarchical, like
> "lib.mbuf", "lib.mempool", "lib.eal.malloc", as done in member library but with
> "lib" prefix instead of "librte", if this makes sense and you have time would
> you mind sending a patch for this as well?

I am not sure about using eal in the library names.
I think lib.malloc is enough and it would allow to move malloc
(and other libraries) outside of EAL if needed.
We already moved PCI and VDEV outside of EAL. More could be moved.
  
Pavan Nikhilesh Nov. 21, 2017, 11:14 a.m. UTC | #6
On Tue, Nov 21, 2017 at 11:55:00AM +0100, Thomas Monjalon wrote:
> 20/11/2017 19:40, Ferruh Yigit:
> > And, since you are touching these files :),
> > for better regex support, it may be good to have log types hierarchical, like
> > "lib.mbuf", "lib.mempool", "lib.eal.malloc", as done in member library but with
> > "lib" prefix instead of "librte", if this makes sense and you have time would
> > you mind sending a patch for this as well?
>
> I am not sure about using eal in the library names.
> I think lib.malloc is enough and it would allow to move malloc
> (and other libraries) outside of EAL if needed.
> We already moved PCI and VDEV outside of EAL. More could be moved.

Does this look good?

static const struct logtype logtype_strings[] = {
    {RTE_LOGTYPE_EAL,        "lib.eal"},
    {RTE_LOGTYPE_MALLOC,     "lib.malloc"},
    {RTE_LOGTYPE_RING,       "lib.ring"},
    {RTE_LOGTYPE_MEMPOOL,    "lib.mempool"},
    {RTE_LOGTYPE_TIMER,      "lib.timer"},
    {RTE_LOGTYPE_PMD,        "pmd"},
    {RTE_LOGTYPE_HASH,       "lib.hash"},
    {RTE_LOGTYPE_LPM,        "lib.lpm"},
    {RTE_LOGTYPE_KNI,        "lib.kni"},
    {RTE_LOGTYPE_ACL,        "lib.acl"},
    {RTE_LOGTYPE_POWER,      "lib.power"},
    {RTE_LOGTYPE_METER,      "lib.meter"},
    {RTE_LOGTYPE_SCHED,      "lib.sched"},
    {RTE_LOGTYPE_PORT,       "lib.port"},
    {RTE_LOGTYPE_TABLE,      "lib.table"},
    {RTE_LOGTYPE_PIPELINE,   "lib.pipeline"},
    {RTE_LOGTYPE_MBUF,       "lib.mbuf"},
    {RTE_LOGTYPE_CRYPTODEV,  "lib.cryptodev"},
    {RTE_LOGTYPE_EFD,        "lib.efd"},
    {RTE_LOGTYPE_EVENTDEV,   "lib.eventdev"},
    {RTE_LOGTYPE_GSO,        "lib.gso"},
    {RTE_LOGTYPE_USER1,      "user1"},
    {RTE_LOGTYPE_USER2,      "user2"},
    {RTE_LOGTYPE_USER3,      "user3"},
    {RTE_LOGTYPE_USER4,      "user4"},
    {RTE_LOGTYPE_USER5,      "user5"},
    {RTE_LOGTYPE_USER6,      "user6"},
    {RTE_LOGTYPE_USER7,      "user7"},
    {RTE_LOGTYPE_USER8,      "user8"}
};

I will be sending out the patch set soon.

Thanks,
Pavan.
  
Thomas Monjalon Nov. 21, 2017, 1:30 p.m. UTC | #7
21/11/2017 12:14, Pavan Nikhilesh Bhagavatula:
> On Tue, Nov 21, 2017 at 11:55:00AM +0100, Thomas Monjalon wrote:
> > 20/11/2017 19:40, Ferruh Yigit:
> > > And, since you are touching these files :),
> > > for better regex support, it may be good to have log types hierarchical, like
> > > "lib.mbuf", "lib.mempool", "lib.eal.malloc", as done in member library but with
> > > "lib" prefix instead of "librte", if this makes sense and you have time would
> > > you mind sending a patch for this as well?
> >
> > I am not sure about using eal in the library names.
> > I think lib.malloc is enough and it would allow to move malloc
> > (and other libraries) outside of EAL if needed.
> > We already moved PCI and VDEV outside of EAL. More could be moved.
> 
> Does this look good?
> 
> static const struct logtype logtype_strings[] = {
>     {RTE_LOGTYPE_EAL,        "lib.eal"},
>     {RTE_LOGTYPE_MALLOC,     "lib.malloc"},
>     {RTE_LOGTYPE_RING,       "lib.ring"},
>     {RTE_LOGTYPE_MEMPOOL,    "lib.mempool"},
>     {RTE_LOGTYPE_TIMER,      "lib.timer"},
>     {RTE_LOGTYPE_PMD,        "pmd"},
>     {RTE_LOGTYPE_HASH,       "lib.hash"},
>     {RTE_LOGTYPE_LPM,        "lib.lpm"},
>     {RTE_LOGTYPE_KNI,        "lib.kni"},
>     {RTE_LOGTYPE_ACL,        "lib.acl"},
>     {RTE_LOGTYPE_POWER,      "lib.power"},
>     {RTE_LOGTYPE_METER,      "lib.meter"},
>     {RTE_LOGTYPE_SCHED,      "lib.sched"},
>     {RTE_LOGTYPE_PORT,       "lib.port"},
>     {RTE_LOGTYPE_TABLE,      "lib.table"},
>     {RTE_LOGTYPE_PIPELINE,   "lib.pipeline"},
>     {RTE_LOGTYPE_MBUF,       "lib.mbuf"},
>     {RTE_LOGTYPE_CRYPTODEV,  "lib.cryptodev"},
>     {RTE_LOGTYPE_EFD,        "lib.efd"},
>     {RTE_LOGTYPE_EVENTDEV,   "lib.eventdev"},
>     {RTE_LOGTYPE_GSO,        "lib.gso"},
>     {RTE_LOGTYPE_USER1,      "user1"},
>     {RTE_LOGTYPE_USER2,      "user2"},
>     {RTE_LOGTYPE_USER3,      "user3"},
>     {RTE_LOGTYPE_USER4,      "user4"},
>     {RTE_LOGTYPE_USER5,      "user5"},
>     {RTE_LOGTYPE_USER6,      "user6"},
>     {RTE_LOGTYPE_USER7,      "user7"},
>     {RTE_LOGTYPE_USER8,      "user8"}
> };
> 
> I will be sending out the patch set soon.

These are only the legacy static log types.
Are you sure you want to change them?
They should be removed when using dynamic logging.
  
Pavan Nikhilesh Nov. 21, 2017, 2:04 p.m. UTC | #8
On Tue, Nov 21, 2017 at 02:30:48PM +0100, Thomas Monjalon wrote:
> 21/11/2017 12:14, Pavan Nikhilesh Bhagavatula:
> > On Tue, Nov 21, 2017 at 11:55:00AM +0100, Thomas Monjalon wrote:
> > > 20/11/2017 19:40, Ferruh Yigit:
<snip>
> >
> > I will be sending out the patch set soon.
>
> These are only the legacy static log types.
> Are you sure you want to change them?
> They should be removed when using dynamic logging.

Actually this same struct is used for registering dynamic logs for legacy
modules currently,

/* register legacy log types */
for (i = 0; i < RTE_DIM(logtype_strings); i++)
	__rte_log_register(logtype_strings[i].logtype,
		logtype_strings[i].log_id);

I have just prefixed them with "lib.". If we remove this form here then each
module has to use constructor style initialisation for logs which would be a
lot of rework.
  
Ferruh Yigit Nov. 21, 2017, 6:10 p.m. UTC | #9
On 11/21/2017 6:04 AM, Pavan Nikhilesh Bhagavatula wrote:
> On Tue, Nov 21, 2017 at 02:30:48PM +0100, Thomas Monjalon wrote:
>> 21/11/2017 12:14, Pavan Nikhilesh Bhagavatula:
>>> On Tue, Nov 21, 2017 at 11:55:00AM +0100, Thomas Monjalon wrote:
>>>> 20/11/2017 19:40, Ferruh Yigit:
> <snip>
>>>
>>> I will be sending out the patch set soon.
>>
>> These are only the legacy static log types.
>> Are you sure you want to change them?
>> They should be removed when using dynamic logging.
> 
> Actually this same struct is used for registering dynamic logs for legacy
> modules currently,
> 
> /* register legacy log types */
> for (i = 0; i < RTE_DIM(logtype_strings); i++)
> 	__rte_log_register(logtype_strings[i].logtype,
> 		logtype_strings[i].log_id);
> 
> I have just prefixed them with "lib.". If we remove this form here then each
> module has to use constructor style initialisation for logs which would be a
> lot of rework.

That work of each library registering dynamic log themselves needs to be done
somehow but that is bigger task, for this patch just renaming static ones to be
consistent can be enough I think.

Thanks,
ferruh
  

Patch

diff --git a/lib/librte_eal/common/eal_common_log.c b/lib/librte_eal/common/eal_common_log.c
index 061e96ef9..e31099d1a 100644
--- a/lib/librte_eal/common/eal_common_log.c
+++ b/lib/librte_eal/common/eal_common_log.c
@@ -336,12 +336,12 @@  rte_vlog(uint32_t level, uint32_t logtype, const char *format, va_list ap)
 		}
 	}
 
-	if (level > rte_logs.level)
-		return 0;
 	if (logtype >= rte_logs.dynamic_types_len)
 		return -1;
-	if (level > rte_logs.dynamic_types[logtype].loglevel)
+	if (level > rte_logs.dynamic_types[logtype].loglevel &&
+			level > rte_logs.level) {
 		return 0;
+	}
 
 	/* save loglevel and logtype in a global per-lcore variable */
 	RTE_PER_LCORE(log_cur_msg).loglevel = level;