From patchwork Fri Sep 6 18:55:47 2019 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 8bit X-Patchwork-Submitter: Michael Niedermayer X-Patchwork-Id: 14962 Return-Path: X-Original-To: patchwork@ffaux-bg.ffmpeg.org Delivered-To: patchwork@ffaux-bg.ffmpeg.org Received: from ffbox0-bg.mplayerhq.hu (ffbox0-bg.ffmpeg.org [79.124.17.100]) by ffaux.localdomain (Postfix) with ESMTP id F1B77449CDD for ; Fri, 6 Sep 2019 21:55:55 +0300 (EEST) Received: from [127.0.1.1] (localhost [127.0.0.1]) by ffbox0-bg.mplayerhq.hu (Postfix) with ESMTP id CD5CA680C46; Fri, 6 Sep 2019 21:55:55 +0300 (EEST) X-Original-To: ffmpeg-devel@ffmpeg.org Delivered-To: ffmpeg-devel@ffmpeg.org Received: from relay9-d.mail.gandi.net (relay9-d.mail.gandi.net [217.70.183.199]) by ffbox0-bg.mplayerhq.hu (Postfix) with ESMTPS id A3D026808CE for ; Fri, 6 Sep 2019 21:55:49 +0300 (EEST) X-Originating-IP: 213.47.68.29 Received: from localhost (213-47-68-29.cable.dynamic.surfer.at [213.47.68.29]) (Authenticated sender: michael@niedermayer.cc) by relay9-d.mail.gandi.net (Postfix) with ESMTPSA id D63F8FF805 for ; Fri, 6 Sep 2019 18:55:48 +0000 (UTC) Date: Fri, 6 Sep 2019 20:55:47 +0200 From: Michael Niedermayer To: FFmpeg development discussions and patches Message-ID: <20190906185547.GF3219@michaelspb> References: <2fbeadf9-3704-44e7-1501-2b40f396e6d3@vivanet.hu> MIME-Version: 1.0 In-Reply-To: User-Agent: Mutt/1.5.24 (2015-08-30) Subject: Re: [FFmpeg-devel] [PATCH] Add option to log timing X-BeenThere: ffmpeg-devel@ffmpeg.org X-Mailman-Version: 2.1.20 Precedence: list List-Id: FFmpeg development discussions and patches List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Reply-To: FFmpeg development discussions and patches Errors-To: ffmpeg-devel-bounces@ffmpeg.org Sender: "ffmpeg-devel" 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));