On 17/01/2023 22:52, Prakash wrote:

libavutil/log: Support for logging timestamps in the log.
Add 'time' flag to the -loglevel option to turn on timestamp logging.
Useful for troubleshooting where time is spent from the log files.

Signed-off-by: Prakash Duggaraju <duggar...@gmail.com>
The commit message seems to be lacking a blank line between headline and body in the attached patch file.
---

  doc/fftools-common-opts.texi |  4 ++++

  fftools/opt_common.c         |  6 ++++++

  libavutil/log.c              | 14 ++++++++++++++

  libavutil/log.h              |  8 ++++++++

  4 files changed, 32 insertions(+)



diff --git a/doc/fftools-common-opts.texi b/doc/fftools-common-opts.texi

index d9145704d6..a3cf9eb57d 100644

--- a/doc/fftools-common-opts.texi

+++ b/doc/fftools-common-opts.texi

@@ -201,6 +201,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

+Indicates that log output should add a @code{[time]} prefix to each message

+line. The time is the relative time in microseconds precision. This can be

+useful for troubleshooting where time is spent from the logs.
Maybe you should mention here that adding the "time" flag practically disables any "repeated" flag if given.
  @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/opt_common.c b/fftools/opt_common.c

index 8a06df82df..a081ad6b08 100644

--- a/fftools/opt_common.c

+++ b/fftools/opt_common.c

@@ -1269,6 +1269,12 @@ int opt_loglevel(void *optctx, const char *opt,
const char *arg)

              } else {

                  flags |= AV_LOG_PRINT_LEVEL;

              }

+        } else if (av_strstart(token, "time", &arg)) {

+            if (cmd == '-') {

+                flags &= ~AV_LOG_PRINT_TIME;

+            } else {

+                flags |= AV_LOG_PRINT_TIME;

+            }

          } else {

              break;

          }

diff --git a/libavutil/log.c b/libavutil/log.c

index 5948e50467..cc16427178 100644

--- a/libavutil/log.c

+++ b/libavutil/log.c

@@ -42,6 +42,7 @@

  #include "internal.h"

  #include "log.h"

  #include "thread.h"

+#include "time.h"



  static AVMutex mutex = AV_MUTEX_INITIALIZER;



@@ -319,6 +320,19 @@ static void format_line(void *avcl, int level, const
char *fmt, va_list vl,

      if (*print_prefix && (level > AV_LOG_QUIET) && (flags &
AV_LOG_PRINT_LEVEL))

          av_bprintf(part+2, "[%s] ", get_level_str(level));



+    if (*print_prefix && (level > AV_LOG_QUIET) && (flags &
AV_LOG_PRINT_TIME)) {

+        int secs, mins;

+        int64_t hours;

+        int64_t time = av_gettime_relative();

+        float millis = (time % 100000) / 1000.0f;

Should be modulo one million, instead one hundred thousand. But see comment regarding formatting below.

+        time  /= 1000000;

+        secs = time % 60;

+        time /= 60;

+        mins = time % 60;

+        hours = time / 60;

+        av_bprintf(part+2, "[%ldh:%02dm:%02ds:%07.03fms] ", hours, mins,
secs, millis);
Adding it to part[2] will colorize time according to the log message level. Maybe add an own AVBPrint buffer for it?
+    }

+

      av_vbprintf(part+3, fmt, vl);



      if(*part[0].str || *part[1].str || *part[2].str || *part[3].str) {

diff --git a/libavutil/log.h b/libavutil/log.h

index ab7ceabe22..2e2d83f6d0 100644

--- a/libavutil/log.h

+++ b/libavutil/log.h

@@ -377,6 +377,14 @@ int av_log_format_line2(void *ptr, int level, const
char *fmt, va_list vl,

   */

  #define AV_LOG_PRINT_LEVEL 2



+/**

+ * Include the system time with each log message.

+ * Useful for troubleshooting where the time was spent.

+ * Results in messages such as:

+ * [rawvideo @ 0xDEADBEEF] [01h:03m:05s:3.112ms] [error] encode did not
produce valid pts

In my personal opinion I find formatting the timestamp with integer seconds and float milliseconds a bit weird. Using float seconds (like HH:MM:SS.mmm) would look more familiar to me.

And maybe add the timestamp at the very front of the formatted log message? That way it should be easier to scroll through the log file and spot time jumps.

+ */

+#define AV_LOG_PRINT_TIME 4

+

  void av_log_set_flags(int arg);

  int av_log_get_flags(void);

Regards, Tobias

_______________________________________________
ffmpeg-devel mailing list
ffmpeg-devel@ffmpeg.org
https://ffmpeg.org/mailman/listinfo/ffmpeg-devel

To unsubscribe, visit link above, or email
ffmpeg-devel-requ...@ffmpeg.org with subject "unsubscribe".

Reply via email to