[edk2-platform][PATCH v1 1/1] EmbeddedPkg/VirtualRealTimeClockLib : Reduce DEBUG message verbosity

[edk2-platform][PATCH v1 1/1] EmbeddedPkg/VirtualRealTimeClockLib : Reduce DEBUG message verbosity

[Samer El-Haj-Mahmoud]

the DEBUG message for using compilation time epoch is appearing very
frequently on DEBUG firmware builds, for example during UEFI SCT runs.
Reduce verbosity to avoid the annoying repetitive message.

Cc: Ard Biesheuvel <ard.biesheuvel@linaro.org>
Cc: Leif Lindholm <leif@nuviainc.com>
Cc: Pete Batard <pete@akeo.ie>
Signed-off-by: Samer El-Haj-Mahmoud <Samer.El-Haj-Mahmoud@arm.com>
---
 EmbeddedPkg/Library/VirtualRealTimeClockLib/VirtualRealTimeClockLib.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/EmbeddedPkg/Library/VirtualRealTimeClockLib/VirtualRealTimeClockLib.c b/EmbeddedPkg/Library/VirtualRealTimeClockLib/VirtualRealTimeClockLib.c
index 5c13ed4cf190..4210708cff36 100644
--- a/EmbeddedPkg/Library/VirtualRealTimeClockLib/VirtualRealTimeClockLib.c
+++ b/EmbeddedPkg/Library/VirtualRealTimeClockLib/VirtualRealTimeClockLib.c
@@ -88,7 +88,7 @@ LibGetTime (
     //
     EpochSeconds = BUILD_EPOCH;
     DEBUG ((
-      DEBUG_INFO,
+      DEBUG_VERBOSE,
       "LibGetTime: %s non volatile variable was not found - Using compilation time epoch.\n",
       mEpochVariableName
       ));
-- 
2.25.1

[edk2-platform][PATCH v1 1/1] EmbeddedPkg/VirtualRealTimeClockLib : Reduce DEBUG message verbosity

[Samer El-Haj-Mahmoud]

the DEBUG message for using compilation time epoch is appearing very
frequently on DEBUG firmware builds, for example during UEFI SCT runs.
Reduce verbosity to avoid the annoying repetitive message.

Cc: Ard Biesheuvel <ardb+tianocore@kernel.org>
Cc: Leif Lindholm <leif@nuviainc.com>
Cc: Pete Batard <pete@akeo.ie>
Signed-off-by: Samer El-Haj-Mahmoud <Samer.El-Haj-Mahmoud@arm.com>
---
 EmbeddedPkg/Library/VirtualRealTimeClockLib/VirtualRealTimeClockLib.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/EmbeddedPkg/Library/VirtualRealTimeClockLib/VirtualRealTimeClockLib.c b/EmbeddedPkg/Library/VirtualRealTimeClockLib/VirtualRealTimeClockLib.c
index 5c13ed4cf190..4210708cff36 100644
--- a/EmbeddedPkg/Library/VirtualRealTimeClockLib/VirtualRealTimeClockLib.c
+++ b/EmbeddedPkg/Library/VirtualRealTimeClockLib/VirtualRealTimeClockLib.c
@@ -88,7 +88,7 @@ LibGetTime (
     //
     EpochSeconds = BUILD_EPOCH;
     DEBUG ((
-      DEBUG_INFO,
+      DEBUG_VERBOSE,
       "LibGetTime: %s non volatile variable was not found - Using compilation time epoch.\n",
       mEpochVariableName
       ));
-- 
2.25.1

Re: [edk2-platform][PATCH v1 1/1] EmbeddedPkg/VirtualRealTimeClockLib : Reduce DEBUG message verbosity

[Ard Biesheuvel]

On Sat, 20 Feb 2021 at 17:41, Samer El-Haj-Mahmoud
<Samer.El-Haj-Mahmoud@arm.com> wrote:
>
> the DEBUG message for using compilation time epoch is appearing very
> frequently on DEBUG firmware builds, for example during UEFI SCT runs.
> Reduce verbosity to avoid the annoying repetitive message.
>
> Cc: Ard Biesheuvel <ardb+tianocore@kernel.org>
> Cc: Leif Lindholm <leif@nuviainc.com>
> Cc: Pete Batard <pete@akeo.ie>
> Signed-off-by: Samer El-Haj-Mahmoud <Samer.El-Haj-Mahmoud@arm.com>


Reviewed-by: Ard Biesheuvel <ardb@kernel.org>

Merged as #1434 into master.

> ---
>  EmbeddedPkg/Library/VirtualRealTimeClockLib/VirtualRealTimeClockLib.c | 2 +-
>  1 file changed, 1 insertion(+), 1 deletion(-)
>
> diff --git a/EmbeddedPkg/Library/VirtualRealTimeClockLib/VirtualRealTimeClockLib.c b/EmbeddedPkg/Library/VirtualRealTimeClockLib/VirtualRealTimeClockLib.c
> index 5c13ed4cf190..4210708cff36 100644
> --- a/EmbeddedPkg/Library/VirtualRealTimeClockLib/VirtualRealTimeClockLib.c
> +++ b/EmbeddedPkg/Library/VirtualRealTimeClockLib/VirtualRealTimeClockLib.c
> @@ -88,7 +88,7 @@ LibGetTime (
>      //
>      EpochSeconds = BUILD_EPOCH;
>      DEBUG ((
> -      DEBUG_INFO,
> +      DEBUG_VERBOSE,
>        "LibGetTime: %s non volatile variable was not found - Using compilation time epoch.\n",
>        mEpochVariableName
>        ));
> --
> 2.25.1
>

Re: [edk2-devel] [edk2-platform][PATCH v1 1/1] EmbeddedPkg/VirtualRealTimeClockLib : Reduce DEBUG message verbosity

[Samer El-Haj-Mahmoud]

Thank you!

> -----Original Message-----
> From: devel@edk2.groups.io <devel@edk2.groups.io> On Behalf Of Ard
> Biesheuvel via groups.io
> Sent: Saturday, February 20, 2021 11:51 AM
> To: Samer El-Haj-Mahmoud <Samer.El-Haj-Mahmoud@arm.com>
> Cc: devel@edk2.groups.io; Ard Biesheuvel <ardb+tianocore@kernel.org>;
> Leif Lindholm <leif@nuviainc.com>; Pete Batard <pete@akeo.ie>
> Subject: Re: [edk2-devel] [edk2-platform][PATCH v1 1/1]
> EmbeddedPkg/VirtualRealTimeClockLib : Reduce DEBUG message verbosity
>
> On Sat, 20 Feb 2021 at 17:41, Samer El-Haj-Mahmoud <Samer.El-Haj-
> Mahmoud@arm.com> wrote:
> >
> > the DEBUG message for using compilation time epoch is appearing very
> > frequently on DEBUG firmware builds, for example during UEFI SCT runs.
> > Reduce verbosity to avoid the annoying repetitive message.
> >
> > Cc: Ard Biesheuvel <ardb+tianocore@kernel.org>
> > Cc: Leif Lindholm <leif@nuviainc.com>
> > Cc: Pete Batard <pete@akeo.ie>
> > Signed-off-by: Samer El-Haj-Mahmoud <Samer.El-Haj-
> Mahmoud@arm.com>
>
>
> Reviewed-by: Ard Biesheuvel <ardb@kernel.org>
>
> Merged as #1434 into master.
>
> > ---
> >  EmbeddedPkg/Library/VirtualRealTimeClockLib/VirtualRealTimeClockLib.c
> > | 2 +-
> >  1 file changed, 1 insertion(+), 1 deletion(-)
> >
> > diff --git
> > a/EmbeddedPkg/Library/VirtualRealTimeClockLib/VirtualRealTimeClockLib.
> > c
> > b/EmbeddedPkg/Library/VirtualRealTimeClockLib/VirtualRealTimeClockLib.
> > c index 5c13ed4cf190..4210708cff36 100644
> > ---
> > a/EmbeddedPkg/Library/VirtualRealTimeClockLib/VirtualRealTimeClockLib.
> > c
> > +++
> b/EmbeddedPkg/Library/VirtualRealTimeClockLib/VirtualRealTimeClock
> > +++ Lib.c
> > @@ -88,7 +88,7 @@ LibGetTime (
> >      //
> >      EpochSeconds = BUILD_EPOCH;
> >      DEBUG ((
> > -      DEBUG_INFO,
> > +      DEBUG_VERBOSE,
> >        "LibGetTime: %s non volatile variable was not found - Using compilation
> time epoch.\n",
> >        mEpochVariableName
> >        ));
> > --
> > 2.25.1
> >
>
>
> 
>

IMPORTANT NOTICE: The contents of this email and any attachments are confidential and may also be privileged. If you are not the intended recipient, please notify the sender immediately and do not disclose the contents to any other person, use it for any purpose, or store or copy the information in any medium. Thank you.

Re: [edk2-platform][PATCH v1 1/1] EmbeddedPkg/VirtualRealTimeClockLib : Reduce DEBUG message verbosity

[Leif Lindholm]

*How* annoying was this?

This is kind of useful information, well at the "would be good to see
in a regular DEBUG build" level.

This change will have suddenly effectively hidden a message that was
already present in many platforms, where they were not (very) annoyingly
repetitive during a normal boot.

It feels the test suite is not the thing that we need to optimise
debug output for.

Is there some alternative way we can rate limit this?

/
    Leif

On Sat, Feb 20, 2021 at 17:50:43 +0100, Ard Biesheuvel wrote:
> On Sat, 20 Feb 2021 at 17:41, Samer El-Haj-Mahmoud
> <Samer.El-Haj-Mahmoud@arm.com> wrote:
> >
> > the DEBUG message for using compilation time epoch is appearing very
> > frequently on DEBUG firmware builds, for example during UEFI SCT runs.
> > Reduce verbosity to avoid the annoying repetitive message.
> >
> > Cc: Ard Biesheuvel <ardb+tianocore@kernel.org>
> > Cc: Leif Lindholm <leif@nuviainc.com>
> > Cc: Pete Batard <pete@akeo.ie>
> > Signed-off-by: Samer El-Haj-Mahmoud <Samer.El-Haj-Mahmoud@arm.com>
> 
> 
> Reviewed-by: Ard Biesheuvel <ardb@kernel.org>
> 
> Merged as #1434 into master.
> 
> > ---
> >  EmbeddedPkg/Library/VirtualRealTimeClockLib/VirtualRealTimeClockLib.c | 2 +-
> >  1 file changed, 1 insertion(+), 1 deletion(-)
> >
> > diff --git a/EmbeddedPkg/Library/VirtualRealTimeClockLib/VirtualRealTimeClockLib.c b/EmbeddedPkg/Library/VirtualRealTimeClockLib/VirtualRealTimeClockLib.c
> > index 5c13ed4cf190..4210708cff36 100644
> > --- a/EmbeddedPkg/Library/VirtualRealTimeClockLib/VirtualRealTimeClockLib.c
> > +++ b/EmbeddedPkg/Library/VirtualRealTimeClockLib/VirtualRealTimeClockLib.c
> > @@ -88,7 +88,7 @@ LibGetTime (
> >      //
> >      EpochSeconds = BUILD_EPOCH;
> >      DEBUG ((
> > -      DEBUG_INFO,
> > +      DEBUG_VERBOSE,
> >        "LibGetTime: %s non volatile variable was not found - Using compilation time epoch.\n",
> >        mEpochVariableName
> >        ));
> > --
> > 2.25.1
> >

Re: [edk2-platform][PATCH v1 1/1] EmbeddedPkg/VirtualRealTimeClockLib : Reduce DEBUG message verbosity

[Samer El-Haj-Mahmoud]

Leif,

I admit, this is not *super* annoying on a normal DEBUG build boot. On the RPi4 for instance, this shows up between 25-50 times until the OS boots (depending on the boot source).

On a test run (such as running SCT), this message is *EXTREMLY* annoying. I see ~6600 instances on one run, accounting for ~60% of the entire debug output during the test. I agree we should not be optimizing for a test run, but this is just beyond being reasonable..

How useful is this message in non-verbose DEBUG output? Does it need to be repeated for every call to LibGetTime() ? I am open for suggestions on rate limiting the output.

--Samer

> -----Original Message-----
> From: Leif Lindholm <leif@nuviainc.com>
> Sent: Saturday, February 20, 2021 4:46 PM
> To: Ard Biesheuvel <ardb@kernel.org>
> Cc: Samer El-Haj-Mahmoud <Samer.El-Haj-Mahmoud@arm.com>;
> devel@edk2.groups.io; Ard Biesheuvel <ardb+tianocore@kernel.org>; Pete
> Batard <pete@akeo.ie>
> Subject: Re: [edk2-platform][PATCH v1 1/1]
> EmbeddedPkg/VirtualRealTimeClockLib : Reduce DEBUG message verbosity
>
> *How* annoying was this?
>
> This is kind of useful information, well at the "would be good to see in a
> regular DEBUG build" level.
>
> This change will have suddenly effectively hidden a message that was already
> present in many platforms, where they were not (very) annoyingly repetitive
> during a normal boot.
>
> It feels the test suite is not the thing that we need to optimise debug output
> for.
>
> Is there some alternative way we can rate limit this?
>
> /
>     Leif
>
> On Sat, Feb 20, 2021 at 17:50:43 +0100, Ard Biesheuvel wrote:
> > On Sat, 20 Feb 2021 at 17:41, Samer El-Haj-Mahmoud
> > <Samer.El-Haj-Mahmoud@arm.com> wrote:
> > >
> > > the DEBUG message for using compilation time epoch is appearing very
> > > frequently on DEBUG firmware builds, for example during UEFI SCT runs.
> > > Reduce verbosity to avoid the annoying repetitive message.
> > >
> > > Cc: Ard Biesheuvel <ardb+tianocore@kernel.org>
> > > Cc: Leif Lindholm <leif@nuviainc.com>
> > > Cc: Pete Batard <pete@akeo.ie>
> > > Signed-off-by: Samer El-Haj-Mahmoud <Samer.El-Haj-
> Mahmoud@arm.com>
> >
> >
> > Reviewed-by: Ard Biesheuvel <ardb@kernel.org>
> >
> > Merged as #1434 into master.
> >
> > > ---
> > >
> > > EmbeddedPkg/Library/VirtualRealTimeClockLib/VirtualRealTimeClockLib.
> > > c | 2 +-
> > >  1 file changed, 1 insertion(+), 1 deletion(-)
> > >
> > > diff --git
> > > a/EmbeddedPkg/Library/VirtualRealTimeClockLib/VirtualRealTimeClockLi
> > > b.c
> > > b/EmbeddedPkg/Library/VirtualRealTimeClockLib/VirtualRealTimeClockLi
> > > b.c index 5c13ed4cf190..4210708cff36 100644
> > > ---
> > > a/EmbeddedPkg/Library/VirtualRealTimeClockLib/VirtualRealTimeClockLi
> > > b.c
> > > +++ b/EmbeddedPkg/Library/VirtualRealTimeClockLib/VirtualRealTimeClo
> > > +++ ckLib.c
> > > @@ -88,7 +88,7 @@ LibGetTime (
> > >      //
> > >      EpochSeconds = BUILD_EPOCH;
> > >      DEBUG ((
> > > -      DEBUG_INFO,
> > > +      DEBUG_VERBOSE,
> > >        "LibGetTime: %s non volatile variable was not found - Using
> compilation time epoch.\n",
> > >        mEpochVariableName
> > >        ));
> > > --
> > > 2.25.1
> > >
IMPORTANT NOTICE: The contents of this email and any attachments are confidential and may also be privileged. If you are not the intended recipient, please notify the sender immediately and do not disclose the contents to any other person, use it for any purpose, or store or copy the information in any medium. Thank you.

Re: [edk2-platform][PATCH v1 1/1] EmbeddedPkg/VirtualRealTimeClockLib : Reduce DEBUG message verbosity

[Ard Biesheuvel]

On Sat, 20 Feb 2021 at 22:46, Leif Lindholm <leif@nuviainc.com> wrote:
>
> *How* annoying was this?
>
> This is kind of useful information, well at the "would be good to see
> in a regular DEBUG build" level.
>
> This change will have suddenly effectively hidden a message that was
> already present in many platforms, where they were not (very) annoyingly
> repetitive during a normal boot.
>
> It feels the test suite is not the thing that we need to optimise
> debug output for.
>
> Is there some alternative way we can rate limit this?
>

Given that the sole purpose of this library is to paper over the fact
that the platform violates the spec, and lacks the ability to tell
time, I think it makes little sense to obsess over how wrong the value
is that it returns.

Re: [edk2-platform][PATCH v1 1/1] EmbeddedPkg/VirtualRealTimeClockLib : Reduce DEBUG message verbosity

[Leif Lindholm]

On Sun, Feb 21, 2021 at 11:50:27 +0100, Ard Biesheuvel wrote:
> On Sat, 20 Feb 2021 at 22:46, Leif Lindholm <leif@nuviainc.com> wrote:
> >
> > *How* annoying was this?
> >
> > This is kind of useful information, well at the "would be good to see
> > in a regular DEBUG build" level.
> >
> > This change will have suddenly effectively hidden a message that was
> > already present in many platforms, where they were not (very) annoyingly
> > repetitive during a normal boot.
> >
> > It feels the test suite is not the thing that we need to optimise
> > debug output for.
> >
> > Is there some alternative way we can rate limit this?
> 
> Given that the sole purpose of this library is to paper over the fact
> that the platform violates the spec, and lacks the ability to tell
> time, I think it makes little sense to obsess over how wrong the value
> is that it returns.

I'm not obsessing about anything, I'm saying that using tediousness
when running a testsuite as an argument, potential issues with the
only aspect that makes this implementation useful without having to
rebuild firmware every few weeks are now hidden.

If we truly don't care about the feature, nuke it. Don't hide when it
breaks.

/
    Leif

Re: [edk2-platform][PATCH v1 1/1] EmbeddedPkg/VirtualRealTimeClockLib : Reduce DEBUG message verbosity

[Ard Biesheuvel]

On Sun, 21 Feb 2021 at 21:43, Leif Lindholm <leif@nuviainc.com> wrote:
>
> On Sun, Feb 21, 2021 at 11:50:27 +0100, Ard Biesheuvel wrote:
> > On Sat, 20 Feb 2021 at 22:46, Leif Lindholm <leif@nuviainc.com> wrote:
> > >
> > > *How* annoying was this?
> > >
> > > This is kind of useful information, well at the "would be good to see
> > > in a regular DEBUG build" level.
> > >
> > > This change will have suddenly effectively hidden a message that was
> > > already present in many platforms, where they were not (very) annoyingly
> > > repetitive during a normal boot.
> > >
> > > It feels the test suite is not the thing that we need to optimise
> > > debug output for.
> > >
> > > Is there some alternative way we can rate limit this?
> >
> > Given that the sole purpose of this library is to paper over the fact
> > that the platform violates the spec, and lacks the ability to tell
> > time, I think it makes little sense to obsess over how wrong the value
> > is that it returns.
>
> I'm not obsessing about anything, I'm saying that using tediousness
> when running a testsuite as an argument, potential issues with the
> only aspect that makes this implementation useful without having to
> rebuild firmware every few weeks are now hidden.
>
> If we truly don't care about the feature, nuke it. Don't hide when it
> breaks.
>

Nuke what exactly? I think the library has a use, I simply don't see
the point of reporting 25-50 times every boot that no timestamp was
recorded in a variable.

Re: [edk2-platform][PATCH v1 1/1] EmbeddedPkg/VirtualRealTimeClockLib : Reduce DEBUG message verbosity

[Leif Lindholm]

On Sun, Feb 21, 2021 at 21:50:20 +0100, Ard Biesheuvel wrote:
> On Sun, 21 Feb 2021 at 21:43, Leif Lindholm <leif@nuviainc.com> wrote:
> >
> > On Sun, Feb 21, 2021 at 11:50:27 +0100, Ard Biesheuvel wrote:
> > > On Sat, 20 Feb 2021 at 22:46, Leif Lindholm <leif@nuviainc.com> wrote:
> > > >
> > > > *How* annoying was this?
> > > >
> > > > This is kind of useful information, well at the "would be good to see
> > > > in a regular DEBUG build" level.
> > > >
> > > > This change will have suddenly effectively hidden a message that was
> > > > already present in many platforms, where they were not (very) annoyingly
> > > > repetitive during a normal boot.
> > > >
> > > > It feels the test suite is not the thing that we need to optimise
> > > > debug output for.
> > > >
> > > > Is there some alternative way we can rate limit this?
> > >
> > > Given that the sole purpose of this library is to paper over the fact
> > > that the platform violates the spec, and lacks the ability to tell
> > > time, I think it makes little sense to obsess over how wrong the value
> > > is that it returns.
> >
> > I'm not obsessing about anything, I'm saying that using tediousness
> > when running a testsuite as an argument, potential issues with the
> > only aspect that makes this implementation useful without having to
> > rebuild firmware every few weeks are now hidden.
> >
> > If we truly don't care about the feature, nuke it. Don't hide when it
> > breaks.
> >
> 
> Nuke what exactly? I think the library has a use, I simply don't see
> the point of reporting 25-50 times every boot that no timestamp was
> recorded in a variable.

Nuke the variable and always use the build timestamp EPOCH.
I would prefer that to silent failure.

Or we can figure out and alternative way to stop it spamming the
console.

The library is declared as a BASE library, but that's clearly untrue
as it depends on UefiRuntimeLib.

So we could, for example, break out the "check for EPOCH in variable"
into a protocol and print the message only once at protocol init.
Or we could add a Pcd for "no point, I have no persistent storage".

/
    Leif