diff mbox series

[FFmpeg-devel,v7,2/2] fftools: Add option to log timing

Message ID MN2PR04MB59815843DD16409699E9FF13BAF79@MN2PR04MB5981.namprd04.prod.outlook.com
State Withdrawn, archived
Headers show
Series [FFmpeg-devel,v7,1/2] libavutil/log: Add capability to prefix loglines with current time or current date+time | expand

Checks

Context Check Description
andriy/x86_make success Make finished
andriy/x86_make_fate success Make fate finished
andriy/PPC64_make success Make finished
andriy/PPC64_make_fate success Make fate finished

Commit Message

Soft Works Aug. 10, 2021, 5:56 p.m. UTC
This commit adds two logging flags: 'time' and 'datetime'.

Usage:

ffmpeg -loglevel +time

or

ffmpeg -loglevel +datetime

Signed-off-by: softworkz <softworkz@hotmail.com>
---
 doc/fftools-common-opts.texi |  4 ++++
 fftools/cmdutils.c           | 21 +++++++++++++++++++++
 fftools/ffmpeg.c             |  6 +++++-
 3 files changed, 30 insertions(+), 1 deletion(-)

Comments

Andreas Rheinhardt Aug. 10, 2021, 6:49 p.m. UTC | #1
Soft Works:
> This commit adds two logging flags: 'time' and 'datetime'.
> 
> Usage:
> 
> ffmpeg -loglevel +time
> 
> or
> 
> ffmpeg -loglevel +datetime
> 
> Signed-off-by: softworkz <softworkz@hotmail.com>
> ---
>  doc/fftools-common-opts.texi |  4 ++++
>  fftools/cmdutils.c           | 21 +++++++++++++++++++++
>  fftools/ffmpeg.c             |  6 +++++-
>  3 files changed, 30 insertions(+), 1 deletion(-)
> 
> diff --git a/doc/fftools-common-opts.texi b/doc/fftools-common-opts.texi
> index 7643dd8396..aae26c28d0 100644
> --- a/doc/fftools-common-opts.texi
> +++ b/doc/fftools-common-opts.texi
> @@ -198,6 +198,10 @@ and the "Last message repeated n times" line will be omitted.
>  Indicates that log output should add a @code{[level]} prefix to each message
>  line. This can be used as an alternative to log coloring, e.g. when dumping the
>  log to file.
> +@item time
> +Prefixes each log line with the local time.
> +@item datetime
> +Same as time but also prints the current date in each line.
>  @end table
>  Flags can also be used alone by adding a '+'/'-' prefix to set/reset a single
>  flag without affecting other @var{flags} or changing @var{loglevel}. When
> diff --git a/fftools/cmdutils.c b/fftools/cmdutils.c
> index 912e881174..7918078766 100644
> --- a/fftools/cmdutils.c
> +++ b/fftools/cmdutils.c
> @@ -918,6 +918,27 @@ int opt_loglevel(void *optctx, const char *opt, const char *arg)
>                  flags |= AV_LOG_PRINT_LEVEL;
>              }
>              arg = token + 5;
> +        } else if (av_strstart(token, "time", NULL)) {
> +            if (cmd == '-') {
> +                flags &= ~AV_LOG_PRINT_TIME;
> +            } else {
> +                flags |= AV_LOG_PRINT_TIME;
> +            }
> +            arg = token + 4;
> +        } else if (av_strstart(token, "timing", NULL)) {

Why are you recognizing an undocumented and redundant command? Just
remove this.

> +            if (cmd == '-') {
> +                flags &= ~AV_LOG_PRINT_TIME;
> +            } else {
> +                flags |= AV_LOG_PRINT_TIME;
> +            }
> +            arg = token + 6;
> +        } else if (av_strstart(token, "datetime", NULL)) {
> +            if (cmd == '-') {
> +                flags &= ~AV_LOG_PRINT_DATETIME;
> +            } else {
> +                flags |= AV_LOG_PRINT_DATETIME;
> +            }
> +            arg = token + 8;

This still hardcodes the lengths of the strings, resulting in potential
breakage if one is updated and the other is forgotten. See my patch for
how to avoid this.

>          } else {
>              break;
>          }
> diff --git a/fftools/ffmpeg.c b/fftools/ffmpeg.c
> index b0ce7c7c32..b0b105be1c 100644
> --- a/fftools/ffmpeg.c
> +++ b/fftools/ffmpeg.c
> @@ -4983,7 +4983,7 @@ static void log_callback_null(void *ptr, int level, const char *fmt, va_list vl)
>  
>  int main(int argc, char **argv)
>  {
> -    int i, ret;
> +    int i, ret, log_flags;
>      BenchmarkTimeStamps ti;
>  
>      init_dynload();
> @@ -5049,6 +5049,10 @@ int main(int argc, char **argv)
>      if ((decode_error_stat[0] + decode_error_stat[1]) * max_error_rate < decode_error_stat[1])
>          exit_program(69);
>  
> +    log_flags = av_log_get_flags();
> +    if (log_flags & AV_LOG_PRINT_TIME || log_flags & AV_LOG_PRINT_DATETIME)

You can check both flags at once (as Nicolas has already pointed out).

> +        av_log(NULL, AV_LOG_INFO, "\n"); /* end with line break to avoid mixing up with shell prompt */
> +
>      exit_program(received_nb_signals ? 255 : main_return_code);
>      return main_return_code;
>  }
>
Soft Works Aug. 10, 2021, 7:03 p.m. UTC | #2
> -----Original Message-----
> From: ffmpeg-devel <ffmpeg-devel-bounces@ffmpeg.org> On Behalf Of
> Andreas Rheinhardt
> Sent: Tuesday, 10 August 2021 20:49
> To: ffmpeg-devel@ffmpeg.org
> Subject: Re: [FFmpeg-devel] [PATCH v7 2/2] fftools: Add option to log
> timing
> 
> Soft Works:
> > This commit adds two logging flags: 'time' and 'datetime'.
> >
> > Usage:
> >
> > ffmpeg -loglevel +time
> >
> > or
> >
> > ffmpeg -loglevel +datetime
> >
> > Signed-off-by: softworkz <softworkz@hotmail.com>
> > ---
> >  doc/fftools-common-opts.texi |  4 ++++
> >  fftools/cmdutils.c           | 21 +++++++++++++++++++++
> >  fftools/ffmpeg.c             |  6 +++++-
> >  3 files changed, 30 insertions(+), 1 deletion(-)
> >
> > diff --git a/doc/fftools-common-opts.texi b/doc/fftools-common-
> opts.texi
> > index 7643dd8396..aae26c28d0 100644
> > --- a/doc/fftools-common-opts.texi
> > +++ b/doc/fftools-common-opts.texi
> > @@ -198,6 +198,10 @@ and the "Last message repeated n times" line
> will be omitted.
> >  Indicates that log output should add a @code{[level]} prefix to
> each message
> >  line. This can be used as an alternative to log coloring, e.g.
> when dumping the
> >  log to file.
> > +@item time
> > +Prefixes each log line with the local time.
> > +@item datetime
> > +Same as time but also prints the current date in each line.
> >  @end table
> >  Flags can also be used alone by adding a '+'/'-' prefix to
> set/reset a single
> >  flag without affecting other @var{flags} or changing
> @var{loglevel}. When
> > diff --git a/fftools/cmdutils.c b/fftools/cmdutils.c
> > index 912e881174..7918078766 100644
> > --- a/fftools/cmdutils.c
> > +++ b/fftools/cmdutils.c
> > @@ -918,6 +918,27 @@ int opt_loglevel(void *optctx, const char
> *opt, const char *arg)
> >                  flags |= AV_LOG_PRINT_LEVEL;
> >              }
> >              arg = token + 5;
> > +        } else if (av_strstart(token, "time", NULL)) {
> > +            if (cmd == '-') {
> > +                flags &= ~AV_LOG_PRINT_TIME;
> > +            } else {
> > +                flags |= AV_LOG_PRINT_TIME;
> > +            }
> > +            arg = token + 4;
> > +        } else if (av_strstart(token, "timing", NULL)) {
> 
> Why are you recognizing an undocumented and redundant command? Just
> remove this.

My mistake, this should only go into my fork where I'm having this 
for years already.

> 
> > +            if (cmd == '-') {
> > +                flags &= ~AV_LOG_PRINT_TIME;
> > +            } else {
> > +                flags |= AV_LOG_PRINT_TIME;
> > +            }
> > +            arg = token + 6;
> > +        } else if (av_strstart(token, "datetime", NULL)) {
> > +            if (cmd == '-') {
> > +                flags &= ~AV_LOG_PRINT_DATETIME;
> > +            } else {
> > +                flags |= AV_LOG_PRINT_DATETIME;
> > +            }
> > +            arg = token + 8;
> 
> This still hardcodes the lengths of the strings, resulting in
> potential
> breakage if one is updated and the other is forgotten. See my patch
> for
> how to avoid this.

Yes, but ALL the code is doing like this. Why should I just change 
the new code and mix it up with the existing code, resulting in 
a weird mashup that is much worse IMO than that tiny caveat that you 
are mentioning.


> 
> >          } else {
> >              break;
> >          }
> > diff --git a/fftools/ffmpeg.c b/fftools/ffmpeg.c
> > index b0ce7c7c32..b0b105be1c 100644
> > --- a/fftools/ffmpeg.c
> > +++ b/fftools/ffmpeg.c
> > @@ -4983,7 +4983,7 @@ static void log_callback_null(void *ptr, int
> level, const char *fmt, va_list vl)
> >
> >  int main(int argc, char **argv)
> >  {
> > -    int i, ret;
> > +    int i, ret, log_flags;
> >      BenchmarkTimeStamps ti;
> >
> >      init_dynload();
> > @@ -5049,6 +5049,10 @@ int main(int argc, char **argv)
> >      if ((decode_error_stat[0] + decode_error_stat[1]) *
> max_error_rate < decode_error_stat[1])
> >          exit_program(69);
> >
> > +    log_flags = av_log_get_flags();
> > +    if (log_flags & AV_LOG_PRINT_TIME || log_flags &
> AV_LOG_PRINT_DATETIME)
> 
> You can check both flags at once (as Nicolas has already pointed
> out).

I had made that change. No idea where it got lost. That ML+Patch
stuff is turning me mad. Sigh..

Thanks for your patience,
softworkz
Andreas Rheinhardt Aug. 10, 2021, 7:08 p.m. UTC | #3
Soft Works:
> 
> 
>> -----Original Message-----
>> From: ffmpeg-devel <ffmpeg-devel-bounces@ffmpeg.org> On Behalf Of
>> Andreas Rheinhardt
>> Sent: Tuesday, 10 August 2021 20:49
>> To: ffmpeg-devel@ffmpeg.org
>> Subject: Re: [FFmpeg-devel] [PATCH v7 2/2] fftools: Add option to log
>> timing
>>
>> Soft Works:
>>> This commit adds two logging flags: 'time' and 'datetime'.
>>>
>>> Usage:
>>>
>>> ffmpeg -loglevel +time
>>>
>>> or
>>>
>>> ffmpeg -loglevel +datetime
>>>
>>> Signed-off-by: softworkz <softworkz@hotmail.com>
>>> ---
>>>  doc/fftools-common-opts.texi |  4 ++++
>>>  fftools/cmdutils.c           | 21 +++++++++++++++++++++
>>>  fftools/ffmpeg.c             |  6 +++++-
>>>  3 files changed, 30 insertions(+), 1 deletion(-)
>>>
>>> diff --git a/doc/fftools-common-opts.texi b/doc/fftools-common-
>> opts.texi
>>> index 7643dd8396..aae26c28d0 100644
>>> --- a/doc/fftools-common-opts.texi
>>> +++ b/doc/fftools-common-opts.texi
>>> @@ -198,6 +198,10 @@ and the "Last message repeated n times" line
>> will be omitted.
>>>  Indicates that log output should add a @code{[level]} prefix to
>> each message
>>>  line. This can be used as an alternative to log coloring, e.g.
>> when dumping the
>>>  log to file.
>>> +@item time
>>> +Prefixes each log line with the local time.
>>> +@item datetime
>>> +Same as time but also prints the current date in each line.
>>>  @end table
>>>  Flags can also be used alone by adding a '+'/'-' prefix to
>> set/reset a single
>>>  flag without affecting other @var{flags} or changing
>> @var{loglevel}. When
>>> diff --git a/fftools/cmdutils.c b/fftools/cmdutils.c
>>> index 912e881174..7918078766 100644
>>> --- a/fftools/cmdutils.c
>>> +++ b/fftools/cmdutils.c
>>> @@ -918,6 +918,27 @@ int opt_loglevel(void *optctx, const char
>> *opt, const char *arg)
>>>                  flags |= AV_LOG_PRINT_LEVEL;
>>>              }
>>>              arg = token + 5;
>>> +        } else if (av_strstart(token, "time", NULL)) {
>>> +            if (cmd == '-') {
>>> +                flags &= ~AV_LOG_PRINT_TIME;
>>> +            } else {
>>> +                flags |= AV_LOG_PRINT_TIME;
>>> +            }
>>> +            arg = token + 4;
>>> +        } else if (av_strstart(token, "timing", NULL)) {
>>
>> Why are you recognizing an undocumented and redundant command? Just
>> remove this.
> 
> My mistake, this should only go into my fork where I'm having this 
> for years already.
> 
>>
>>> +            if (cmd == '-') {
>>> +                flags &= ~AV_LOG_PRINT_TIME;
>>> +            } else {
>>> +                flags |= AV_LOG_PRINT_TIME;
>>> +            }
>>> +            arg = token + 6;
>>> +        } else if (av_strstart(token, "datetime", NULL)) {
>>> +            if (cmd == '-') {
>>> +                flags &= ~AV_LOG_PRINT_DATETIME;
>>> +            } else {
>>> +                flags |= AV_LOG_PRINT_DATETIME;
>>> +            }
>>> +            arg = token + 8;
>>
>> This still hardcodes the lengths of the strings, resulting in
>> potential
>> breakage if one is updated and the other is forgotten. See my patch
>> for
>> how to avoid this.
> 
> Yes, but ALL the code is doing like this. Why should I just change 
> the new code and mix it up with the existing code, resulting in 
> a weird mashup that is much worse IMO than that tiny caveat that you 
> are mentioning.
> I actually intended my patch
(https://ffmpeg.org/pipermail/ffmpeg-devel/2021-August/283439.html)
which deals with the legacy flags to be applied first, so there will be
no mashup.

- Andreas
Soft Works Aug. 10, 2021, 7:19 p.m. UTC | #4
> -----Original Message-----
> From: ffmpeg-devel <ffmpeg-devel-bounces@ffmpeg.org> On Behalf Of
> Andreas Rheinhardt
> Sent: Tuesday, 10 August 2021 21:09
> To: ffmpeg-devel@ffmpeg.org
> Subject: Re: [FFmpeg-devel] [PATCH v7 2/2] fftools: Add option to log
> timing
> 
> Soft Works:
> >
> >
> >> -----Original Message-----
> >> From: ffmpeg-devel <ffmpeg-devel-bounces@ffmpeg.org> On Behalf Of
> >> Andreas Rheinhardt
> >> Sent: Tuesday, 10 August 2021 20:49
> >> To: ffmpeg-devel@ffmpeg.org
> >> Subject: Re: [FFmpeg-devel] [PATCH v7 2/2] fftools: Add option to
> log
> >> timing
> >>
> >> Soft Works:
> >>> This commit adds two logging flags: 'time' and 'datetime'.
> >>>
> >>> Usage:
> >>>
> >>> ffmpeg -loglevel +time
> >>>
> >>> or
> >>>
> >>> ffmpeg -loglevel +datetime
> >>>
> >>> Signed-off-by: softworkz <softworkz@hotmail.com>
> >>> ---
> >>>  doc/fftools-common-opts.texi |  4 ++++
> >>>  fftools/cmdutils.c           | 21 +++++++++++++++++++++
> >>>  fftools/ffmpeg.c             |  6 +++++-
> >>>  3 files changed, 30 insertions(+), 1 deletion(-)
> >>>
> >>> diff --git a/doc/fftools-common-opts.texi b/doc/fftools-common-
> >> opts.texi
> >>> index 7643dd8396..aae26c28d0 100644
> >>> --- a/doc/fftools-common-opts.texi
> >>> +++ b/doc/fftools-common-opts.texi
> >>> @@ -198,6 +198,10 @@ and the "Last message repeated n times" line
> >> will be omitted.
> >>>  Indicates that log output should add a @code{[level]} prefix to
> >> each message
> >>>  line. This can be used as an alternative to log coloring, e.g.
> >> when dumping the
> >>>  log to file.
> >>> +@item time
> >>> +Prefixes each log line with the local time.
> >>> +@item datetime
> >>> +Same as time but also prints the current date in each line.
> >>>  @end table
> >>>  Flags can also be used alone by adding a '+'/'-' prefix to
> >> set/reset a single
> >>>  flag without affecting other @var{flags} or changing
> >> @var{loglevel}. When
> >>> diff --git a/fftools/cmdutils.c b/fftools/cmdutils.c
> >>> index 912e881174..7918078766 100644
> >>> --- a/fftools/cmdutils.c
> >>> +++ b/fftools/cmdutils.c
> >>> @@ -918,6 +918,27 @@ int opt_loglevel(void *optctx, const char
> >> *opt, const char *arg)
> >>>                  flags |= AV_LOG_PRINT_LEVEL;
> >>>              }
> >>>              arg = token + 5;
> >>> +        } else if (av_strstart(token, "time", NULL)) {
> >>> +            if (cmd == '-') {
> >>> +                flags &= ~AV_LOG_PRINT_TIME;
> >>> +            } else {
> >>> +                flags |= AV_LOG_PRINT_TIME;
> >>> +            }
> >>> +            arg = token + 4;
> >>> +        } else if (av_strstart(token, "timing", NULL)) {
> >>
> >> Why are you recognizing an undocumented and redundant command?
> Just
> >> remove this.
> >
> > My mistake, this should only go into my fork where I'm having this
> > for years already.
> >
> >>
> >>> +            if (cmd == '-') {
> >>> +                flags &= ~AV_LOG_PRINT_TIME;
> >>> +            } else {
> >>> +                flags |= AV_LOG_PRINT_TIME;
> >>> +            }
> >>> +            arg = token + 6;
> >>> +        } else if (av_strstart(token, "datetime", NULL)) {
> >>> +            if (cmd == '-') {
> >>> +                flags &= ~AV_LOG_PRINT_DATETIME;
> >>> +            } else {
> >>> +                flags |= AV_LOG_PRINT_DATETIME;
> >>> +            }
> >>> +            arg = token + 8;
> >>
> >> This still hardcodes the lengths of the strings, resulting in
> >> potential
> >> breakage if one is updated and the other is forgotten. See my
> patch
> >> for
> >> how to avoid this.
> >
> > Yes, but ALL the code is doing like this. Why should I just change
> > the new code and mix it up with the existing code, resulting in
> > a weird mashup that is much worse IMO than that tiny caveat that
> you
> > are mentioning.
> > I actually intended my patch
> (https://ffmpeg.org/pipermail/ffmpeg-devel/2021-August/283439.html)
> which deals with the legacy flags to be applied first, so there will
> be
> no mashup.

You could have done this after merging my patch and do everything exactly
as you want it to have. I have oriented my patch based on the existing
code and when you find that incorrect, you'll have to change it anyway,
so you could have also changed the parts that I'm adding afterwards.
Instead you force me to wait for your patch, rebase and adapt my patch
based on your change. 
I'm afraid, the number of hoops I'm ready to jump through is exhausted.

Kind regards,
softworkz
diff mbox series

Patch

diff --git a/doc/fftools-common-opts.texi b/doc/fftools-common-opts.texi
index 7643dd8396..aae26c28d0 100644
--- a/doc/fftools-common-opts.texi
+++ b/doc/fftools-common-opts.texi
@@ -198,6 +198,10 @@  and the "Last message repeated n times" line will be omitted.
 Indicates that log output should add a @code{[level]} prefix to each message
 line. This can be used as an alternative to log coloring, e.g. when dumping the
 log to file.
+@item time
+Prefixes each log line with the local time.
+@item datetime
+Same as time but also prints the current date in each line.
 @end table
 Flags can also be used alone by adding a '+'/'-' prefix to set/reset a single
 flag without affecting other @var{flags} or changing @var{loglevel}. When
diff --git a/fftools/cmdutils.c b/fftools/cmdutils.c
index 912e881174..7918078766 100644
--- a/fftools/cmdutils.c
+++ b/fftools/cmdutils.c
@@ -918,6 +918,27 @@  int opt_loglevel(void *optctx, const char *opt, const char *arg)
                 flags |= AV_LOG_PRINT_LEVEL;
             }
             arg = token + 5;
+        } else if (av_strstart(token, "time", NULL)) {
+            if (cmd == '-') {
+                flags &= ~AV_LOG_PRINT_TIME;
+            } else {
+                flags |= AV_LOG_PRINT_TIME;
+            }
+            arg = token + 4;
+        } else if (av_strstart(token, "timing", NULL)) {
+            if (cmd == '-') {
+                flags &= ~AV_LOG_PRINT_TIME;
+            } else {
+                flags |= AV_LOG_PRINT_TIME;
+            }
+            arg = token + 6;
+        } else if (av_strstart(token, "datetime", NULL)) {
+            if (cmd == '-') {
+                flags &= ~AV_LOG_PRINT_DATETIME;
+            } else {
+                flags |= AV_LOG_PRINT_DATETIME;
+            }
+            arg = token + 8;
         } else {
             break;
         }
diff --git a/fftools/ffmpeg.c b/fftools/ffmpeg.c
index b0ce7c7c32..b0b105be1c 100644
--- a/fftools/ffmpeg.c
+++ b/fftools/ffmpeg.c
@@ -4983,7 +4983,7 @@  static void log_callback_null(void *ptr, int level, const char *fmt, va_list vl)
 
 int main(int argc, char **argv)
 {
-    int i, ret;
+    int i, ret, log_flags;
     BenchmarkTimeStamps ti;
 
     init_dynload();
@@ -5049,6 +5049,10 @@  int main(int argc, char **argv)
     if ((decode_error_stat[0] + decode_error_stat[1]) * max_error_rate < decode_error_stat[1])
         exit_program(69);
 
+    log_flags = av_log_get_flags();
+    if (log_flags & AV_LOG_PRINT_TIME || log_flags & AV_LOG_PRINT_DATETIME)
+        av_log(NULL, AV_LOG_INFO, "\n"); /* end with line break to avoid mixing up with shell prompt */
+
     exit_program(received_nb_signals ? 255 : main_return_code);
     return main_return_code;
 }