From patchwork Mon Mar 7 22:15:38 2022 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Pierre-Anthony Lemieux X-Patchwork-Id: 34633 Delivered-To: ffmpegpatchwork2@gmail.com Received: by 2002:a05:6838:d078:0:0:0:0 with SMTP id x24csp1905458nkx; Mon, 7 Mar 2022 14:16:41 -0800 (PST) X-Google-Smtp-Source: ABdhPJx7sXxeAxSboBXmXExqy5VxDT2j2kzWAdi7ICvhXQvPPfrxGYFJOkSHIlTM1OsgoC6XxUg4 X-Received: by 2002:a05:6402:2365:b0:415:ed07:70de with SMTP id a5-20020a056402236500b00415ed0770demr13195000eda.150.1646691401400; Mon, 07 Mar 2022 14:16:41 -0800 (PST) ARC-Seal: i=1; a=rsa-sha256; t=1646691401; cv=none; d=google.com; s=arc-20160816; b=g4YiR5qqlJvabciJqyeR/05eogSbuaPn9XGJlk0BFVJ5JsgVJKYQ6L8BnY7cO4jI0b s6/Xd8MQHVr13F05830U+3cyrm9ysM06AcnTNSMRPp6M4y/Qo7gSZarY6+9hGqUdTP89 NlVcdb0JpOmOQIOFjcf2AMmCzQPjCtegcVKnBxXX7R5aE3ZOP4rXunjRJRgKWKcLqLU5 PoyzT6oYZqh8nXK2ZQmar1zS4gomGqcrViW1+Q13fEAbSkxWXtabtoacTBcooTdOCMoQ rEaI7NnPctRnoyRNrBWyuR0FBt+G59HlYv5gqwOpo5+N1sh4otbGwiOmecDgeq/vFP8W jp+w== ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=arc-20160816; h=sender:errors-to:content-transfer-encoding:cc:reply-to :list-subscribe:list-help:list-post:list-archive:list-unsubscribe :list-id:precedence:subject:mime-version:references:in-reply-to :message-id:date:to:from:delivered-to; bh=4A4Q1cAMykGFaxfqQQ541vcvinXTv5XxwUWIzH1+GfY=; b=i7uDulPub0Or7pd7HKLXnjjpuSwJyAq2Rv+a73hwNQZNCsk13oTfBGAiThtlRo2MNe +iHkfb0q6h/1lCWjUtQ/asvcwGmFxB2ocFzqlnR8mjdAT4bgw/ZXXOlereWJDwBNdfdM yOKYbn14Uargb1f/mnF+4Zr62LxRY9IB++Ho0fAjcIEw7IfW1T6cvONzYNA3h/csyLwm vmqXda3lMMYEA0AUuJwZv5Hxq7csCTiEqIkDdQmaGq1JVjEoYBv0W0+Y9irV7zi/FcbO L5rg7LYReuBBp8rNC2gdAoQfOb/53eT7reoNDcqgZLldV8MwcnrD1kJRwN3+Wan8XytN 9vwQ== ARC-Authentication-Results: i=1; mx.google.com; spf=pass (google.com: domain of ffmpeg-devel-bounces@ffmpeg.org designates 79.124.17.100 as permitted sender) smtp.mailfrom=ffmpeg-devel-bounces@ffmpeg.org Return-Path: Received: from ffbox0-bg.mplayerhq.hu (ffbox0-bg.ffmpeg.org. [79.124.17.100]) by mx.google.com with ESMTP id ms24-20020a170907621800b006daff82aca8si4454770ejc.520.2022.03.07.14.16.41; Mon, 07 Mar 2022 14:16:41 -0800 (PST) Received-SPF: pass (google.com: domain of ffmpeg-devel-bounces@ffmpeg.org designates 79.124.17.100 as permitted sender) client-ip=79.124.17.100; Authentication-Results: mx.google.com; spf=pass (google.com: domain of ffmpeg-devel-bounces@ffmpeg.org designates 79.124.17.100 as permitted sender) smtp.mailfrom=ffmpeg-devel-bounces@ffmpeg.org Received: from [127.0.1.1] (localhost [127.0.0.1]) by ffbox0-bg.mplayerhq.hu (Postfix) with ESMTP id 3F75F68B196; Tue, 8 Mar 2022 00:16:22 +0200 (EET) X-Original-To: ffmpeg-devel@ffmpeg.org Delivered-To: ffmpeg-devel@ffmpeg.org Received: from mail-pj1-f45.google.com (mail-pj1-f45.google.com [209.85.216.45]) by ffbox0-bg.mplayerhq.hu (Postfix) with ESMTPS id 8131168B18F for ; Tue, 8 Mar 2022 00:16:16 +0200 (EET) Received: by mail-pj1-f45.google.com with SMTP id v1-20020a17090a088100b001bf25f97c6eso766297pjc.0 for ; Mon, 07 Mar 2022 14:16:16 -0800 (PST) X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20210112; h=x-gm-message-state:from:to:cc:subject:date:message-id:in-reply-to :references:mime-version:content-transfer-encoding; bh=TN7H518HNKeCPbdCF0F/reBROPhorrmQ+bsHQZCVUGY=; b=sFRXYhspt8PCCVjooBKAy08IcZbnl9Lk6tfoMMZVB8Q7w+uYhzCAwwz2IjIOSfMJdv YBrrqG3qHVGDpn1WdnhuWiXWQbUAst/6JcEWOZM6lHEuV50ujb+1ilvysNFvgS0BYiax XyyrFLYOIKCOMmg04mpiveF0yrU8w6oipN8kW0wpAIqmePkcGwn+EDo2F3pmLHDW4bxV wNsGQY3v+e/1Xw/ZOC5a/t1rqh2ZEMEzuw1ktK6VjFQkPpg1tsMBeVc9RaRmEFAd7C2C jGO4/+azMop9cvVgGgKGVPj15KC5JZyU2rn09ZR3mXWrpMC3MtaiYNLxGKYfzvc+m05H VEsw== X-Gm-Message-State: AOAM531t4ome2K1KdrmykAusZBs0CAbQuPn9cUe+wB4FVuXe0/rT0kzO wVpJV7h6id2hni61CH8rW+nBV4Eq2Gs= X-Received: by 2002:a17:902:b697:b0:151:4c2e:48be with SMTP id c23-20020a170902b69700b001514c2e48bemr14227042pls.70.1646691374335; Mon, 07 Mar 2022 14:16:14 -0800 (PST) Received: from localhost (76-14-89-2.sf-cable.astound.net. [76.14.89.2]) by smtp.gmail.com with ESMTPSA id f20-20020a056a001ad400b004f6e8f8f90bsm7838433pfv.109.2022.03.07.14.16.12 (version=TLS1_2 cipher=ECDHE-ECDSA-CHACHA20-POLY1305 bits=256/256); Mon, 07 Mar 2022 14:16:14 -0800 (PST) Received: by localhost (sSMTP sendmail emulation); Mon, 07 Mar 2022 14:15:49 -0800 From: pal@sandflow.com To: ffmpeg-devel@ffmpeg.org Date: Mon, 7 Mar 2022 14:15:38 -0800 Message-Id: <20220307221542.3265-3-pal@sandflow.com> X-Mailer: git-send-email 2.35.1.windows.2 In-Reply-To: <20220307221542.3265-1-pal@sandflow.com> References: <20220307221542.3265-1-pal@sandflow.com> MIME-Version: 1.0 Subject: [FFmpeg-devel] [PATCH v3 3/7] avformat/imf: clean-up and reduce logging X-BeenThere: ffmpeg-devel@ffmpeg.org X-Mailman-Version: 2.1.29 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 Cc: Pierre-Anthony Lemieux Errors-To: ffmpeg-devel-bounces@ffmpeg.org Sender: "ffmpeg-devel" X-TUID: SfHkcf+5v+wi From: Pierre-Anthony Lemieux --- libavformat/imfdec.c | 93 ++++++++++++++------------------------------ 1 file changed, 29 insertions(+), 64 deletions(-) diff --git a/libavformat/imfdec.c b/libavformat/imfdec.c index f208b262c3..ac212b05e1 100644 --- a/libavformat/imfdec.c +++ b/libavformat/imfdec.c @@ -203,11 +203,8 @@ static int parse_imf_asset_map_from_xml_dom(AVFormatContext *s, } if (asset_map_element->type != XML_ELEMENT_NODE || av_strcasecmp(asset_map_element->name, "AssetMap")) { - av_log(s, - AV_LOG_ERROR, - "Unable to parse asset map XML - wrong root node name[%s] type[%d]\n", - asset_map_element->name, - (int)asset_map_element->type); + av_log(s, AV_LOG_ERROR, "Unable to parse asset map XML - wrong root node name[%s] type[%d]\n", + asset_map_element->name, (int)asset_map_element->type); return AVERROR_INVALIDDATA; } @@ -333,11 +330,8 @@ static int parse_assetmap(AVFormatContext *s, const char *url) ret = parse_imf_asset_map_from_xml_dom(s, doc, &c->asset_locator_map, base_url); if (!ret) - av_log(s, - AV_LOG_DEBUG, - "Found %d assets from %s\n", - c->asset_locator_map.asset_count, - url); + av_log(s, AV_LOG_DEBUG, "Found %d assets from %s\n", + c->asset_locator_map.asset_count, url); xmlFreeDoc(doc); @@ -370,9 +364,7 @@ static int open_track_resource_context(AVFormatContext *s, IMFVirtualTrackResourcePlaybackCtx *track_resource = track->resources + resource_index; if (track_resource->ctx) { - av_log(s, - AV_LOG_DEBUG, - "Input context already opened for %s.\n", + av_log(s, AV_LOG_DEBUG, "Input context already opened for %s.\n", track_resource->locator->absolute_uri); return 0; } @@ -400,11 +392,8 @@ static int open_track_resource_context(AVFormatContext *s, NULL, &opts); if (ret < 0) { - av_log(s, - AV_LOG_ERROR, - "Could not open %s input context: %s\n", - track_resource->locator->absolute_uri, - av_err2str(ret)); + av_log(s, AV_LOG_ERROR, "Could not open %s input context: %s\n", + track_resource->locator->absolute_uri, av_err2str(ret)); goto cleanup; } av_dict_free(&opts); @@ -427,8 +416,7 @@ static int open_track_resource_context(AVFormatContext *s, st->time_base)) av_log(s, AV_LOG_WARNING, "Incoherent stream timebase " AVRATIONAL_FORMAT "and composition timeline position: " AVRATIONAL_FORMAT "\n", - st->time_base.num, st->time_base.den, - track->current_timestamp.den, track->current_timestamp.num); + AVRATIONAL_ARG(st->time_base), AVRATIONAL_ARG(track->current_timestamp)); if (seek_offset) { av_log(s, AV_LOG_DEBUG, "Seek at resource %s entry point: %" PRIi64 "\n", @@ -465,9 +453,7 @@ static int open_track_file_resource(AVFormatContext *s, asset_locator = find_asset_map_locator(&c->asset_locator_map, track_file_resource->track_file_uuid); if (!asset_locator) { - av_log(s, - AV_LOG_ERROR, - "Could not find asset locator for UUID: " FF_IMF_UUID_FORMAT "\n", + av_log(s, AV_LOG_ERROR, "Could not find asset locator for UUID: " FF_IMF_UUID_FORMAT "\n", UID_ARG(track_file_resource->track_file_uuid)); return AVERROR_INVALIDDATA; } @@ -618,9 +604,7 @@ static int open_cpl_tracks(AVFormatContext *s) if (c->cpl->main_image_2d_track) { if ((ret = open_virtual_track(s, c->cpl->main_image_2d_track, track_index++)) != 0) { - av_log(s, - AV_LOG_ERROR, - "Could not open image track " FF_IMF_UUID_FORMAT "\n", + av_log(s, AV_LOG_ERROR, "Could not open image track " FF_IMF_UUID_FORMAT "\n", UID_ARG(c->cpl->main_image_2d_track->base.id_uuid)); return ret; } @@ -628,9 +612,7 @@ static int open_cpl_tracks(AVFormatContext *s) for (uint32_t i = 0; i < c->cpl->main_audio_track_count; i++) { if ((ret = open_virtual_track(s, &c->cpl->main_audio_tracks[i], track_index++)) != 0) { - av_log(s, - AV_LOG_ERROR, - "Could not open audio track " FF_IMF_UUID_FORMAT "\n", + av_log(s, AV_LOG_ERROR, "Could not open audio track " FF_IMF_UUID_FORMAT "\n", UID_ARG(c->cpl->main_audio_tracks[i].base.id_uuid)); return ret; } @@ -706,13 +688,9 @@ static IMFVirtualTrackPlaybackCtx *get_next_track_with_minimum_timestamp(AVForma AVRational minimum_timestamp = av_make_q(INT32_MAX, 1); for (uint32_t i = c->track_count; i > 0; i--) { - av_log(s, - AV_LOG_DEBUG, - "Compare track %d timestamp " AVRATIONAL_FORMAT + av_log(s, AV_LOG_TRACE, "Compare track %d timestamp " AVRATIONAL_FORMAT " to minimum " AVRATIONAL_FORMAT - " (over duration: " AVRATIONAL_FORMAT - ")\n", - i, + " (over duration: " AVRATIONAL_FORMAT ")\n", i, AVRATIONAL_ARG(c->tracks[i - 1]->current_timestamp), AVRATIONAL_ARG(minimum_timestamp), AVRATIONAL_ARG(c->tracks[i - 1]->duration)); @@ -723,12 +701,8 @@ static IMFVirtualTrackPlaybackCtx *get_next_track_with_minimum_timestamp(AVForma } } - av_log(s, - AV_LOG_DEBUG, - "Found next track to read: %d (timestamp: %lf / %lf)\n", - track->index, - av_q2d(track->current_timestamp), - av_q2d(minimum_timestamp)); + av_log(s, AV_LOG_DEBUG, "Found next track to read: %d (timestamp: %lf / %lf)\n", + track->index, av_q2d(track->current_timestamp), av_q2d(minimum_timestamp)); return track; } @@ -742,7 +716,7 @@ static int get_resource_context_for_timestamp(AVFormatContext *s, IMFVirtualTrac } av_log(s, - AV_LOG_DEBUG, + AV_LOG_TRACE, "Looking for track %d resource for timestamp = %lf / %lf\n", track->index, av_q2d(track->current_timestamp), @@ -750,15 +724,9 @@ static int get_resource_context_for_timestamp(AVFormatContext *s, IMFVirtualTrac for (uint32_t i = 0; i < track->resource_count; i++) { if (av_cmp_q(track->resources[i].end_time, track->current_timestamp) > 0) { - av_log(s, - AV_LOG_DEBUG, - "Found resource %d in track %d to read at timestamp %lf: " - "entry=%" PRIu32 - ", duration=%" PRIu32 - ", editrate=" AVRATIONAL_FORMAT, - i, - track->index, - av_q2d(track->current_timestamp), + av_log(s, AV_LOG_DEBUG, "Found resource %d in track %d to read at timestamp %lf: " + "entry=%" PRIu32 ", duration=%" PRIu32 ", editrate=" AVRATIONAL_FORMAT "\n", + i, track->index, av_q2d(track->current_timestamp), track->resources[i].resource->base.entry_point, track->resources[i].resource->base.duration, AVRATIONAL_ARG(track->resources[i].resource->base.edit_rate)); @@ -766,9 +734,7 @@ static int get_resource_context_for_timestamp(AVFormatContext *s, IMFVirtualTrac if (track->current_resource_index != i) { int ret; - av_log(s, - AV_LOG_DEBUG, - "Switch resource on track %d: re-open context\n", + av_log(s, AV_LOG_TRACE, "Switch resource on track %d: re-open context\n", track->index); ret = open_track_resource_context(s, track, i); @@ -804,15 +770,13 @@ static int imf_read_packet(AVFormatContext *s, AVPacket *pkt) return ret; ret = av_read_frame(resource->ctx, pkt); - if (ret) { - av_log(s, AV_LOG_ERROR, "Failed to read frame\n"); + if (ret) return ret; - } av_log(s, AV_LOG_DEBUG, "Got packet: pts=%" PRId64 ", dts=%" PRId64 ", duration=%" PRId64 ", stream_index=%d, pos=%" PRId64 ", time_base=" AVRATIONAL_FORMAT "\n", pkt->pts, pkt->dts, pkt->duration, - pkt->stream_index, pkt->pos, pkt->time_base.num, pkt->time_base.den); + pkt->stream_index, pkt->pos, AVRATIONAL_ARG(pkt->time_base)); /* IMF resources contain only one stream */ @@ -832,9 +796,10 @@ static int imf_read_packet(AVFormatContext *s, AVPacket *pkt) if (pkt->dts != AV_NOPTS_VALUE) pkt->dts += delta_ts; } else { - av_log(s, AV_LOG_WARNING, "Incoherent time stamp " AVRATIONAL_FORMAT " for time base " AVRATIONAL_FORMAT, - resource->ts_offset.num, resource->ts_offset.den, pkt->time_base.num, - pkt->time_base.den); + av_log(s, AV_LOG_WARNING, "Incoherent time stamp " AVRATIONAL_FORMAT + " for time base " AVRATIONAL_FORMAT, + AVRATIONAL_ARG(resource->ts_offset), + AVRATIONAL_ARG(pkt->time_base)); } /* advance the track timestamp by the packet duration */ @@ -857,7 +822,7 @@ static int imf_read_packet(AVFormatContext *s, AVPacket *pkt) if (!ret) pkt->duration = new_pkt_dur; else - av_log(s, AV_LOG_WARNING, "Incoherent time base in packet duration calculation"); + av_log(s, AV_LOG_WARNING, "Incoherent time base in packet duration calculation\n"); /* shrink the packet itself for audio essence */ @@ -882,7 +847,7 @@ static int imf_read_packet(AVFormatContext *s, AVPacket *pkt) av_make_q(1, st->codecpar->sample_rate)); if (ret || skip_samples < 0 || skip_samples > UINT32_MAX) { - av_log(s, AV_LOG_WARNING, "Cannot skip audio samples"); + av_log(s, AV_LOG_WARNING, "Cannot skip audio samples\n"); } else { uint8_t *side_data = av_packet_new_side_data(pkt, AV_PKT_DATA_SKIP_SAMPLES, 10); if (!side_data) @@ -896,7 +861,7 @@ static int imf_read_packet(AVFormatContext *s, AVPacket *pkt) next_timestamp = resource->end_time; } else { - av_log(s, AV_LOG_WARNING, "Non-audio packet duration reduced"); + av_log(s, AV_LOG_WARNING, "Non-audio packet duration reduced\n"); } }