From 3b1d4102afa8b97ad7d2ae2ed4d0f1372cf81e77 Mon Sep 17 00:00:00 2001 From: "FeRD (Frank Dana)" Date: Wed, 12 Jan 2022 01:08:31 -0500 Subject: [PATCH 1/7] FFmpegWriter: Format ZmqLogger calls, move headers --- src/FFmpegWriter.cpp | 224 ++++++++++++++++++++++++++++++++----------- src/FFmpegWriter.h | 9 -- 2 files changed, 170 insertions(+), 63 deletions(-) diff --git a/src/FFmpegWriter.cpp b/src/FFmpegWriter.cpp index 5662c271..bbd23d5b 100644 --- a/src/FFmpegWriter.cpp +++ b/src/FFmpegWriter.cpp @@ -13,13 +13,20 @@ // // SPDX-License-Identifier: LGPL-3.0-or-later +#include +#include +#include +#include +#include + #include "FFmpegUtilities.h" #include "FFmpegWriter.h" #include "Exceptions.h" #include "Frame.h" - -#include +#include "OpenMPUtilities.h" +#include "Settings.h" +#include "ZmqLogger.h" using namespace openshot; @@ -133,7 +140,11 @@ void FFmpegWriter::auto_detect_format() { // initialize streams void FFmpegWriter::initialize_streams() { - ZmqLogger::Instance()->AppendDebugMethod("FFmpegWriter::initialize_streams", "fmt->video_codec", fmt->video_codec, "fmt->audio_codec", fmt->audio_codec, "AV_CODEC_ID_NONE", AV_CODEC_ID_NONE); + ZmqLogger::Instance()->AppendDebugMethod( + "FFmpegWriter::initialize_streams", + "fmt->video_codec", fmt->video_codec, + "fmt->audio_codec", fmt->audio_codec, + "AV_CODEC_ID_NONE", AV_CODEC_ID_NONE); // Add the audio and video streams using the default format codecs and initialize the codecs video_st = NULL; @@ -253,7 +264,11 @@ void FFmpegWriter::SetVideoOptions(bool has_video, std::string codec, Fraction f info.display_ratio.num = size.num; info.display_ratio.den = size.den; - ZmqLogger::Instance()->AppendDebugMethod("FFmpegWriter::SetVideoOptions (" + codec + ")", "width", width, "height", height, "size.num", size.num, "size.den", size.den, "fps.num", fps.num, "fps.den", fps.den); + ZmqLogger::Instance()->AppendDebugMethod( + "FFmpegWriter::SetVideoOptions (" + codec + ")", + "width", width, "height", height, + "size.num", size.num, "size.den", size.den, + "fps.num", fps.num, "fps.den", fps.den); // Enable / Disable video info.has_video = has_video; @@ -568,7 +583,9 @@ void FFmpegWriter::SetOption(StreamType stream, std::string name, std::string va AV_OPTION_SET(st, c->priv_data, name.c_str(), value.c_str(), c); } - ZmqLogger::Instance()->AppendDebugMethod("FFmpegWriter::SetOption (" + (std::string)name + ")", "stream == VIDEO_STREAM", stream == VIDEO_STREAM); + ZmqLogger::Instance()->AppendDebugMethod( + "FFmpegWriter::SetOption (" + (std::string)name + ")", + "stream == VIDEO_STREAM", stream == VIDEO_STREAM); // Muxing dictionary is not part of the codec context. // Just reusing SetOption function to set popular multiplexing presets. @@ -604,7 +621,10 @@ void FFmpegWriter::PrepareStreams() { if (!info.has_audio && !info.has_video) throw InvalidOptions("No video or audio options have been set. You must set has_video or has_audio (or both).", path); - ZmqLogger::Instance()->AppendDebugMethod("FFmpegWriter::PrepareStreams [" + path + "]", "info.has_audio", info.has_audio, "info.has_video", info.has_video); + ZmqLogger::Instance()->AppendDebugMethod( + "FFmpegWriter::PrepareStreams [" + path + "]", + "info.has_audio", info.has_audio, + "info.has_video", info.has_video); // Initialize the streams (i.e. add the streams) initialize_streams(); @@ -643,7 +663,8 @@ void FFmpegWriter::WriteHeader() { // Write the stream header if (avformat_write_header(oc, &dict) != 0) { - ZmqLogger::Instance()->AppendDebugMethod("FFmpegWriter::WriteHeader (avformat_write_header)"); + ZmqLogger::Instance()->AppendDebugMethod( + "FFmpegWriter::WriteHeader (avformat_write_header)"); throw InvalidFile("Could not write header to file.", path); }; @@ -671,7 +692,13 @@ void FFmpegWriter::WriteFrame(std::shared_ptr frame) { if (info.has_audio && audio_st) spooled_audio_frames.push_back(frame); - ZmqLogger::Instance()->AppendDebugMethod("FFmpegWriter::WriteFrame", "frame->number", frame->number, "spooled_video_frames.size()", spooled_video_frames.size(), "spooled_audio_frames.size()", spooled_audio_frames.size(), "cache_size", cache_size, "is_writing", is_writing); + ZmqLogger::Instance()->AppendDebugMethod( + "FFmpegWriter::WriteFrame", + "frame->number", frame->number, + "spooled_video_frames.size()", spooled_video_frames.size(), + "spooled_audio_frames.size()", spooled_audio_frames.size(), + "cache_size", cache_size, + "is_writing", is_writing); // Write the frames once it reaches the correct cache size if ((int)spooled_video_frames.size() == cache_size || (int)spooled_audio_frames.size() == cache_size) { @@ -685,7 +712,10 @@ void FFmpegWriter::WriteFrame(std::shared_ptr frame) { // Write all frames in the queue to the video file. void FFmpegWriter::write_queued_frames() { - ZmqLogger::Instance()->AppendDebugMethod("FFmpegWriter::write_queued_frames", "spooled_video_frames.size()", spooled_video_frames.size(), "spooled_audio_frames.size()", spooled_audio_frames.size()); + ZmqLogger::Instance()->AppendDebugMethod( + "FFmpegWriter::write_queued_frames", + "spooled_video_frames.size()", spooled_video_frames.size(), + "spooled_audio_frames.size()", spooled_audio_frames.size()); // Flip writing flag is_writing = true; @@ -778,7 +808,10 @@ void FFmpegWriter::write_queued_frames() { // Write a block of frames from a reader void FFmpegWriter::WriteFrame(ReaderBase *reader, int64_t start, int64_t length) { - ZmqLogger::Instance()->AppendDebugMethod("FFmpegWriter::WriteFrame (from Reader)", "start", start, "length", length); + ZmqLogger::Instance()->AppendDebugMethod( + "FFmpegWriter::WriteFrame (from Reader)", + "start", start, + "length", length); // Loop through each frame (and encoded it) for (int64_t number = start; number <= length; number++) { @@ -867,7 +900,10 @@ void FFmpegWriter::flush_encoders() { #endif // IS_FFMPEG_3_2 if (error_code < 0) { - ZmqLogger::Instance()->AppendDebugMethod("FFmpegWriter::flush_encoders ERROR [" + av_err2string(error_code) + "]", "error_code", error_code); + ZmqLogger::Instance()->AppendDebugMethod( + "FFmpegWriter::flush_encoders ERROR [" + + av_err2string(error_code) + "]", + "error_code", error_code); } if (!got_packet) { break; @@ -880,7 +916,10 @@ void FFmpegWriter::flush_encoders() { // Write packet error_code = av_interleaved_write_frame(oc, &pkt); if (error_code < 0) { - ZmqLogger::Instance()->AppendDebugMethod("FFmpegWriter::flush_encoders ERROR [" + av_err2string(error_code) + "]", "error_code", error_code); + ZmqLogger::Instance()->AppendDebugMethod( + "FFmpegWriter::flush_encoders ERROR [" + + av_err2string(error_code) + "]", + "error_code", error_code); } } @@ -903,8 +942,9 @@ void FFmpegWriter::flush_encoders() { #endif if (error_code < 0) { ZmqLogger::Instance()->AppendDebugMethod( - "FFmpegWriter::flush_encoders ERROR [" + av_err2string(error_code) + "]", - "error_code", error_code); + "FFmpegWriter::flush_encoders ERROR [" + + av_err2string(error_code) + "]", + "error_code", error_code); } if (!got_packet) { break; @@ -925,8 +965,9 @@ void FFmpegWriter::flush_encoders() { error_code = av_interleaved_write_frame(oc, &pkt); if (error_code < 0) { ZmqLogger::Instance()->AppendDebugMethod( - "FFmpegWriter::flush_encoders ERROR [" + av_err2string(error_code) + "]", - "error_code", error_code); + "FFmpegWriter::flush_encoders ERROR [" + + av_err2string(error_code) + "]", + "error_code", error_code); } // Increment PTS by duration of packet @@ -1107,7 +1148,15 @@ AVStream *FFmpegWriter::add_audio_stream() { #endif AV_COPY_PARAMS_FROM_CONTEXT(st, c); - ZmqLogger::Instance()->AppendDebugMethod("FFmpegWriter::add_audio_stream", "c->codec_id", c->codec_id, "c->bit_rate", c->bit_rate, "c->channels", c->channels, "c->sample_fmt", c->sample_fmt, "c->channel_layout", c->channel_layout, "c->sample_rate", c->sample_rate); + + ZmqLogger::Instance()->AppendDebugMethod( + "FFmpegWriter::add_audio_stream", + "c->codec_id", c->codec_id, + "c->bit_rate", c->bit_rate, + "c->channels", c->channels, + "c->sample_fmt", c->sample_fmt, + "c->channel_layout", c->channel_layout, + "c->sample_rate", c->sample_rate); return st; } @@ -1290,13 +1339,14 @@ AVStream *FFmpegWriter::add_video_stream() { } AV_COPY_PARAMS_FROM_CONTEXT(st, c); -#if (LIBAVFORMAT_VERSION_MAJOR < 58) - // FFmpeg < 4.0 - ZmqLogger::Instance()->AppendDebugMethod("FFmpegWriter::add_video_stream (" + (std::string)fmt->name + " : " + (std::string)av_get_pix_fmt_name(c->pix_fmt) + ")", "c->codec_id", c->codec_id, "c->bit_rate", c->bit_rate, "c->pix_fmt", c->pix_fmt, "oc->oformat->flags", oc->oformat->flags, "AVFMT_RAWPICTURE", AVFMT_RAWPICTURE); -#else - ZmqLogger::Instance()->AppendDebugMethod("FFmpegWriter::add_video_stream (" + (std::string)fmt->name + " : " + (std::string)av_get_pix_fmt_name(c->pix_fmt) + ")", "c->codec_id", c->codec_id, "c->bit_rate", c->bit_rate, "c->pix_fmt", c->pix_fmt, "oc->oformat->flags", oc->oformat->flags); -#endif - + ZmqLogger::Instance()->AppendDebugMethod( + "FFmpegWriter::add_video_stream (" + + (std::string)fmt->name + " : " + + (std::string)av_get_pix_fmt_name(c->pix_fmt) + ")", + "c->codec_id", c->codec_id, + "c->bit_rate", c->bit_rate, + "c->pix_fmt", c->pix_fmt, + "oc->oformat->flags", oc->oformat->flags); return st; } @@ -1368,7 +1418,12 @@ void FFmpegWriter::open_audio(AVFormatContext *oc, AVStream *st) { av_dict_set(&st->metadata, iter->first.c_str(), iter->second.c_str(), 0); } - ZmqLogger::Instance()->AppendDebugMethod("FFmpegWriter::open_audio", "audio_codec_ctx->thread_count", audio_codec_ctx->thread_count, "audio_input_frame_size", audio_input_frame_size, "buffer_size", AVCODEC_MAX_AUDIO_FRAME_SIZE + MY_INPUT_BUFFER_PADDING_SIZE); + ZmqLogger::Instance()->AppendDebugMethod( + "FFmpegWriter::open_audio", + "audio_codec_ctx->thread_count", audio_codec_ctx->thread_count, + "audio_input_frame_size", audio_input_frame_size, + "buffer_size", + AVCODEC_MAX_AUDIO_FRAME_SIZE + MY_INPUT_BUFFER_PADDING_SIZE); } // open video codec @@ -1406,16 +1461,22 @@ void FFmpegWriter::open_video(AVFormatContext *oc, AVStream *st) { #elif defined(_WIN32) || defined(__APPLE__) if( adapter_ptr != NULL ) { #endif - ZmqLogger::Instance()->AppendDebugMethod("Encode Device present using device", "adapter", adapter_num); + ZmqLogger::Instance()->AppendDebugMethod( + "Encode Device present using device", + "adapter", adapter_num); } else { - adapter_ptr = NULL; // use default - ZmqLogger::Instance()->AppendDebugMethod("Encode Device not present, using default"); - } - if (av_hwdevice_ctx_create(&hw_device_ctx, hw_en_av_device_type, - adapter_ptr, NULL, 0) < 0) { - ZmqLogger::Instance()->AppendDebugMethod("FFmpegWriter::open_video ERROR creating hwdevice, Codec name:", info.vcodec.c_str(), -1); - throw InvalidCodec("Could not create hwdevice", path); + adapter_ptr = NULL; // use default + ZmqLogger::Instance()->AppendDebugMethod( + "Encode Device not present, using default"); + } + if (av_hwdevice_ctx_create(&hw_device_ctx, + hw_en_av_device_type, adapter_ptr, NULL, 0) < 0) + { + ZmqLogger::Instance()->AppendDebugMethod( + "FFmpegWriter::open_video ERROR creating hwdevice, Codec name:", + info.vcodec.c_str(), -1); + throw InvalidCodec("Could not create hwdevice", path); } } #endif // USE_HW_ACCEL @@ -1472,16 +1533,23 @@ void FFmpegWriter::open_video(AVFormatContext *oc, AVStream *st) { // tested to work with defaults break; default: - ZmqLogger::Instance()->AppendDebugMethod("No codec-specific options defined for this codec. HW encoding may fail", + ZmqLogger::Instance()->AppendDebugMethod( + "No codec-specific options defined for this codec. HW encoding may fail", "codec_id", video_codec_ctx->codec_id); break; } // set hw_frames_ctx for encoder's AVCodecContext int err; - if ((err = set_hwframe_ctx(video_codec_ctx, hw_device_ctx, info.width, info.height)) < 0) { - ZmqLogger::Instance()->AppendDebugMethod("FFmpegWriter::open_video (set_hwframe_ctx) ERROR faled to set hwframe context", - "width", info.width, "height", info.height, av_err2string(err), -1); + if ((err = set_hwframe_ctx( + video_codec_ctx, hw_device_ctx, + info.width, info.height)) < 0) + { + ZmqLogger::Instance()->AppendDebugMethod( + "FFmpegWriter::open_video (set_hwframe_ctx) ERROR faled to set hwframe context", + "width", info.width, + "height", info.height, + av_err2string(err), -1); } } #endif // USE_HW_ACCEL @@ -1499,7 +1567,9 @@ void FFmpegWriter::open_video(AVFormatContext *oc, AVStream *st) { av_dict_set(&st->metadata, iter->first.c_str(), iter->second.c_str(), 0); } - ZmqLogger::Instance()->AppendDebugMethod("FFmpegWriter::open_video", "video_codec_ctx->thread_count", video_codec_ctx->thread_count); + ZmqLogger::Instance()->AppendDebugMethod( + "FFmpegWriter::open_video", + "video_codec_ctx->thread_count", video_codec_ctx->thread_count); } @@ -1572,7 +1642,14 @@ void FFmpegWriter::write_audio_packets(bool is_final) { int samples_position = 0; - ZmqLogger::Instance()->AppendDebugMethod("FFmpegWriter::write_audio_packets", "is_final", is_final, "total_frame_samples", total_frame_samples, "channel_layout_in_frame", channel_layout_in_frame, "channels_in_frame", channels_in_frame, "samples_in_frame", samples_in_frame, "LAYOUT_MONO", LAYOUT_MONO); + ZmqLogger::Instance()->AppendDebugMethod( + "FFmpegWriter::write_audio_packets", + "is_final", is_final, + "total_frame_samples", total_frame_samples, + "channel_layout_in_frame", channel_layout_in_frame, + "channels_in_frame", channels_in_frame, + "samples_in_frame", samples_in_frame, + "LAYOUT_MONO", LAYOUT_MONO); // Keep track of the original sample format AVSampleFormat output_sample_fmt = audio_codec_ctx->sample_fmt; @@ -1587,7 +1664,10 @@ void FFmpegWriter::write_audio_packets(bool is_final) { // Fill input frame with sample data int error_code = avcodec_fill_audio_frame(audio_frame, channels_in_frame, AV_SAMPLE_FMT_S16, (uint8_t *) all_queued_samples, all_queued_samples_size, 0); if (error_code < 0) { - ZmqLogger::Instance()->AppendDebugMethod("FFmpegWriter::write_audio_packets ERROR [" + av_err2string(error_code) + "]", "error_code", error_code); + ZmqLogger::Instance()->AppendDebugMethod( + "FFmpegWriter::write_audio_packets ERROR [" + + av_err2string(error_code) + "]", + "error_code", error_code); } // Do not convert audio to planar format (yet). We need to keep everything interleaved at this point. @@ -1624,7 +1704,14 @@ void FFmpegWriter::write_audio_packets(bool is_final) { audio_converted->nb_samples = total_frame_samples / channels_in_frame; av_samples_alloc(audio_converted->data, audio_converted->linesize, info.channels, audio_converted->nb_samples, output_sample_fmt, 0); - ZmqLogger::Instance()->AppendDebugMethod("FFmpegWriter::write_audio_packets (1st resampling)", "in_sample_fmt", AV_SAMPLE_FMT_S16, "out_sample_fmt", output_sample_fmt, "in_sample_rate", sample_rate_in_frame, "out_sample_rate", info.sample_rate, "in_channels", channels_in_frame, "out_channels", info.channels); + ZmqLogger::Instance()->AppendDebugMethod( + "FFmpegWriter::write_audio_packets (1st resampling)", + "in_sample_fmt", AV_SAMPLE_FMT_S16, + "out_sample_fmt", output_sample_fmt, + "in_sample_rate", sample_rate_in_frame, + "out_sample_rate", info.sample_rate, + "in_channels", channels_in_frame, + "out_channels", info.channels); // setup resample context if (!avr) { @@ -1673,7 +1760,10 @@ void FFmpegWriter::write_audio_packets(bool is_final) { AV_FREE_FRAME(&audio_converted); all_queued_samples = NULL; // this array cleared with above call - ZmqLogger::Instance()->AppendDebugMethod("FFmpegWriter::write_audio_packets (Successfully completed 1st resampling)", "nb_samples", nb_samples, "remaining_frame_samples", remaining_frame_samples); + ZmqLogger::Instance()->AppendDebugMethod( + "FFmpegWriter::write_audio_packets (Successfully completed 1st resampling)", + "nb_samples", nb_samples, + "remaining_frame_samples", remaining_frame_samples); } // Loop until no more samples @@ -1717,7 +1807,7 @@ void FFmpegWriter::write_audio_packets(bool is_final) { AV_RESET_FRAME(frame_final); if (av_sample_fmt_is_planar(audio_codec_ctx->sample_fmt)) { ZmqLogger::Instance()->AppendDebugMethod( - "FFmpegWriter::write_audio_packets (2nd resampling for Planar formats)", + "FFmpegWriter::write_audio_packets (2nd resampling for Planar formats)", "in_sample_fmt", output_sample_fmt, "out_sample_fmt", audio_codec_ctx->sample_fmt, "in_sample_rate", info.sample_rate, @@ -1794,7 +1884,9 @@ void FFmpegWriter::write_audio_packets(bool is_final) { AV_FREE_FRAME(&audio_frame); all_queued_samples = NULL; // this array cleared with above call - ZmqLogger::Instance()->AppendDebugMethod("FFmpegWriter::write_audio_packets (Successfully completed 2nd resampling for Planar formats)", "nb_samples", nb_samples); + ZmqLogger::Instance()->AppendDebugMethod( + "FFmpegWriter::write_audio_packets (Successfully completed 2nd resampling for Planar formats)", + "nb_samples", nb_samples); } else { // Create a new array @@ -1884,7 +1976,10 @@ void FFmpegWriter::write_audio_packets(bool is_final) { } if (error_code < 0) { - ZmqLogger::Instance()->AppendDebugMethod("FFmpegWriter::write_audio_packets ERROR [" + av_err2string(error_code) + "]", "error_code", error_code); + ZmqLogger::Instance()->AppendDebugMethod( + "FFmpegWriter::write_audio_packets ERROR [" + + av_err2string(error_code) + "]", + "error_code", error_code); } // Increment PTS (no pkt.duration, so calculate with maths) @@ -1991,7 +2086,11 @@ void FFmpegWriter::process_video_packet(std::shared_ptr frame) { // Fill with data AV_COPY_PICTURE_DATA(frame_source, (uint8_t *) pixels, PIX_FMT_RGBA, source_image_width, source_image_height); - ZmqLogger::Instance()->AppendDebugMethod("FFmpegWriter::process_video_packet", "frame->number", frame->number, "bytes_source", bytes_source, "bytes_final", bytes_final); + ZmqLogger::Instance()->AppendDebugMethod( + "FFmpegWriter::process_video_packet", + "frame->number", frame->number, + "bytes_source", bytes_source, + "bytes_final", bytes_final); // Resize & convert pixel format sws_scale(scaler, frame_source->data, frame_source->linesize, 0, @@ -2008,12 +2107,18 @@ void FFmpegWriter::process_video_packet(std::shared_ptr frame) { bool FFmpegWriter::write_video_packet(std::shared_ptr frame, AVFrame *frame_final) { #if (LIBAVFORMAT_VERSION_MAJOR >= 58) // FFmpeg 4.0+ - ZmqLogger::Instance()->AppendDebugMethod("FFmpegWriter::write_video_packet", - "frame->number", frame->number, "oc->oformat->flags", oc->oformat->flags); + ZmqLogger::Instance()->AppendDebugMethod( + "FFmpegWriter::write_video_packet", + "frame->number", frame->number, + "oc->oformat->flags", oc->oformat->flags); if (AV_GET_CODEC_TYPE(video_st) == AVMEDIA_TYPE_VIDEO && AV_FIND_DECODER_CODEC_ID(video_st) == AV_CODEC_ID_RAWVIDEO) { #else - ZmqLogger::Instance()->AppendDebugMethod("FFmpegWriter::write_video_packet", + // TODO: Should we have moved away from oc->oformat->flags / AVFMT_RAWPICTURE + // on ffmpeg < 4.0 as well? + // Does AV_CODEC_ID_RAWVIDEO not work in ffmpeg 3.x? + ZmqLogger::Instance()->AppendDebugMethod( + "FFmpegWriter::write_video_packet", "frame->number", frame->number, "oc->oformat->flags & AVFMT_RAWPICTURE", oc->oformat->flags & AVFMT_RAWPICTURE); @@ -2034,7 +2139,10 @@ bool FFmpegWriter::write_video_packet(std::shared_ptr frame, AVFrame *fra /* write the compressed frame in the media file */ int error_code = av_interleaved_write_frame(oc, &pkt); if (error_code < 0) { - ZmqLogger::Instance()->AppendDebugMethod("FFmpegWriter::write_video_packet ERROR [" + av_err2string(error_code) + "]", "error_code", error_code); + ZmqLogger::Instance()->AppendDebugMethod( + "FFmpegWriter::write_video_packet ERROR [" + + av_err2string(error_code) + "]", + "error_code", error_code); return false; } @@ -2087,7 +2195,8 @@ bool FFmpegWriter::write_video_packet(std::shared_ptr frame, AVFrame *fra } error_code = ret; if (ret < 0 ) { - ZmqLogger::Instance()->AppendDebugMethod("FFmpegWriter::write_video_packet (Frame not sent)"); + ZmqLogger::Instance()->AppendDebugMethod( + "FFmpegWriter::write_video_packet (Frame not sent)"); if (ret == AVERROR(EAGAIN) ) { std::clog << "Frame EAGAIN\n"; } @@ -2115,10 +2224,14 @@ bool FFmpegWriter::write_video_packet(std::shared_ptr frame, AVFrame *fra // Write video packet (older than FFmpeg 3.2) error_code = avcodec_encode_video2(video_codec_ctx, &pkt, frame_final, &got_packet_ptr); if (error_code != 0) { - ZmqLogger::Instance()->AppendDebugMethod("FFmpegWriter::write_video_packet ERROR [" + av_err2string(error_code) + "]", "error_code", error_code); + ZmqLogger::Instance()->AppendDebugMethod( + "FFmpegWriter::write_video_packet ERROR [" + + av_err2string(error_code) + "]", + "error_code", error_code); } if (got_packet_ptr == 0) { - ZmqLogger::Instance()->AppendDebugMethod("FFmpegWriter::write_video_packet (Frame gotpacket error)"); + ZmqLogger::Instance()->AppendDebugMethod( + "FFmpegWriter::write_video_packet (Frame gotpacket error)"); } #endif // IS_FFMPEG_3_2 @@ -2131,7 +2244,10 @@ bool FFmpegWriter::write_video_packet(std::shared_ptr frame, AVFrame *fra /* write the compressed frame in the media file */ int result = av_interleaved_write_frame(oc, &pkt); if (result < 0) { - ZmqLogger::Instance()->AppendDebugMethod("FFmpegWriter::write_video_packet ERROR [" + av_err2string(result) + "]", "result", result); + ZmqLogger::Instance()->AppendDebugMethod( + "FFmpegWriter::write_video_packet ERROR [" + + av_err2string(result) + "]", + "result", result); return false; } } diff --git a/src/FFmpegWriter.h b/src/FFmpegWriter.h index 62f707b0..ff27e8a1 100644 --- a/src/FFmpegWriter.h +++ b/src/FFmpegWriter.h @@ -22,15 +22,6 @@ // Include FFmpeg headers and macros #include "FFmpegUtilities.h" -#include -#include -#include -#include "CacheMemory.h" -#include "OpenMPUtilities.h" -#include "ZmqLogger.h" -#include "Settings.h" - - namespace openshot { /// This enumeration designates the type of stream when encoding (video or audio) From 806052f9c8fd22220e93726da4fd4cc4c4eeab4d Mon Sep 17 00:00:00 2001 From: "FeRD (Frank Dana)" Date: Wed, 12 Jan 2022 10:52:05 -0500 Subject: [PATCH 2/7] Clip, Timeline: Reformat logging calls --- src/Clip.cpp | 71 ++++++++++++++---- src/Timeline.cpp | 184 ++++++++++++++++++++++++++++++++++------------- 2 files changed, 191 insertions(+), 64 deletions(-) diff --git a/src/Clip.cpp b/src/Clip.cpp index 7fdd9555..a98875e1 100644 --- a/src/Clip.cpp +++ b/src/Clip.cpp @@ -699,7 +699,9 @@ std::shared_ptr Clip::GetOrCreateFrame(int64_t number) { try { // Debug output - ZmqLogger::Instance()->AppendDebugMethod("Clip::GetOrCreateFrame (from reader)", "number", number); + ZmqLogger::Instance()->AppendDebugMethod( + "Clip::GetOrCreateFrame (from reader)", + "number", number); // Attempt to get a frame (but this could fail if a reader has just been closed) auto reader_frame = reader->GetFrame(number); @@ -727,7 +729,10 @@ std::shared_ptr Clip::GetOrCreateFrame(int64_t number) int estimated_samples_in_frame = Frame::GetSamplesPerFrame(number, reader->info.fps, reader->info.sample_rate, reader->info.channels); // Debug output - ZmqLogger::Instance()->AppendDebugMethod("Clip::GetOrCreateFrame (create blank)", "number", number, "estimated_samples_in_frame", estimated_samples_in_frame); + ZmqLogger::Instance()->AppendDebugMethod( + "Clip::GetOrCreateFrame (create blank)", + "number", number, + "estimated_samples_in_frame", estimated_samples_in_frame); // Create blank frame auto new_frame = std::make_shared( @@ -1242,7 +1247,12 @@ void Clip::apply_keyframes(std::shared_ptr frame, std::shared_ptr if (Waveform()) { // Debug output - ZmqLogger::Instance()->AppendDebugMethod("Clip::get_transform (Generate Waveform Image)", "frame->number", frame->number, "Waveform()", Waveform(), "background_canvas->width()", background_canvas->width(), "background_canvas->height()", background_canvas->height()); + ZmqLogger::Instance()->AppendDebugMethod( + "Clip::get_transform (Generate Waveform Image)", + "frame->number", frame->number, + "Waveform()", Waveform(), + "background_canvas->width()", background_canvas->width(), + "background_canvas->height()", background_canvas->height()); // Get the color of the waveform int red = wave_color.red.GetInt(frame->number); @@ -1259,7 +1269,11 @@ void Clip::apply_keyframes(std::shared_ptr frame, std::shared_ptr QTransform transform = get_transform(frame, background_canvas->width(), background_canvas->height()); // Debug output - ZmqLogger::Instance()->AppendDebugMethod("Clip::ApplyKeyframes (Transform: Composite Image Layer: Prepare)", "frame->number", frame->number, "background_canvas->width()", background_canvas->width(), "background_canvas->height()", background_canvas->height()); + ZmqLogger::Instance()->AppendDebugMethod( + "Clip::ApplyKeyframes (Transform: Composite Image Layer: Prepare)", + "frame->number", frame->number, + "background_canvas->width()", background_canvas->width(), + "background_canvas->height()", background_canvas->height()); // Load timeline's new frame image into a QPainter QPainter painter(background_canvas.get()); @@ -1333,7 +1347,10 @@ QTransform Clip::get_transform(std::shared_ptr frame, int width, int heig } // Debug output - ZmqLogger::Instance()->AppendDebugMethod("Clip::get_transform (Set Alpha & Opacity)", "alpha_value", alpha_value, "frame->number", frame->number); + ZmqLogger::Instance()->AppendDebugMethod( + "Clip::get_transform (Set Alpha & Opacity)", + "alpha_value", alpha_value, + "frame->number", frame->number); } /* RESIZE SOURCE IMAGE - based on scale type */ @@ -1350,29 +1367,45 @@ QTransform Clip::get_transform(std::shared_ptr frame, int width, int heig source_size.scale(width, height, Qt::KeepAspectRatio); // Debug output - ZmqLogger::Instance()->AppendDebugMethod("Clip::get_transform (Scale: SCALE_FIT)", "frame->number", frame->number, "source_width", source_size.width(), "source_height", source_size.height()); + ZmqLogger::Instance()->AppendDebugMethod( + "Clip::get_transform (Scale: SCALE_FIT)", + "frame->number", frame->number, + "source_width", source_size.width(), + "source_height", source_size.height()); break; } case (SCALE_STRETCH): { source_size.scale(width, height, Qt::IgnoreAspectRatio); // Debug output - ZmqLogger::Instance()->AppendDebugMethod("Clip::get_transform (Scale: SCALE_STRETCH)", "frame->number", frame->number, "source_width", source_size.width(), "source_height", source_size.height()); + ZmqLogger::Instance()->AppendDebugMethod( + "Clip::get_transform (Scale: SCALE_STRETCH)", + "frame->number", frame->number, + "source_width", source_size.width(), + "source_height", source_size.height()); break; } case (SCALE_CROP): { source_size.scale(width, height, Qt::KeepAspectRatioByExpanding); // Debug output - ZmqLogger::Instance()->AppendDebugMethod("Clip::get_transform (Scale: SCALE_CROP)", "frame->number", frame->number, "source_width", source_size.width(), "source_height", source_size.height()); + ZmqLogger::Instance()->AppendDebugMethod( + "Clip::get_transform (Scale: SCALE_CROP)", + "frame->number", frame->number, + "source_width", source_size.width(), + "source_height", source_size.height()); break; } case (SCALE_NONE): { - // Image is already the original size (i.e. no scaling mode) relative - // to the preview window size (i.e. timeline / preview ratio). No further - // scaling is needed here. + // Image is already the original size (i.e. no scaling mode) relative + // to the preview window size (i.e. timeline / preview ratio). No further + // scaling is needed here. // Debug output - ZmqLogger::Instance()->AppendDebugMethod("Clip::get_transform (Scale: SCALE_NONE)", "frame->number", frame->number, "source_width", source_size.width(), "source_height", source_size.height()); + ZmqLogger::Instance()->AppendDebugMethod( + "Clip::get_transform (Scale: SCALE_NONE)", + "frame->number", frame->number, + "source_width", source_size.width(), + "source_height", source_size.height()); break; } } @@ -1498,7 +1531,12 @@ QTransform Clip::get_transform(std::shared_ptr frame, int width, int heig } // Debug output - ZmqLogger::Instance()->AppendDebugMethod("Clip::get_transform (Gravity)", "frame->number", frame->number, "source_clip->gravity", gravity, "scaled_source_width", scaled_source_width, "scaled_source_height", scaled_source_height); + ZmqLogger::Instance()->AppendDebugMethod( + "Clip::get_transform (Gravity)", + "frame->number", frame->number, + "source_clip->gravity", gravity, + "scaled_source_width", scaled_source_width, + "scaled_source_height", scaled_source_height); QTransform transform; @@ -1512,7 +1550,12 @@ QTransform Clip::get_transform(std::shared_ptr frame, int width, int heig float origin_y_value = origin_y.GetValue(frame->number); // Transform source image (if needed) - ZmqLogger::Instance()->AppendDebugMethod("Clip::get_transform (Build QTransform - if needed)", "frame->number", frame->number, "x", x, "y", y, "r", r, "sx", sx, "sy", sy); + ZmqLogger::Instance()->AppendDebugMethod( + "Clip::get_transform (Build QTransform - if needed)", + "frame->number", frame->number, + "x", x, "y", y, + "r", r, + "sx", sx, "sy", sy); if (!isEqual(x, 0) || !isEqual(y, 0)) { // TRANSLATE/MOVE CLIP diff --git a/src/Timeline.cpp b/src/Timeline.cpp index 0de6045f..2d651c0b 100644 --- a/src/Timeline.cpp +++ b/src/Timeline.cpp @@ -521,7 +521,11 @@ double Timeline::calculate_time(int64_t number, Fraction rate) std::shared_ptr Timeline::apply_effects(std::shared_ptr frame, int64_t timeline_frame_number, int layer) { // Debug output - ZmqLogger::Instance()->AppendDebugMethod("Timeline::apply_effects", "frame->number", frame->number, "timeline_frame_number", timeline_frame_number, "layer", layer); + ZmqLogger::Instance()->AppendDebugMethod( + "Timeline::apply_effects", + "frame->number", frame->number, + "timeline_frame_number", timeline_frame_number, + "layer", layer); // Find Effects at this position and layer for (auto effect : effects) @@ -533,7 +537,12 @@ std::shared_ptr Timeline::apply_effects(std::shared_ptr frame, int bool does_effect_intersect = (effect_start_position <= timeline_frame_number && effect_end_position >= timeline_frame_number && effect->Layer() == layer); // Debug output - ZmqLogger::Instance()->AppendDebugMethod("Timeline::apply_effects (Does effect intersect)", "effect->Position()", effect->Position(), "does_effect_intersect", does_effect_intersect, "timeline_frame_number", timeline_frame_number, "layer", layer); + ZmqLogger::Instance()->AppendDebugMethod( + "Timeline::apply_effects (Does effect intersect)", + "effect->Position()", effect->Position(), + "does_effect_intersect", does_effect_intersect, + "timeline_frame_number", timeline_frame_number, + "layer", layer); // Clip is visible if (does_effect_intersect) @@ -543,7 +552,10 @@ std::shared_ptr Timeline::apply_effects(std::shared_ptr frame, int long effect_frame_number = timeline_frame_number - effect_start_position + effect_start_frame; // Debug output - ZmqLogger::Instance()->AppendDebugMethod("Timeline::apply_effects (Process Effect)", "effect_frame_number", effect_frame_number, "does_effect_intersect", does_effect_intersect); + ZmqLogger::Instance()->AppendDebugMethod( + "Timeline::apply_effects (Process Effect)", + "effect_frame_number", effect_frame_number, + "does_effect_intersect", does_effect_intersect); // Apply the effect to this frame frame = effect->GetFrame(frame, effect_frame_number); @@ -565,7 +577,10 @@ std::shared_ptr Timeline::GetOrCreateFrame(std::shared_ptr backgro try { // Debug output - ZmqLogger::Instance()->AppendDebugMethod("Timeline::GetOrCreateFrame (from reader)", "number", number, "samples_in_frame", samples_in_frame); + ZmqLogger::Instance()->AppendDebugMethod( + "Timeline::GetOrCreateFrame (from reader)", + "number", number, + "samples_in_frame", samples_in_frame); // Attempt to get a frame (but this could fail if a reader has just been closed) new_frame = std::shared_ptr(clip->GetFrame(background_frame, number, options)); @@ -580,7 +595,10 @@ std::shared_ptr Timeline::GetOrCreateFrame(std::shared_ptr backgro } // Debug output - ZmqLogger::Instance()->AppendDebugMethod("Timeline::GetOrCreateFrame (create blank)", "number", number, "samples_in_frame", samples_in_frame); + ZmqLogger::Instance()->AppendDebugMethod( + "Timeline::GetOrCreateFrame (create blank)", + "number", number, + "samples_in_frame", samples_in_frame); // Create blank frame return new_frame; @@ -603,12 +621,20 @@ void Timeline::add_layer(std::shared_ptr new_frame, Clip* source_clip, in return; // Debug output - ZmqLogger::Instance()->AppendDebugMethod("Timeline::add_layer", "new_frame->number", new_frame->number, "clip_frame_number", clip_frame_number); + ZmqLogger::Instance()->AppendDebugMethod( + "Timeline::add_layer", + "new_frame->number", new_frame->number, + "clip_frame_number", clip_frame_number); /* COPY AUDIO - with correct volume */ if (source_clip->Reader()->info.has_audio) { // Debug output - ZmqLogger::Instance()->AppendDebugMethod("Timeline::add_layer (Copy Audio)", "source_clip->Reader()->info.has_audio", source_clip->Reader()->info.has_audio, "source_frame->GetAudioChannelsCount()", source_frame->GetAudioChannelsCount(), "info.channels", info.channels, "clip_frame_number", clip_frame_number); + ZmqLogger::Instance()->AppendDebugMethod( + "Timeline::add_layer (Copy Audio)", + "source_clip->Reader()->info.has_audio", source_clip->Reader()->info.has_audio, + "source_frame->GetAudioChannelsCount()", source_frame->GetAudioChannelsCount(), + "info.channels", info.channels, + "clip_frame_number", clip_frame_number); if (source_frame->GetAudioChannelsCount() == info.channels && source_clip->has_audio.GetInt(clip_frame_number) != 0) for (int channel = 0; channel < source_frame->GetAudioChannelsCount(); channel++) @@ -661,17 +687,32 @@ void Timeline::add_layer(std::shared_ptr new_frame, Clip* source_clip, in } else // Debug output - ZmqLogger::Instance()->AppendDebugMethod("Timeline::add_layer (No Audio Copied - Wrong # of Channels)", "source_clip->Reader()->info.has_audio", source_clip->Reader()->info.has_audio, "source_frame->GetAudioChannelsCount()", source_frame->GetAudioChannelsCount(), "info.channels", info.channels, "clip_frame_number", clip_frame_number); + ZmqLogger::Instance()->AppendDebugMethod( + "Timeline::add_layer (No Audio Copied - Wrong # of Channels)", + "source_clip->Reader()->info.has_audio", + source_clip->Reader()->info.has_audio, + "source_frame->GetAudioChannelsCount()", + source_frame->GetAudioChannelsCount(), + "info.channels", info.channels, + "clip_frame_number", clip_frame_number); } // Debug output - ZmqLogger::Instance()->AppendDebugMethod("Timeline::add_layer (Transform: Composite Image Layer: Completed)", "source_frame->number", source_frame->number, "new_frame->GetImage()->width()", new_frame->GetImage()->width(), "new_frame->GetImage()->height()", new_frame->GetImage()->height()); + ZmqLogger::Instance()->AppendDebugMethod( + "Timeline::add_layer (Transform: Composite Image Layer: Completed)", + "source_frame->number", source_frame->number, + "new_frame->GetImage()->width()", new_frame->GetImage()->width(), + "new_frame->GetImage()->height()", new_frame->GetImage()->height()); } // Update the list of 'opened' clips void Timeline::update_open_clips(Clip *clip, bool does_clip_intersect) { - ZmqLogger::Instance()->AppendDebugMethod("Timeline::update_open_clips (before)", "does_clip_intersect", does_clip_intersect, "closing_clips.size()", closing_clips.size(), "open_clips.size()", open_clips.size()); + ZmqLogger::Instance()->AppendDebugMethod( + "Timeline::update_open_clips (before)", + "does_clip_intersect", does_clip_intersect, + "closing_clips.size()", closing_clips.size(), + "open_clips.size()", open_clips.size()); // is clip already in list? bool clip_found = open_clips.count(clip); @@ -699,14 +740,21 @@ void Timeline::update_open_clips(Clip *clip, bool does_clip_intersect) } // Debug output - ZmqLogger::Instance()->AppendDebugMethod("Timeline::update_open_clips (after)", "does_clip_intersect", does_clip_intersect, "clip_found", clip_found, "closing_clips.size()", closing_clips.size(), "open_clips.size()", open_clips.size()); + ZmqLogger::Instance()->AppendDebugMethod( + "Timeline::update_open_clips (after)", + "does_clip_intersect", does_clip_intersect, + "clip_found", clip_found, + "closing_clips.size()", closing_clips.size(), + "open_clips.size()", open_clips.size()); } // Sort clips by position on the timeline void Timeline::sort_clips() { // Debug output - ZmqLogger::Instance()->AppendDebugMethod("Timeline::SortClips", "clips.size()", clips.size()); + ZmqLogger::Instance()->AppendDebugMethod( + "Timeline::SortClips", + "clips.size()", clips.size()); // sort clips clips.sort(CompareClips()); @@ -765,49 +813,56 @@ std::shared_ptr Timeline::GetFrame(int64_t requested_frame) frame = final_cache->GetFrame(requested_frame); if (frame) { // Debug output - ZmqLogger::Instance()->AppendDebugMethod("Timeline::GetFrame (Cached frame found)", "requested_frame", requested_frame); + ZmqLogger::Instance()->AppendDebugMethod( + "Timeline::GetFrame (Cached frame found)", + "requested_frame", requested_frame); // Return cached frame return frame; } else { - // Create a scoped lock, allowing only a single thread to run the following code at one time - const std::lock_guard lock(getFrameMutex); + // Create a scoped lock, allowing only a single thread to run the following code at one time + const std::lock_guard lock(getFrameMutex); - // Check for open reader (or throw exception) - if (!is_open) - throw ReaderClosed("The Timeline is closed. Call Open() before calling this method."); + // Check for open reader (or throw exception) + if (!is_open) + throw ReaderClosed("The Timeline is closed. Call Open() before calling this method."); - // Check cache again (due to locking) - frame = final_cache->GetFrame(requested_frame); - if (frame) { - // Debug output - ZmqLogger::Instance()->AppendDebugMethod("Timeline::GetFrame (Cached frame found on 2nd look)", "requested_frame", requested_frame); + // Check cache again (due to locking) + frame = final_cache->GetFrame(requested_frame); + if (frame) { + // Debug output + ZmqLogger::Instance()->AppendDebugMethod( + "Timeline::GetFrame (Cached frame found on 2nd look)", + "requested_frame", requested_frame); - // Return cached frame - return frame; - } + // Return cached frame + return frame; + } - // Check if previous frame was cached? (if not, assume we are seeking somewhere else on the Timeline, and need - // to clear all cache (for continuity sake). For example, jumping back to a previous spot can cause issues with audio - // data where the new jump location doesn't match up with the previously cached audio data. - std::shared_ptr previous_frame = final_cache->GetFrame(requested_frame - 1); - if (!previous_frame) { - // Seeking to new place on timeline (destroy cache) - ClearAllCache(); - } + // Check if previous frame was cached? (if not, assume we are seeking somewhere else on the Timeline, and need + // to clear all cache (for continuity sake). For example, jumping back to a previous spot can cause issues with audio + // data where the new jump location doesn't match up with the previously cached audio data. + std::shared_ptr previous_frame = final_cache->GetFrame(requested_frame - 1); + if (!previous_frame) { + // Seeking to new place on timeline (destroy cache) + ClearAllCache(); + } - // Minimum number of frames to process (for performance reasons) - int minimum_frames = OPEN_MP_NUM_PROCESSORS; + // Minimum number of frames to process (for performance reasons) + int minimum_frames = OPEN_MP_NUM_PROCESSORS; - // Get a list of clips that intersect with the requested section of timeline - // This also opens the readers for intersecting clips, and marks non-intersecting clips as 'needs closing' - std::vector nearby_clips; - nearby_clips = find_intersecting_clips(requested_frame, 1, true); + // Get a list of clips that intersect with the requested section of timeline + // This also opens the readers for intersecting clips, and marks non-intersecting clips as 'needs closing' + std::vector nearby_clips; + nearby_clips = find_intersecting_clips(requested_frame, 1, true); // Debug output - ZmqLogger::Instance()->AppendDebugMethod("Timeline::GetFrame (processing frame)", "requested_frame", requested_frame, "omp_get_thread_num()", omp_get_thread_num()); + ZmqLogger::Instance()->AppendDebugMethod( + "Timeline::GetFrame (processing frame)", + "requested_frame", requested_frame, + "omp_get_thread_num()", omp_get_thread_num()); // Init some basic properties about this frame int samples_in_frame = Frame::GetSamplesPerFrame(requested_frame, info.fps, info.sample_rate, info.channels); @@ -819,7 +874,11 @@ std::shared_ptr Timeline::GetFrame(int64_t requested_frame) new_frame->ChannelsLayout(info.channel_layout); // Debug output - ZmqLogger::Instance()->AppendDebugMethod("Timeline::GetFrame (Adding solid color)", "requested_frame", requested_frame, "info.width", info.width, "info.height", info.height); + ZmqLogger::Instance()->AppendDebugMethod( + "Timeline::GetFrame (Adding solid color)", + "requested_frame", requested_frame, + "info.width", info.width, + "info.height", info.height); // Add Background Color to 1st layer (if animated or not black) if ((color.red.GetCount() > 1 || color.green.GetCount() > 1 || color.blue.GetCount() > 1) || @@ -827,7 +886,11 @@ std::shared_ptr Timeline::GetFrame(int64_t requested_frame) new_frame->AddColor(preview_width, preview_height, color.GetColorHex(requested_frame)); // Debug output - ZmqLogger::Instance()->AppendDebugMethod("Timeline::GetFrame (Loop through clips)", "requested_frame", requested_frame, "clips.size()", clips.size(), "nearby_clips.size()", nearby_clips.size()); + ZmqLogger::Instance()->AppendDebugMethod( + "Timeline::GetFrame (Loop through clips)", + "requested_frame", requested_frame, + "clips.size()", clips.size(), + "nearby_clips.size()", nearby_clips.size()); // Find Clips near this time for (auto clip : nearby_clips) @@ -838,7 +901,12 @@ std::shared_ptr Timeline::GetFrame(int64_t requested_frame) bool does_clip_intersect = (clip_start_position <= requested_frame && clip_end_position >= requested_frame); // Debug output - ZmqLogger::Instance()->AppendDebugMethod("Timeline::GetFrame (Does clip intersect)", "requested_frame", requested_frame, "clip->Position()", clip->Position(), "clip->Duration()", clip->Duration(), "does_clip_intersect", does_clip_intersect); + ZmqLogger::Instance()->AppendDebugMethod( + "Timeline::GetFrame (Does clip intersect)", + "requested_frame", requested_frame, + "clip->Position()", clip->Position(), + "clip->Duration()", clip->Duration(), + "does_clip_intersect", does_clip_intersect); // Clip is visible if (does_clip_intersect) @@ -873,22 +941,32 @@ std::shared_ptr Timeline::GetFrame(int64_t requested_frame) long clip_frame_number = requested_frame - clip_start_position + clip_start_frame; // Debug output - ZmqLogger::Instance()->AppendDebugMethod("Timeline::GetFrame (Calculate clip's frame #)", "clip->Position()", clip->Position(), "clip->Start()", clip->Start(), "info.fps.ToFloat()", info.fps.ToFloat(), "clip_frame_number", clip_frame_number); + ZmqLogger::Instance()->AppendDebugMethod( + "Timeline::GetFrame (Calculate clip's frame #)", + "clip->Position()", clip->Position(), + "clip->Start()", clip->Start(), + "info.fps.ToFloat()", info.fps.ToFloat(), + "clip_frame_number", clip_frame_number); // Add clip's frame as layer add_layer(new_frame, clip, clip_frame_number, is_top_clip, max_volume); } else { // Debug output - ZmqLogger::Instance()->AppendDebugMethod("Timeline::GetFrame (clip does not intersect)", - "requested_frame", requested_frame, "does_clip_intersect", - does_clip_intersect); + ZmqLogger::Instance()->AppendDebugMethod( + "Timeline::GetFrame (clip does not intersect)", + "requested_frame", requested_frame, + "does_clip_intersect", does_clip_intersect); } } // end clip loop // Debug output - ZmqLogger::Instance()->AppendDebugMethod("Timeline::GetFrame (Add frame to cache)", "requested_frame", requested_frame, "info.width", info.width, "info.height", info.height); + ZmqLogger::Instance()->AppendDebugMethod( + "Timeline::GetFrame (Add frame to cache)", + "requested_frame", requested_frame, + "info.width", info.width, + "info.height", info.height); // Set frame # on mapped frame new_frame->SetFrameNumber(requested_frame); @@ -927,7 +1005,13 @@ std::vector Timeline::find_intersecting_clips(int64_t requested_frame, in (clip_end_position >= min_requested_frame || clip_end_position >= max_requested_frame); // Debug output - ZmqLogger::Instance()->AppendDebugMethod("Timeline::find_intersecting_clips (Is clip near or intersecting)", "requested_frame", requested_frame, "min_requested_frame", min_requested_frame, "max_requested_frame", max_requested_frame, "clip->Position()", clip->Position(), "does_clip_intersect", does_clip_intersect); + ZmqLogger::Instance()->AppendDebugMethod( + "Timeline::find_intersecting_clips (Is clip near or intersecting)", + "requested_frame", requested_frame, + "min_requested_frame", min_requested_frame, + "max_requested_frame", max_requested_frame, + "clip->Position()", clip->Position(), + "does_clip_intersect", does_clip_intersect); // Open (or schedule for closing) this clip, based on if it's intersecting or not update_open_clips(clip, does_clip_intersect); From 549149d6573cfcce2a4ccfae9221e18dd99aae4c Mon Sep 17 00:00:00 2001 From: "FeRD (Frank Dana)" Date: Wed, 12 Jan 2022 10:52:44 -0500 Subject: [PATCH 3/7] src/Qt/*: Reformat logging calls, fix indents --- src/Qt/PlayerPrivate.cpp | 9 ++++- src/Qt/VideoCacheThread.cpp | 60 ++++++++++++++++++---------------- src/Qt/VideoPlaybackThread.cpp | 5 ++- 3 files changed, 43 insertions(+), 31 deletions(-) diff --git a/src/Qt/PlayerPrivate.cpp b/src/Qt/PlayerPrivate.cpp index 2cd8c6db..932508f2 100644 --- a/src/Qt/PlayerPrivate.cpp +++ b/src/Qt/PlayerPrivate.cpp @@ -107,7 +107,14 @@ namespace openshot auto sleep_time = duration_cast(frame_duration - render_time); // Debug - ZmqLogger::Instance()->AppendDebugMethod("PlayerPrivate::run (determine sleep)", "video_frame_diff", video_frame_diff, "video_position", video_position, "audio_position", audio_position, "speed", speed, "render_time(ms)", render_time.count(), "sleep_time(ms)", sleep_time.count()); + ZmqLogger::Instance()->AppendDebugMethod( + "PlayerPrivate::run (determine sleep)", + "video_frame_diff", video_frame_diff, + "video_position", video_position, + "audio_position", audio_position, + "speed", speed, + "render_time(ms)", render_time.count(), + "sleep_time(ms)", sleep_time.count()); // Adjust drift (if more than a few frames off between audio and video) if (video_frame_diff > 6 && reader->info.has_audio && reader->info.has_video) { diff --git a/src/Qt/VideoCacheThread.cpp b/src/Qt/VideoCacheThread.cpp index 60d94d1d..b798e84c 100644 --- a/src/Qt/VideoCacheThread.cpp +++ b/src/Qt/VideoCacheThread.cpp @@ -77,46 +77,48 @@ namespace openshot using ms = std::chrono::milliseconds; using double_ms = std::chrono::duration; - while (!threadShouldExit() && is_playing) { + while (!threadShouldExit() && is_playing) { // Calculate on-screen time for a single frame in milliseconds const auto frame_duration = double_ms(1000.0 / reader->info.fps.ToDouble()); - // Cache frames before the other threads need them - // Cache frames up to the max frames. Reset to current position - // if cache gets too far away from display frame. Cache frames - // even when player is paused (i.e. speed 0). - while (((position - current_display_frame) < max_concurrent_frames) && is_playing) - { - // Only cache up till the max_concurrent_frames amount... then sleep - try - { - if (reader) { - ZmqLogger::Instance()->AppendDebugMethod("VideoCacheThread::run (cache frame)", "position", position, "current_display_frame", current_display_frame, "max_concurrent_frames", max_concurrent_frames, "needed_frames", (position - current_display_frame)); + // Cache frames before the other threads need them + // Cache frames up to the max frames. Reset to current position + // if cache gets too far away from display frame. Cache frames + // even when player is paused (i.e. speed 0). + while (((position - current_display_frame) < max_concurrent_frames) && is_playing) + { + // Only cache up till the max_concurrent_frames amount... then sleep + try + { + if (reader) { + ZmqLogger::Instance()->AppendDebugMethod( + "VideoCacheThread::run (cache frame)", + "position", position, + "current_display_frame", current_display_frame, + "max_concurrent_frames", max_concurrent_frames, + "needed_frames", (position - current_display_frame)); - // Force the frame to be generated + // Force the frame to be generated smallest_frame = reader->GetCache()->GetSmallestFrame(); if (smallest_frame && smallest_frame->number > current_display_frame) { // Cache position has gotten too far away from current display frame. // Reset the position to the current display frame. position = current_display_frame; - } - reader->GetFrame(position); - } + } + reader->GetFrame(position); + } + } + // Ignore out of bounds frame exceptions + catch (const OutOfBoundsFrame & e) { } - } - catch (const OutOfBoundsFrame & e) - { - // Ignore out of bounds frame exceptions - } + // Increment frame number + position++; + } - // Increment frame number - position++; - } + // Sleep for 1 frame length + std::this_thread::sleep_for(frame_duration); + } - // Sleep for 1 frame length - std::this_thread::sleep_for(frame_duration); - } - - return; + return; } } diff --git a/src/Qt/VideoPlaybackThread.cpp b/src/Qt/VideoPlaybackThread.cpp index f8df00cc..b8c53e58 100644 --- a/src/Qt/VideoPlaybackThread.cpp +++ b/src/Qt/VideoPlaybackThread.cpp @@ -51,7 +51,10 @@ namespace openshot if (need_render && frame) { // Debug - ZmqLogger::Instance()->AppendDebugMethod("VideoPlaybackThread::run (before render)", "frame->number", frame->number, "need_render", need_render); + ZmqLogger::Instance()->AppendDebugMethod( + "VideoPlaybackThread::run (before render)", + "frame->number", frame->number, + "need_render", need_render); // Render the frame to the screen renderer->paint(frame); From 8344e5c7a1b0da580c4073620ec2afdde50b5678 Mon Sep 17 00:00:00 2001 From: "FeRD (Frank Dana)" Date: Wed, 12 Jan 2022 10:53:58 -0500 Subject: [PATCH 4/7] FrameMapper: Reformat logging calls --- src/FrameMapper.cpp | 28 +++++++++++++++++++++++----- 1 file changed, 23 insertions(+), 5 deletions(-) diff --git a/src/FrameMapper.cpp b/src/FrameMapper.cpp index c405bf26..e9fc51e4 100644 --- a/src/FrameMapper.cpp +++ b/src/FrameMapper.cpp @@ -342,7 +342,12 @@ MappedFrame FrameMapper::GetMappedFrame(int64_t TargetFrameNumber) TargetFrameNumber = frames.size(); // Debug output - ZmqLogger::Instance()->AppendDebugMethod("FrameMapper::GetMappedFrame", "TargetFrameNumber", TargetFrameNumber, "frames.size()", frames.size(), "frames[...].Odd", frames[TargetFrameNumber - 1].Odd.Frame, "frames[...].Even", frames[TargetFrameNumber - 1].Even.Frame); + ZmqLogger::Instance()->AppendDebugMethod( + "FrameMapper::GetMappedFrame", + "TargetFrameNumber", TargetFrameNumber, + "frames.size()", frames.size(), + "frames[...].Odd", frames[TargetFrameNumber - 1].Odd.Frame, + "frames[...].Even", frames[TargetFrameNumber - 1].Even.Frame); // Return frame return frames[TargetFrameNumber - 1]; @@ -358,7 +363,10 @@ std::shared_ptr FrameMapper::GetOrCreateFrame(int64_t number) try { // Debug output - ZmqLogger::Instance()->AppendDebugMethod("FrameMapper::GetOrCreateFrame (from reader)", "number", number, "samples_in_frame", samples_in_frame); + ZmqLogger::Instance()->AppendDebugMethod( + "FrameMapper::GetOrCreateFrame (from reader)", + "number", number, + "samples_in_frame", samples_in_frame); // Attempt to get a frame (but this could fail if a reader has just been closed) new_frame = reader->GetFrame(number); @@ -373,7 +381,10 @@ std::shared_ptr FrameMapper::GetOrCreateFrame(int64_t number) } // Debug output - ZmqLogger::Instance()->AppendDebugMethod("FrameMapper::GetOrCreateFrame (create blank)", "number", number, "samples_in_frame", samples_in_frame); + ZmqLogger::Instance()->AppendDebugMethod( + "FrameMapper::GetOrCreateFrame (create blank)", + "number", number, + "samples_in_frame", samples_in_frame); // Create blank frame new_frame = std::make_shared(number, info.width, info.height, "#000000", samples_in_frame, reader->info.channels); @@ -418,14 +429,21 @@ std::shared_ptr FrameMapper::GetFrame(int64_t requested_frame) int minimum_frames = 1; // Debug output - ZmqLogger::Instance()->AppendDebugMethod("FrameMapper::GetFrame (Loop through frames)", "requested_frame", requested_frame, "minimum_frames", minimum_frames); + ZmqLogger::Instance()->AppendDebugMethod( + "FrameMapper::GetFrame (Loop through frames)", + "requested_frame", requested_frame, + "minimum_frames", minimum_frames); // Loop through all requested frames for (int64_t frame_number = requested_frame; frame_number < requested_frame + minimum_frames; frame_number++) { // Debug output - ZmqLogger::Instance()->AppendDebugMethod("FrameMapper::GetFrame (inside omp for loop)", "frame_number", frame_number, "minimum_frames", minimum_frames, "requested_frame", requested_frame); + ZmqLogger::Instance()->AppendDebugMethod( + "FrameMapper::GetFrame (inside omp for loop)", + "frame_number", frame_number, + "minimum_frames", minimum_frames, + "requested_frame", requested_frame); // Get the mapped frame MappedFrame mapped = GetMappedFrame(frame_number); From 03262ab9c6c4bd33d565c328b9fce98e92283d30 Mon Sep 17 00:00:00 2001 From: Frank Dana Date: Tue, 18 Jan 2022 07:57:21 -0500 Subject: [PATCH 5/7] CI: Use windows-2022, clean-slate MSYS2 image (#799) Turns out that when setting up to build on Windows, it's almost 35% faster (#WhoKnew?) if we start from a clean slate and directly install all 204 packages that make up our build environment. (That's the total count after dependency resolution.) Using the preinstalled MSYS2 image, we have to update all of those packages _first_ (a slow process), before we can even start our own installs. --- .github/workflows/ci.yml | 7 +++---- 1 file changed, 3 insertions(+), 4 deletions(-) diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index aa1d7a0a..57b9e83d 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -14,7 +14,7 @@ jobs: - { os: ubuntu-18.04, shell: bash } - { os: ubuntu-latest, shell: bash } - { os: macos-latest, shell: bash } - - { os: windows-latest, shell: 'msys2 {0}' } + - { os: windows-2022, shell: 'msys2 {0}' } compiler: - { cc: gcc, cxx: g++ } - { cc: clang, cxx: clang++ } @@ -22,7 +22,7 @@ jobs: # Windows clang isn't being our friend, # JUCE seems to think it can use _get_tzname there # (it can't) - - sys: { os: windows-latest, shell: 'msys2 {0}' } + - sys: { os: windows-2022, shell: 'msys2 {0}' } compiler: { cc: clang, cxx: clang++ } defaults: run: @@ -102,11 +102,10 @@ jobs: if: ${{ runner.os == 'Windows' }} uses: msys2/setup-msys2@v2 with: - release: false + release: true update: true install: >- mingw-w64-x86_64-gcc - mingw-w64-x86_64-clang mingw-w64-x86_64-lld mingw-w64-x86_64-make mingw-w64-x86_64-cmake From 8633b3aba62a56f803a289d60e69f7f4dd7de564 Mon Sep 17 00:00:00 2001 From: Frank Dana Date: Tue, 18 Jan 2022 16:18:10 -0500 Subject: [PATCH 6/7] Win CI: Prune Qt5 package set (#800) --- .github/workflows/ci.yml | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 57b9e83d..041cc952 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -110,7 +110,10 @@ jobs: mingw-w64-x86_64-make mingw-w64-x86_64-cmake mingw-w64-x86_64-pkgconf - mingw-w64-x86_64-qt5 + mingw-w64-x86_64-qt5-base + mingw-w64-x86_64-qt5-svg + mingw-w64-x86_64-qt5-winextras + mingw-w64-x86_64-qt5-tools mingw-w64-x86_64-libvpx mingw-w64-x86_64-ffmpeg mingw-w64-x86_64-zeromq From a86097a3906ba7f88ae2b3cb8ddbd58fc92adcec Mon Sep 17 00:00:00 2001 From: Frank Dana Date: Tue, 25 Jan 2022 19:59:42 -0500 Subject: [PATCH 7/7] Make coverage work on macOS, enable in CI (#804) --- .github/workflows/ci.yml | 4 ++-- CMakeLists.txt | 16 +++++++++------- 2 files changed, 11 insertions(+), 9 deletions(-) diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 041cc952..35feed81 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -63,7 +63,7 @@ jobs: - uses: haya14busa/action-cond@v1 id: coverage with: - cond: ${{ matrix.compiler.cc == 'gcc' && runner.os == 'linux' }} + cond: ${{ (matrix.compiler.cc == 'gcc' && runner.os == 'linux') || (matrix.compiler.cc == 'clang' && runner.os == 'macos') }} if_true: "-DENABLE_COVERAGE:BOOL=1" - uses: haya14busa/action-cond@v1 @@ -96,7 +96,7 @@ jobs: run: | brew install \ qt5 ffmpeg zeromq cppzmq libomp opencv protobuf babl \ - python3 swig catch2 doxygen graphviz + python3 swig catch2 doxygen graphviz lcov - name: Set up MSYS and install Windows dependencies if: ${{ runner.os == 'Windows' }} diff --git a/CMakeLists.txt b/CMakeLists.txt index 3ca3b0a1..416718f1 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -106,9 +106,9 @@ IF (WIN32) ENDIF(WIN32) ############## Code Coverage ######################### -if (ENABLE_COVERAGE AND NOT ENABLE_TESTS) - message(WARNING "ENABLE_COVERAGE requires unit tests, forcing ENABLE_TESTS") - set(ENABLE_TESTS ON CACHE BOOL "Build unit tests (requires Catch2 or UnitTest++)" FORCE) +if (ENABLE_COVERAGE AND NOT BUILD_TESTING) + message(WARNING "ENABLE_COVERAGE requires unit tests, forcing BUILD_TESTING") + set(BUILD_TESTING ON CACHE BOOL "Build unit tests (requires Catch2 or UnitTest++)" FORCE) endif() if (ENABLE_COVERAGE) @@ -247,11 +247,13 @@ add_feature_info("Unit tests" ${BUILD_TESTING} "Compile unit tests for library f ############## COVERAGE REPORTING ################# if (ENABLE_COVERAGE AND DEFINED UNIT_TEST_TARGETS) set(COVERAGE_EXCLUDES - "bindings/*" + "**/*_wrap.cxx" "examples/*" - "${CMAKE_CURRENT_BINARY_DIR}/bindings/*" - "${CMAKE_CURRENT_BINARY_DIR}/src/*_autogen/*" - "${CMAKE_CURRENT_BINARY_DIR}/src/protobuf_messages/*" + "**/moc_*.cpp" + "*.pb.cc" + "*.pb.h" + "src/*.pb.cc" + "src/*.pb.h" "audio/*" ) setup_target_for_coverage_lcov(