diff --git a/CMakeLists.txt b/CMakeLists.txt index e3f9a631..f850199e 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -39,6 +39,7 @@ endif() target_sources( ${CMAKE_PROJECT_NAME} + PRIVATE src/forms/output-settings.cpp src/forms/output-settings.h @@ -49,6 +50,8 @@ target_sources( src/obs-support/remote-text.hpp src/obs-support/shared-update.cpp src/obs-support/shared-update.hpp + src/obs-support/sync-debug.cpp + src/obs-support/sync-debug.h src/config.cpp src/config.h src/main-output.cpp diff --git a/src/ndi-filter.cpp b/src/ndi-filter.cpp index 6d1b4bf5..23c29892 100644 --- a/src/ndi-filter.cpp +++ b/src/ndi-filter.cpp @@ -16,6 +16,7 @@ ******************************************************************************/ #include "plugin-main.h" +#include "obs-support/sync-debug.h" #include #include @@ -114,6 +115,10 @@ void ndi_filter_raw_video(void *data, video_data *frame) if (!frame || !frame->data[0]) return; + obs_sync_debug_log("OBS -> ndi_filter_raw_video", + obs_source_get_name(f->obs_source), (uint64_t)0, + frame->timestamp); + NDIlib_video_frame_v2_t video_frame = {0}; video_frame.xres = f->known_width; video_frame.yres = f->known_height; @@ -122,11 +127,23 @@ void ndi_filter_raw_video(void *data, video_data *frame) video_frame.frame_rate_D = f->ovi.fps_den; video_frame.picture_aspect_ratio = 0; // square pixels video_frame.frame_format_type = NDIlib_frame_format_type_progressive; - video_frame.timecode = NDIlib_send_timecode_synthesize; + + // video_frame.timecode = NDIlib_send_timecode_synthesize; + video_frame.timecode = (frame->timestamp / 100); + video_frame.timestamp = frame->timestamp; + video_frame.p_data = frame->data[0]; video_frame.line_stride_in_bytes = frame->linesize[0]; pthread_mutex_lock(&f->ndi_sender_video_mutex); + + obs_sync_debug_log("NDI <- ndi_filter_raw_video", + obs_source_get_name(f->obs_source), + video_frame.timecode, video_frame.timestamp); + OBS_SYNC_DEBUG_LOG_VIDEO_TIME("NDI <- ndi_filter", + obs_source_get_name(f->obs_source), + video_frame.timestamp, + (uint8_t *)video_frame.p_data); ndiLib->send_send_video_v2(f->ndi_sender, &video_frame); pthread_mutex_unlock(&f->ndi_sender_video_mutex); } @@ -185,7 +202,12 @@ void ndi_filter_offscreen_render(void *data, uint32_t, uint32_t) } video_frame output_frame; + if (video_output_lock_frame(f->video_output, &output_frame, 1, os_gettime_ns())) { + obs_sync_debug_log("OBS -> ndi_filter_offscreen_render", + obs_source_get_name(f->obs_source), + 0, os_gettime_ns()); + if (f->video_data) { gs_stagesurface_unmap(f->stagesurface); f->video_data = nullptr; @@ -353,12 +375,20 @@ obs_audio_data *ndi_filter_asyncaudio(void *data, obs_audio_data *audio_data) // ndi-output.cpp/ndi_output_raw_audio(...) auto f = (ndi_filter_t *)data; + obs_sync_debug_log("OBS -> ndi_filter_asyncaudio", + obs_source_get_name(f->obs_source), 0, + audio_data->timestamp); + obs_get_audio_info(&f->oai); NDIlib_audio_frame_v3_t audio_frame = {0}; audio_frame.sample_rate = f->oai.samples_per_sec; audio_frame.no_channels = f->oai.speakers; - audio_frame.timecode = NDIlib_send_timecode_synthesize; + + // audio_frame.timecode = NDIlib_send_timecode_synthesize; + audio_frame.timecode = audio_data->timestamp / 100; + audio_frame.timestamp = audio_data->timestamp; + audio_frame.no_samples = audio_data->frames; audio_frame.channel_stride_in_bytes = audio_frame.no_samples * @@ -389,7 +419,17 @@ obs_audio_data *ndi_filter_asyncaudio(void *data, obs_audio_data *audio_data) audio_frame.p_data = f->audio_conv_buffer; pthread_mutex_lock(&f->ndi_sender_audio_mutex); + + obs_sync_debug_log("NDI <- ndi_filter_asyncaudio", + obs_source_get_name(f->obs_source), + audio_frame.timecode, audio_frame.timestamp); + OBS_SYNC_DEBUG_LOG_AUDIO_TIME("NDI <- ndi_filter", + obs_source_get_name(f->obs_source), + audio_frame.timestamp, audio_frame.p_data, + audio_frame.no_samples, + audio_frame.sample_rate); ndiLib->send_send_audio_v3(f->ndi_sender, &audio_frame); + pthread_mutex_unlock(&f->ndi_sender_audio_mutex); return audio_data; diff --git a/src/ndi-output.cpp b/src/ndi-output.cpp index 92c7cd35..8e2af515 100644 --- a/src/ndi-output.cpp +++ b/src/ndi-output.cpp @@ -16,8 +16,10 @@ ******************************************************************************/ #include "plugin-main.h" +#include "obs-support/sync-debug.h" // #include "plugin-support.h" + static FORCE_INLINE uint32_t min_uint32(uint32_t a, uint32_t b) { return a < b ? a : b; @@ -312,7 +314,8 @@ void ndi_output_rawvideo(void *data, video_data *frame) auto o = (ndi_output_t *)data; if (!o->started || !o->frame_width || !o->frame_height) return; - + obs_sync_debug_log("OBS -> ndi_output_rawvideo", o->ndi_name, + (uint64_t)0, frame->timestamp); uint32_t width = o->frame_width; uint32_t height = o->frame_height; @@ -336,6 +339,11 @@ void ndi_output_rawvideo(void *data, video_data *frame) video_frame.line_stride_in_bytes = frame->linesize[0]; } + obs_sync_debug_log("NDI <- ndi_output_rawvideo", o->ndi_name, + video_frame.timecode, video_frame.timestamp); + OBS_SYNC_DEBUG_LOG_VIDEO_TIME("NDI <- ndi_output", o->ndi_name, + frame->timestamp, + (uint8_t *)video_frame.p_data); ndiLib->send_send_video_async_v2(o->ndi_sender, &video_frame); } @@ -347,6 +355,9 @@ void ndi_output_rawaudio(void *data, audio_data *frame) if (!o->started || !o->audio_samplerate || !o->audio_channels) return; + obs_sync_debug_log("OBS -> ndi_output_rawaudio", o->ndi_name, + (uint64_t)0, frame->timestamp); + NDIlib_audio_frame_v3_t audio_frame = {0}; audio_frame.sample_rate = o->audio_samplerate; audio_frame.no_channels = (int)o->audio_channels; @@ -376,7 +387,13 @@ void ndi_output_rawaudio(void *data, audio_data *frame) } audio_frame.p_data = o->audio_conv_buffer; - + OBS_SYNC_DEBUG_LOG_AUDIO_TIME("NDI <- ndi_output", o->ndi_name, + frame->timestamp, + (float *)audio_frame.p_data, + audio_frame.no_samples, + audio_frame.sample_rate); + obs_sync_debug_log("NDI <- ndi_output_rawaudio", o->ndi_name, + audio_frame.timecode, audio_frame.timestamp); ndiLib->send_send_audio_v3(o->ndi_sender, &audio_frame); } diff --git a/src/ndi-source.cpp b/src/ndi-source.cpp index c9ffe65a..63185312 100644 --- a/src/ndi-source.cpp +++ b/src/ndi-source.cpp @@ -21,6 +21,7 @@ #include #include +#include "obs-support/sync-debug.h" #include #include @@ -706,6 +707,14 @@ void ndi_source_thread_process_audio3(ndi_source_config_t *config, NDIlib_audio_ return; } + obs_sync_debug_log("NDI -> ndi_source_thread_process_audio2", + obs_source_get_name(obs_source), + ndi_audio_frame->timecode, + ndi_audio_frame->timestamp); + OBS_SYNC_DEBUG_LOG_AUDIO_TIME( + "NDI -> ndi_source_thread", obs_source_get_name(obs_source), + ndi_audio_frame->timestamp, ndi_audio_frame2->p_data, + ndi_audio_frame->no_samples, ndi_audio_frame2->sample_rate); const int channelCount = ndi_audio_frame->no_channels > 8 ? 8 : ndi_audio_frame->no_channels; obs_audio_frame->speakers = channel_count_to_layout(channelCount); @@ -728,12 +737,84 @@ void ndi_source_thread_process_audio3(ndi_source_config_t *config, NDIlib_audio_ (uint8_t *)ndi_audio_frame->p_data + (i * ndi_audio_frame->channel_stride_in_bytes); } + obs_sync_debug_log("OBS <- ndi_source_thread_process_audio2", + obs_source_get_name(obs_source), (int64_t)0, + obs_audio_frame->timestamp); + OBS_SYNC_DEBUG_LOG_AUDIO_TIME( + "OBS <- ndi_source_thread", obs_source_get_name(obs_source), + obs_audio_frame->timestamp, (float *)obs_audio_frame->data[0], + obs_audio_frame->frames, obs_audio_frame->samples_per_sec); obs_source_output_audio(obs_source, obs_audio_frame); } -void ndi_source_thread_process_video2(ndi_source_config_t *config, NDIlib_video_frame_v2_t *ndi_video_frame, - obs_source *obs_source, obs_source_frame *obs_video_frame) +void ndi_source_thread_process_audio3(ndi_source_config_t *config, + NDIlib_audio_frame_v3_t *ndi_audio_frame3, + obs_source_t *obs_source, + obs_source_audio *obs_audio_frame) +{ + if (!config->audio_enabled) { + return; + } + + obs_sync_debug_log("NDI -> ndi_source_thread_process_audio3", + obs_source_get_name(obs_source), + ndi_audio_frame3->timecode, + ndi_audio_frame3->timestamp); + + OBS_SYNC_DEBUG_LOG_AUDIO_TIME( + "NDI -> ndi_source_thread", obs_source_get_name(obs_source), + ndi_audio_frame3->timestamp, (float *)ndi_audio_frame3->p_data, + ndi_audio_frame3->no_samples, ndi_audio_frame3->sample_rate); + + const int channelCount = ndi_audio_frame3->no_channels > 8 + ? 8 + : ndi_audio_frame3->no_channels; + + obs_audio_frame->speakers = channel_count_to_layout(channelCount); + + switch (config->sync_mode) { + case PROP_SYNC_NDI_TIMESTAMP: + obs_audio_frame->timestamp = + (uint64_t)(ndi_audio_frame3->timestamp * 100); + break; + + case PROP_SYNC_NDI_SOURCE_TIMECODE: + obs_audio_frame->timestamp = + (uint64_t)(ndi_audio_frame3->timecode * 100); + break; + } + + obs_audio_frame->samples_per_sec = ndi_audio_frame3->sample_rate; + obs_audio_frame->format = AUDIO_FORMAT_FLOAT_PLANAR; + obs_audio_frame->frames = ndi_audio_frame3->no_samples; + for (int i = 0; i < channelCount; ++i) { + obs_audio_frame->data[i] = + (uint8_t *)ndi_audio_frame3->p_data + + (i * ndi_audio_frame3->channel_stride_in_bytes); + } + + obs_sync_debug_log("OBS <- ndi_source_thread_process_audio3", + obs_source_get_name(obs_source), (int64_t)0, + obs_audio_frame->timestamp); + OBS_SYNC_DEBUG_LOG_AUDIO_TIME( + "OBS <- ndi_source_thread", obs_source_get_name(obs_source), + obs_audio_frame->timestamp, (float *)obs_audio_frame->data[0], + obs_audio_frame->frames, obs_audio_frame->samples_per_sec); + obs_source_output_audio(obs_source, obs_audio_frame); +} + +void ndi_source_thread_process_video2(ndi_source_config_t *config, NDIlib_video_frame_v2_t *ndi_video_frame, + obs_source *obs_source, obs_source_frame *obs_video_frame) + { + obs_sync_debug_log("NDI -> ndi_source_thread_process_video2", + obs_source_get_name(obs_source), + ndi_video_frame->timecode, + ndi_video_frame->timestamp); + OBS_SYNC_DEBUG_LOG_VIDEO_TIME("NDI -> ndi_source_thread", + obs_source_get_name(obs_source), + ndi_video_frame->timestamp, + (uint8_t *)ndi_video_frame->p_data); switch (ndi_video_frame->FourCC) { case NDIlib_FourCC_type_BGRA: obs_video_frame->format = VIDEO_FORMAT_BGRA; @@ -787,6 +868,13 @@ void ndi_source_thread_process_video2(ndi_source_config_t *config, NDIlib_video_ video_format_get_parameters(config->yuv_colorspace, config->yuv_range, obs_video_frame->color_matrix, obs_video_frame->color_range_min, obs_video_frame->color_range_max); + obs_sync_debug_log("OBS <- ndi_source_thread_process_video2", + obs_source_get_name(obs_source), (int64_t)0, + obs_video_frame->timestamp); + OBS_SYNC_DEBUG_LOG_VIDEO_TIME("OBS <- ndi_source_thread", + obs_source_get_name(obs_source), + (int64_t)obs_video_frame->timestamp, + obs_video_frame->data[0]); obs_source_output_video(obs_source, obs_video_frame); } diff --git a/src/obs-support/sync-debug.cpp b/src/obs-support/sync-debug.cpp new file mode 100644 index 00000000..b03f1216 --- /dev/null +++ b/src/obs-support/sync-debug.cpp @@ -0,0 +1,171 @@ +#include "obs-support/sync-debug.h" +#include + +// Shared map to store the last log time for each message +static std::map lastLogTime; + +// Function to clear the lastLogTime map +void obs_clear_last_log_time() +{ + if (lastLogTime.size() == 0) + return; + + lastLogTime.clear(); + obs_log(LOG_INFO, "Cleared lastLogTime map."); +} + +// Function to log messages with a cooldown for each message +void obs_sync_debug_log(const char *message, const char *source_ndi_name, + uint64_t timecode, uint64_t timestamp) +{ + if ((LOG_LEVEL != LOG_VERBOSE) || (lastLogTime.size() >= 100)) + return; + + auto now = std::chrono::steady_clock::now(); + + std::string key = std::string(message) + " [" + + std::string(source_ndi_name) + "]"; + auto it = lastLogTime.find(key); + if (it == lastLogTime.end() || + std::chrono::duration_cast(now - it->second) + .count() >= 5) { + + std::string timecodeStr = "N/A"; + if (timecode > (uint64_t)0) { + timecodeStr = + (timecode == LLONG_MAX) + ? "MAX" + : std::to_string(timecode / 1000000); + } + + std::string timestampStr = "N/A"; + + if (timestamp > (uint64_t)0) { + timestampStr = + (timestamp == LLONG_MAX) + ? "MAX" + : std::to_string(timestamp / 1000000); + } + + obs_log(LOG_VERBOSE, "tc=%14s ts=%14s: %s", timecodeStr.c_str(), + timestampStr.c_str(), key.c_str()); + lastLogTime[key] = now; + } +} + +std::map audio_on; +std::map audio_on_time; +std::map white_on; +std::map white_on_time; + +int64_t obs_sync_white_time(int64_t time, uint8_t *p_data) +{ + uint8_t pixel0 = p_data[0]; + uint8_t pixel1 = p_data[1]; + bool white = (((pixel0 == 128) && (pixel1 == 235)) || + ((pixel0 == 255) && (pixel1 == 255))); + return white ? time : 0; +} +int64_t obs_sync_audio_time(int64_t time, float *p_data, int nsamples, + int samplerate) +{ + int64_t return_time = 0; + int sample = 0; + while (sample < nsamples) { + auto sample_amp = p_data[sample]; + if (sample_amp != 0.0f) { + int64_t ns_per_sample = 1000000000 / samplerate; + return_time = time + sample * ns_per_sample; + float sample_amp_prev = 0.0f; + if (sample > 0) + sample_amp_prev = p_data[sample - 1]; + return return_time; + } + sample++; + } + return return_time; +} + +void obs_sync_debug_log_video_time(const char *message, + const char *source_ndi_name, + uint64_t timestamp, uint8_t *data) +{ + if ((LOG_LEVEL != LOG_VERBOSE) || (white_on.size() >= 100)) + return; + std::string key = std::string(message) + " [" + + std::string(source_ndi_name) + "]"; + + auto wo = white_on.find(key); + if (wo == white_on.end()) { + white_on[key] = false; + wo = white_on.find(key); + } + + // If white frame is going from off to on, log the frame time, audio time and diff + auto white_time = obs_sync_white_time(timestamp, data); + if (!wo->second && (white_time > 0)) { + white_on[key] = true; + white_on_time[key] = white_time; + + auto diff = white_on_time[key] - audio_on_time[key]; + + std::string wtimeStr = "N/A"; + if (white_on_time[key] > (int64_t)0) { + wtimeStr = (white_on_time[key] == LLONG_MAX) + ? "MAX" + : std::to_string(white_on_time[key] / + 1000000); + } + + std::string atimeStr = "N/A"; + if (audio_on_time[key] > (int64_t)0) { + atimeStr = (audio_on_time[key] == LLONG_MAX) + ? "MAX" + : std::to_string(audio_on_time[key] / + 1000000); + } + + std::string dtimeStr = "N/A"; + if ((audio_on_time[key] > (int64_t)0) && + (white_on_time[key] > (int64_t)0)) { + + dtimeStr = ((audio_on_time[key] == LLONG_MAX) || + (white_on_time[key] == LLONG_MAX)) + ? "MAX" + : std::to_string(diff / 1000000); + } + obs_log(LOG_VERBOSE, + "~___~___ Sync Test Data Found: AT %14s WT %14s: %5s %s", + atimeStr.c_str(), wtimeStr.c_str(), dtimeStr.c_str(), + key.c_str()); + + } else if (wo->second && (white_time == 0)) { + white_on[key] = false; + } +} +void obs_sync_debug_log_audio_time(const char *message, + const char *source_ndi_name, + uint64_t timestamp, float *data, + int no_samples, int sample_rate) +{ + if ((LOG_LEVEL != LOG_VERBOSE) || (audio_on.size() >= 100)) + return; + std::string key = std::string(message) + " [" + + std::string(source_ndi_name) + "]"; + + auto ao = audio_on.find(key); + if (ao == audio_on.end()) { + audio_on[key] = false; // set audio off + ao = audio_on.find(key); + } + + // If audio on, log the frame time + auto audio_time = + obs_sync_audio_time(timestamp, data, no_samples, sample_rate); + if (!ao->second && (audio_time > 0)) { + ao->second = true; // set audio on + audio_on_time[key] = audio_time; + } else if (ao->second && (audio_time == 0)) { + ao->second = false; + } +} diff --git a/src/obs-support/sync-debug.h b/src/obs-support/sync-debug.h new file mode 100644 index 00000000..329fae77 --- /dev/null +++ b/src/obs-support/sync-debug.h @@ -0,0 +1,44 @@ +#pragma once + +#include +#include +#include +#include +#include "plugin-main.h" +#include "plugin-support.h" + +void obs_sync_debug_log(const char *checkpoint, const char *source_ndi_name, + uint64_t timecode, uint64_t timestamp); +void obs_sync_debug_log_video_time(const char *message, + const char *source_ndi_name, + uint64_t timestamp, uint8_t *data); +void obs_sync_debug_log_audio_time(const char *message, + const char *source_ndi_name, + uint64_t timestamp, float *data, + int no_samples, int sample_rate); +void obs_clear_last_log_time(); + +// Uncomment to enable measuring audio and video time differences +// using black/white frames and audio on white frames +#define SYNC_DEBUG 1 +#ifdef SYNC_DEBUG +#define OBS_SYNC_DEBUG_LOG_VIDEO_TIME(message, source_ndi_name, timestamp, \ + data) \ + obs_sync_debug_log_video_time(message, source_ndi_name, timestamp, data) +#else +#define OBS_SYNC_DEBUG_LOG_VIDEO_TIME(message, source_ndi_name, timestamp, \ + data) \ + do { \ + } while (0) +#endif +#ifdef SYNC_DEBUG +#define OBS_SYNC_DEBUG_LOG_AUDIO_TIME(message, source_ndi_name, timestamp, \ + data, no_samples, sample_rate) \ + obs_sync_debug_log_audio_time(message, source_ndi_name, timestamp, \ + data, no_samples, sample_rate) +#else +#define OBS_SYNC_DEBUG_LOG_AUDIO_TIME(message, source_ndi_name, timestamp, \ + data, no_samples, sample_rate) \ + do { \ + } while (0) +#endif diff --git a/src/plugin-main.cpp b/src/plugin-main.cpp index f220daca..0be2112f 100644 --- a/src/plugin-main.cpp +++ b/src/plugin-main.cpp @@ -19,6 +19,8 @@ #include "obs-module.h" #include "plugin-support.h" +#include "obs-support/sync-debug.h" + #include "forms/output-settings.h" #include "forms/update.h" #include "main-output.h" @@ -402,7 +404,9 @@ void obs_module_unload(void) delete loaded_lib; } + obs_clear_last_log_time(); obs_log(LOG_DEBUG, "-obs_module_unload(): goodbye!"); + } const NDIlib_v6 *load_ndilib() diff --git a/tests/SendSyncTestData.exe b/tests/SendSyncTestData.exe new file mode 100644 index 00000000..5ab16791 Binary files /dev/null and b/tests/SendSyncTestData.exe differ diff --git a/tests/SyncTestZeroAV.mp4 b/tests/SyncTestZeroAV.mp4 new file mode 100644 index 00000000..81f54189 Binary files /dev/null and b/tests/SyncTestZeroAV.mp4 differ