[FFmpeg-devel] [PATCH v3 1/2] Add option to log timing
Andreas Rheinhardt
andreas.rheinhardt at outlook.com
Mon Aug 9 04:10:30 EEST 2021
Soft Works:
> This commit adds two logging flags: 'timing' and 'datetiming'.
>
> Usage:
>
> ffmpeg -loglevel +timing
>
> or
>
> ffmpeg -loglevel +datetiming
>
> Signed-off-by: softworkz <softworkz at hotmail.com>
> (cherry picked from commit 960c82cede25c21bcea478b26309691fdc7fcec7)
> (cherry picked from commit 0851f36f5ecead61317a1ce631facdacae76d886)
This refers to objects not in our repo, so it is useless.
> ---
> v2 was from 2019-09-17
> fftools/cmdutils.c | 14 ++++++++++++++
> fftools/ffmpeg.c | 6 +++++-
> libavutil/log.c | 37 ++++++++++++++++++++++++++++++++-----
> libavutil/log.h | 10 ++++++++++
> 4 files changed, 61 insertions(+), 6 deletions(-)
>
> diff --git a/fftools/cmdutils.c b/fftools/cmdutils.c
> index f5e39f616f..238a607d03 100644
> --- a/fftools/cmdutils.c
> +++ b/fftools/cmdutils.c
> @@ -919,6 +919,20 @@ int opt_loglevel(void *optctx, const char *opt, const char *arg)
> flags |= AV_LOG_PRINT_LEVEL;
> }
> arg = token + 5;
> + } else if (!strncmp(token, "timing", 6)) {
> + if (cmd == '-') {
> + flags &= ~AV_LOG_PRINT_TIME;
> + } else {
> + flags |= AV_LOG_PRINT_TIME;
> + }
> + arg = token + 6;
> + } else if (!strncmp(token, "datetiming", 10)) {
Don't hardcode the length, use av_strstart.
> + if (cmd == '-') {
> + flags &= ~AV_LOG_PRINT_DATETIME;
> + } else {
> + flags |= AV_LOG_PRINT_DATETIME;
> + }
> + arg = token + 10;
> } 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;
> }
> diff --git a/libavutil/log.c b/libavutil/log.c
> index 66defa9c42..ff4b6cc885 100644
> --- a/libavutil/log.c
> +++ b/libavutil/log.c
> @@ -40,6 +40,8 @@
> #include "internal.h"
> #include "log.h"
> #include "thread.h"
> +#include "time.h"
> +#include "time_internal.h"
>
> static AVMutex mutex = AV_MUTEX_INITIALIZER;
>
> @@ -289,14 +291,32 @@ static const char *get_level_str(int level)
> }
> }
>
> +static void format_date_now(AVBPrint* timeBuf, int include_date)
> +{
> + struct tm *ptm, tmbuf;
> + int64_t time_us = av_gettime();
> + int64_t time_ms = time_us / 1000;
> + const time_t time_s = time_ms / 1000;
> + int millisec = time_ms - (time_s * 1000);
> + ptm = localtime_r(&time_s, &tmbuf);
> + if (ptm) {
> + if (include_date)
> + av_bprint_strftime(timeBuf, "%Y-%m-%d ", ptm);
> +
> + av_bprint_strftime(timeBuf, "%H:%M:%S", ptm);
> + av_bprintf(timeBuf, ".%03d ", millisec);
> + }
> +}
> +
> static void format_line(void *avcl, int level, const char *fmt, va_list vl,
> - AVBPrint part[4], int *print_prefix, int type[2])
> + AVBPrint part[5], int *print_prefix, int type[2])
> {
> AVClass* avc = avcl ? *(AVClass **) avcl : NULL;
> av_bprint_init(part+0, 0, AV_BPRINT_SIZE_AUTOMATIC);
> av_bprint_init(part+1, 0, AV_BPRINT_SIZE_AUTOMATIC);
> av_bprint_init(part+2, 0, AV_BPRINT_SIZE_AUTOMATIC);
> av_bprint_init(part+3, 0, 65536);
> + av_bprint_init(part+4, 0, AV_BPRINT_SIZE_AUTOMATIC);
>
> if(type) type[0] = type[1] = AV_CLASS_CATEGORY_NA + 16;
> if (*print_prefix && avc) {
> @@ -314,6 +334,10 @@ static void format_line(void *avcl, int level, const char *fmt, va_list vl,
> if(type) type[1] = get_category(avcl);
> }
>
> + if (*print_prefix
> + && ((flags & AV_LOG_PRINT_TIME) || (flags & AV_LOG_PRINT_DATETIME)))
> + format_date_now(&part[4], flags & AV_LOG_PRINT_DATETIME);
> +
> if (*print_prefix && (level > AV_LOG_QUIET) && (flags & AV_LOG_PRINT_LEVEL))
> av_bprintf(part+2, "[%s] ", get_level_str(level));
>
> @@ -334,12 +358,12 @@ void av_log_format_line(void *ptr, int level, const char *fmt, va_list vl,
> int av_log_format_line2(void *ptr, int level, const char *fmt, va_list vl,
> char *line, int line_size, int *print_prefix)
> {
> - AVBPrint part[4];
> + AVBPrint part[5];
> int ret;
>
> format_line(ptr, level, fmt, vl, part, print_prefix, NULL);
> ret = snprintf(line, line_size, "%s%s%s%s", part[0].str, part[1].str, part[2].str, part[3].str);
> - av_bprint_finalize(part+3, NULL);
> + av_bprint_finalize(part+4, NULL);
> return ret;
> }
>
> @@ -348,7 +372,7 @@ void av_log_default_callback(void* ptr, int level, const char* fmt, va_list vl)
> static int print_prefix = 1;
> static int count;
> static char prev[LINE_SZ];
> - AVBPrint part[4];
> + AVBPrint part[5];
> char line[LINE_SZ];
> static int is_atty;
> int type[2];
> @@ -383,6 +407,9 @@ void av_log_default_callback(void* ptr, int level, const char* fmt, va_list vl)
> count = 0;
> }
> strcpy(prev, line);
> +
> + sanitize(part[4].str);
> + colored_fputs(7, 0, part[4].str);
> sanitize(part[0].str);
> colored_fputs(type[0], 0, part[0].str);
> sanitize(part[1].str);
> @@ -397,7 +424,7 @@ void av_log_default_callback(void* ptr, int level, const char* fmt, va_list vl)
> VALGRIND_PRINTF_BACKTRACE("%s", "");
> #endif
> end:
> - av_bprint_finalize(part+3, NULL);
> + av_bprint_finalize(part+4, NULL);
This is completely wrong: The AVBPrints that use
AV_BPRINT_SIZE_AUTOMATIC don't need to be finalized, but the other one
(namely part[3]) need it. The same goes for the change above.
> ff_mutex_unlock(&mutex);
> }
>
> diff --git a/libavutil/log.h b/libavutil/log.h
> index 8727c38afc..27eb071884 100644
> --- a/libavutil/log.h
> +++ b/libavutil/log.h
> @@ -377,6 +377,16 @@ int av_log_format_line2(void *ptr, int level, const char *fmt, va_list vl,
> */
> #define AV_LOG_PRINT_LEVEL 2
>
> +/**
> + * Include system time in log output.
> + */
> +#define AV_LOG_PRINT_TIME 4
> +
> +/**
> + * Include system date and time in log output.
> + */
> +#define AV_LOG_PRINT_DATETIME 8
> +
> void av_log_set_flags(int arg);
> int av_log_get_flags(void);
>
>
You need to separate this into an libavutil patch and a subsequent patch
to fftools. The documentation should be added to the commit introducing
the things to be documented. The patch to libavutil needs an APIchanges
entry and a minor version bump.
- Andreas
More information about the ffmpeg-devel
mailing list