[FFmpeg-devel] [PATCH] Add option to log timing

[Michael Niedermayer]

On Wed, Sep 04, 2019 at 07:35:11PM +0000, Soft Works wrote:
> 
> > Why this restriction? I think all log lines should be start with
> > time/date if corresponding flag is present. This makes the log to be
> > easy to parse by scripts.
> 
> Initially I didn’t have this restriction, but it doesn’t work well together with some multi-line logging.
> See below for an example.
> 
> To get this nice, it would require a larger amount of changes, and probably result in something that nobody wants to merge in.
> 
> Anyway, there’s a flag controlling this behavior and if you really want, you can set it.
> Then you’ll see something like this:
> 
> 
> 18:59:04.449 Input #0, mov,mp4,m4a,3gp,3g2,mj2, from 'file:xxxxxxx.mp4':
> 18:59:04.449   Metadata:
>     major_brand     : isom18:59:04.449
>     minor_version   : 51218:59:04.449
>     compatible_brands: isomiso2avc1mp4118:59:04.449
>     encoder         : Lavf58.12.10018:59:04.449
>   Duration: 00:20:52.72, start: 0.000000, bitrate: 1386 kb/s18:59:04.449
>     Stream #0:0(und): Video: h264 (High) (avc1 / 0x31637661), yuv420p, 640x360 [SAR 1:1 DAR 16:9], 612 kb/s, Level 30, 25 fps, 25 tbr, 12800 tbn, 50 tbc (default)18:59:04.449
> 18:59:04.449     Metadata:
>       handler_name    : VideoHandler18:59:04.449
>     Stream #0:1(ger): Audio: aac (LC) (mp4a / 0x6134706D), 48000 Hz, 5.1, fltp, 381 kb/s (default)18:59:04.449
> 18:59:04.449     Metadata:
>       handler_name    : SoundHandler18:59:04.449
>     Stream #0:2(eng): Audio: aac (LC) (mp4a / 0x6134706D), 48000 Hz, 5.1, fltp, 382 kb/s18:59:04.449
> 18:59:04.449     Metadata:
>       handler_name    : SoundHandler18:59:04.449
> 18:59:04.737 Stream mapping:
>   Stream #0:0 (h264_cuvid) -> scale_cuda (graph 0)18:59:04.737
>   scale_cuda (graph 0)18:59:04.737  -> Stream #0:0 (h264_nvenc)
>   Stream #0:1 -> #0:1 (aac (native) -> mp3 (libmp3lame))18:59:04.737

i just enabled prefixes for all calls, and i get this:

[]   libavutil      56. 35.100 / 56. 35.100
[]   libavcodec     58. 56.101 / 58. 56.101
[]   libavformat    58. 32.104 / 58. 32.104
[]   libavdevice    58.  9.100 / 58.  9.100
[]   libavfilter     7. 58.102 /  7. 58.102
[]   libswscale      5.  6.100 /  5.  6.100
[]   libswresample   3.  6.100 /  3.  6.100
[]   libpostproc    55.  6.100 / 55.  6.100
[mpeg @ 0x3334f80] start time for stream 0 is not set in estimate_timings_from_pts
[] Input #0, mpeg, from 'matrixbench_mpeg2.mpg':
[]   Duration: 00:03:07.66, start: 0.220000, bitrate: 5633 kb/s
[]     Stream #0:0[0x1bf]: Data: dvd_nav_packet
[]     Stream #0:1[0x1e0]: Video: mpeg2video (Main), yuv420p(tv, bt470bg/bt470m/bt470m, bottom first), 720x576 [SAR 16:15 DAR 4:3], 25 fps, 25 tbr, 90k tbn, 50 tbc
[]     Stream #0:2[0x1c0]: Audio: mp2, 48000 Hz, stereo, s16p, 384 kb/s
File 'test.avi' already exists. Overwrite ? [y/N] [] y
Stream mapping:
[]   Stream #0:1 -> #0:0 (mpeg2video (native) -> mpeg4 (native))
[]   Stream #0:2 -> #0:1 (mp2 (native) -> mp3 (libmp3lame))
[] Press [q] to stop, [?] for help
[] Output #0, avi, to 'test.avi':
[]   Metadata:
[]     ISFT            : Lavf58.32.104
[]     Stream #0:0: Video: mpeg4 (FMP4 / 0x34504D46), yuv420p, 720x576 [SAR 16:15 DAR 4:3], q=2-31, 200 kb/s, 25 fps, 25 tbn, 25 tbc
[]     Metadata:
[]       encoder         : Lavc58.56.101 mpeg4
[]     Side data:
[]       cpb: bitrate max/min/avg: 0/0/200000 buffer size: 0 vbv_delay: N/A
[]     Stream #0:1: Audio: mp3 (libmp3lame) (U[0][0][0] / 0x0055), 48000 Hz, stereo, s16p
[]     Metadata:
[]       encoder         : Lavc58.56.101 libmp3lame
[] frame= 1069 fps=710 q=24.8 Lsize=    2255kB time=00:00:42.76 bitrate= 432.0kbits/s speed=28.4x    
[] video:1511kB audio:667kB subtitle:0kB other streams:0kB global headers:0kB muxing overhead: 3.539204%

This looks much better than your example, so i have to disagree that
theres a problem for calls during startup or some requirment of high 
complexity

diff --git a/libavutil/log.c b/libavutil/log.c
index 93a156b8e4..5109c773bd 100644
--- a/libavutil/log.c
+++ b/libavutil/log.c
@@ -266,7 +266,9 @@ static void format_line(void *avcl, int level, const char *fmt, va_list vl,
         av_bprintf(part+1, "[%s @ %p] ",
                  avc->item_name(avcl), avcl);
         if(type) type[1] = get_category(avcl);
-    }
+    } else if (*print_prefix)
+        av_bprintf(part+1, "[] ");
+
 
     if (*print_prefix && (level > AV_LOG_QUIET) && (flags & AV_LOG_PRINT_LEVEL))
         av_bprintf(part+2, "[%s] ", get_level_str(level));

[...]

-- 
Michael     GnuPG fingerprint: 9FF2128B147EF6730BADF133611EC787040B0FAB

Why not whip the teacher when the pupil misbehaves? -- Diogenes of Sinope
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 181 bytes
Desc: not available
URL: <http://ffmpeg.org/pipermail/ffmpeg-devel/attachments/20190906/04585b5f/attachment.sig>