]> git.sesse.net Git - nageru/blobdiff - nageru/decklink_output.cpp
WIP patch for async output.
[nageru] / nageru / decklink_output.cpp
index da172af686acbc3ff7acf489a7befd01a2efb2f7..f061766bf256f4fbf08ae7a09e83e87bce5cf15a 100644 (file)
@@ -126,7 +126,7 @@ bool DeckLinkOutput::set_device(IDeckLink *decklink)
        return true;
 }
 
-void DeckLinkOutput::start_output(uint32_t mode, int64_t base_pts)
+void DeckLinkOutput::start_output(uint32_t mode, int64_t base_pts, bool is_master_card)
 {
        assert(output);
        assert(!playback_initiated);
@@ -139,7 +139,11 @@ void DeckLinkOutput::start_output(uint32_t mode, int64_t base_pts)
        should_quit.unquit();
        playback_initiated = true;
        playback_started = false;
-       this->base_pts = base_pts;
+       if (is_master_card) {
+               this->base_pts = base_pts;
+       } else {
+               this->next_output_pts = 0;
+       }
 
        IDeckLinkConfiguration *config = nullptr;
        if (output->QueryInterface(IID_IDeckLinkConfiguration, (void**)&config) != S_OK) {
@@ -219,9 +223,17 @@ void DeckLinkOutput::start_output(uint32_t mode, int64_t base_pts)
                fprintf(stderr, "Couldn't enable audio output\n");
                abort();
        }
-       if (output->BeginAudioPreroll() != S_OK) {
-               fprintf(stderr, "Couldn't begin audio preroll\n");
-               abort();
+       if (is_master_card) {
+               if (output->BeginAudioPreroll() != S_OK) {
+                       fprintf(stderr, "Couldn't begin audio preroll\n");
+                       abort();
+               }
+       } else {
+               if (output->StartScheduledPlayback(/*base_pts=*/0, TIMEBASE, 1.0) != S_OK) {
+                       fprintf(stderr, "Could not start playback\n");
+                       abort();  // TODO
+               }
+               playback_started = true;
        }
 
        present_thread = thread([this]{
@@ -275,6 +287,8 @@ void DeckLinkOutput::send_frame(GLuint y_tex, GLuint cbcr_tex, YCbCrLumaCoeffici
 {
        assert(!should_quit.should_quit());
 
+       input_jitter_history.frame_arrived(steady_clock::now(), duration, /*dropped_frames=*/0, true);
+
        if ((current_mode_flags & bmdDisplayModeColorspaceRec601) && output_ycbcr_coefficients == YCBCR_REC_709) {
                if (!last_frame_had_mode_mismatch) {
                        fprintf(stderr, "WARNING: Chosen output mode expects Rec. 601 Y'CbCr coefficients.\n");
@@ -346,6 +360,8 @@ void DeckLinkOutput::send_frame(GLuint y_tex, GLuint cbcr_tex, YCbCrLumaCoeffici
 
 void DeckLinkOutput::send_audio(int64_t pts, const std::vector<float> &samples)
 {
+       return;  // FIXME we may need to map pts or something?
+
        unique_ptr<int32_t[]> int_samples(new int32_t[samples.size()]);
        for (size_t i = 0; i < samples.size(); ++i) {
                int_samples[i] = lrintf(samples[i] * 2147483648.0f);
@@ -439,7 +455,7 @@ uint32_t DeckLinkOutput::pick_video_mode(uint32_t mode) const
        }
 
        // Prioritize 59.94 > 60 > 29.97. If none of those are found, then pick the highest one.
-       for (const pair<int, int> &desired : vector<pair<int, int>>{ { 60000, 1001 }, { 60, 1 }, { 30000, 1001 } }) {
+       for (const pair<int, int> &desired : vector<pair<int, int>>{ { 50, 1 }, { 60000, 1001 }, { 60, 1 }, { 30000, 1001 } }) {
                for (const auto &it : video_modes) {
                        if (it.second.frame_rate_num * desired.second == desired.first * it.second.frame_rate_den) {
                                return it.first;
@@ -473,22 +489,70 @@ YCbCrLumaCoefficients DeckLinkOutput::preferred_ycbcr_coefficients() const
 HRESULT DeckLinkOutput::ScheduledFrameCompleted(/* in */ IDeckLinkVideoFrame *completedFrame, /* in */ BMDOutputFrameCompletionResult result)
 {
        Frame *frame = static_cast<Frame *>(completedFrame);
+
+       BMDTimeValue stream_frame_time, played_at_time;
+       BMDTimeValue hardwareTime, timeInFrame, ticksPerFrame;
+       double playback_speed;
+       output->GetFrameCompletionReferenceTimestamp(frame, TIMEBASE, &played_at_time);
+       output->GetScheduledStreamTime(TIMEBASE, &stream_frame_time, &playback_speed);
+       output->GetHardwareReferenceClock(TIMEBASE, &hardwareTime, &timeInFrame, &ticksPerFrame);
+
+       steady_clock::time_point now = steady_clock::now();
+       int frame_delay = (stream_frame_time - frame->pts) / frame_duration - 1;
+       map<int, string> status = {
+               { bmdOutputFrameCompleted, "played" },
+               { bmdOutputFrameDisplayedLate, "DELAYED" },
+               { bmdOutputFrameDropped, "DROPPED" },
+               { bmdOutputFrameFlushed, "FLUSHED" }
+       };
+
+       if ((result == bmdOutputFrameCompleted || result == bmdOutputFrameDisplayedLate) && false) {
+               fprintf(stderr, "now=%ld / %.2f: frame with pts=%ld (%ld ago, %d delay) / %.2f was %s at time %ld (%ld ago)\n",
+                       stream_frame_time, PTSToTime(stream_frame_time),
+                       frame->pts, stream_frame_time - frame->pts, frame_delay, PTSToTime(frame->pts),
+                       status[result].c_str(),
+                       played_at_time, hardwareTime - played_at_time);
+       } else if (result == bmdOutputFrameDisplayedLate) {
+               fprintf(stderr, "now=%ld / %.2f: frame with pts=%ld (%ld ago, %d delay) / %.2f was %s to %.2f\n",
+                       stream_frame_time, PTSToTime(stream_frame_time),
+                       frame->pts, stream_frame_time - frame->pts, frame_delay, PTSToTime(frame->pts),
+                       status[result].c_str(), PTSToTime(frame->pts) + frame_delay);
+       } else {
+               fprintf(stderr, "now=%ld / %.2f: frame with pts=%ld (%ld ago, %d delay) / %.2f was %s\n",
+                       stream_frame_time, PTSToTime(stream_frame_time),
+                       frame->pts, stream_frame_time - frame->pts, frame_delay, PTSToTime(frame->pts),
+                       status[result].c_str());
+       }
+       if (frame_delay < 0) {
+               fprintf(stderr, "ERROR: Frame went backwards in time (scheduled to start at pts=%ld, ended at or before pts=%ld), something is strange.\n",
+                       frame->pts, stream_frame_time);
+               frame_delay = 0;
+       }
+       
        switch (result) {
        case bmdOutputFrameCompleted:
                ++metric_decklink_output_completed_frames_completed;
+               if (frame_delay != 0) {
+                       fprintf(stderr, "ERROR: Frame was reportedly completed without delay, but was delayed nevertheless.\n");
+                       // Our callback _might_ be delayed 1+ frame for other reasons,
+                       // so ignore this. It's a pity GetFrameCompletionReferenceTimestamp()
+                       // cannot give us a timestamp on the same time scale as
+                       // GetScheduledStreamTime(); it would be more robust.
+                       frame_delay = 0;
+               }
                break;
        case bmdOutputFrameDisplayedLate:
-               fprintf(stderr, "Output frame displayed late (pts=%" PRId64 ")\n", frame->pts);
-               fprintf(stderr, "Consider increasing --output-buffer-frames if this persists.\n");
+       //      fprintf(stderr, "Output frame displayed late (pts=%" PRId64 ")\n", frame->pts);
+               //fprintf(stderr, "Consider increasing --output-buffer-frames if this persists.\n");
                ++metric_decklink_output_completed_frames_late;
                break;
        case bmdOutputFrameDropped:
-               fprintf(stderr, "Output frame was dropped (pts=%" PRId64 ")\n", frame->pts);
-               fprintf(stderr, "Consider increasing --output-buffer-frames if this persists.\n");
+       //      fprintf(stderr, "Output frame was dropped (pts=%" PRId64 ")\n", frame->pts);
+               //fprintf(stderr, "Consider increasing --output-buffer-frames if this persists.\n");
                ++metric_decklink_output_completed_frames_dropped;
                break;
        case bmdOutputFrameFlushed:
-               fprintf(stderr, "Output frame was flushed (pts=%" PRId64 ")\n", frame->pts);
+       //      fprintf(stderr, "Output frame was flushed (pts=%" PRId64 ")\n", frame->pts);
                ++metric_decklink_output_completed_frames_flushed;
                break;
        default:
@@ -503,9 +567,55 @@ HRESULT DeckLinkOutput::ScheduledFrameCompleted(/* in */ IDeckLinkVideoFrame *co
        {
                lock_guard<mutex> lock(frame_queue_mutex);
                frame_freelist.push(unique_ptr<Frame>(frame));
-               assert(scheduled_frames.front() == frame);
-               scheduled_frames.pop_front();
+
+               // Dropped frames can come out-of-order, so we can't just look at the front;
+               // we need to go and find it in the list.
+               auto it = find(scheduled_frames.begin(), scheduled_frames.end(), frame);
+               assert(it != scheduled_frames.end());
+               scheduled_frames.erase(it);
                --metric_decklink_output_inflight_frames;
+
+               if (frame_delay > 0 && result == bmdOutputFrameDisplayedLate) {
+                       // All frames that were queued earlier will be delayed,
+                       // so update so that we don't double-count the delay.
+                       int64_t prev_frame_pts = frame->pts + frame_delay * frame_duration;
+                       for (Frame *other_frame : scheduled_frames) {
+                               int64_t old_pts = other_frame->pts;
+                               other_frame->pts = std::max(other_frame->pts, prev_frame_pts + frame_duration);
+                               fprintf(stderr, " - moving frame from pts=%ld (%.3f) to pts=%ld (%.3f)\n",
+                                       old_pts, PTSToTime(old_pts), other_frame->pts, PTSToTime(other_frame->pts));
+                               prev_frame_pts = other_frame->pts;
+                       }
+
+                       int64_t earliest_next_frame = (stream_frame_time + frame_duration - 1) / frame_duration * frame_duration;
+                       earliest_next_frame = std::max(earliest_next_frame, prev_frame_pts + frame_duration);
+                       if (next_output_pts < earliest_next_frame) {
+                               // In effect, duplicate a frame. FIXME write something about this
+                               // FIXME is this really right now? but perhaps we're forced
+                               // and it messes up the queue length calculation temporarily, we need something else there
+                               //fprintf(stderr, "Duplicating frame %d times due to starvation!\n", frame_delay);
+
+                               // FIXME this causes us to believe in output jitter?
+                               fprintf(stderr, " - moving output pointer from pts=%ld (%.3f) to pts=%ld (%.3f)\n",
+                                       next_output_pts, PTSToTime(next_output_pts), earliest_next_frame, PTSToTime(earliest_next_frame));
+                               next_output_pts = earliest_next_frame;
+                               // FIXME metric
+                       }
+               }
+
+               if (result == bmdOutputFrameCompleted || result == bmdOutputFrameDisplayedLate) {
+                       //output_jitter_history.frame_arrived(now, frame_duration, /*dropped_frames=*/frame_delay, true);
+                       // TODO: backdate now, and possibly also get_expected_next_frame()?
+                       queue_length_policy.update_policy(
+                               now,
+                               input_jitter_history.get_expected_next_frame(),
+                               frame->duration, frame_duration,
+                               input_jitter_history.estimate_max_jitter(),
+                       //      output_jitter_history.estimate_max_jitter(), true);
+                               0.0, true);
+                       num_safe_frames = queue_length_policy.get_safe_queue_length();
+               }
+               fprintf(stderr, "%zu frames in flight, safe queue length = %u (starv=%d)\n", scheduled_frames.size(), queue_length_policy.get_safe_queue_length(), frame_delay);
        }
 
        return S_OK;
@@ -574,6 +684,17 @@ void DeckLinkOutput::present_thread_func()
                        }
                        frame = move(pending_video_frames.front());
                        pending_video_frames.pop();
+
+                       if (scheduled_frames.size() > num_safe_frames) {  // FIXME check off-by-one here
+                               fprintf(stderr, "Dropping frame to keep latency down!\n");
+                               // FIXME metric
+                               continue;
+                       }
+
+                       // Overwrite the pts given by the client; it doesn't own our clock.
+                       // TODO: Write something about what semi-unsynchronized really means.
+                       frame->pts = next_output_pts;
+                       next_output_pts += frame_duration;
                }
 
                for ( ;; ) {
@@ -612,6 +733,11 @@ void DeckLinkOutput::present_thread_func()
        }
 }
 
+double DeckLinkOutput::PTSToTime(int64_t pts)
+{
+       return double(pts) / frame_duration;
+}
+
 HRESULT STDMETHODCALLTYPE DeckLinkOutput::QueryInterface(REFIID, LPVOID *)
 {
        return E_NOINTERFACE;