From 0d6426d79ce79ddd23959f358c84ba1de6e375da Mon Sep 17 00:00:00 2001 From: yanj_github Date: Wed, 15 Jan 2025 12:37:23 +0000 Subject: [PATCH] Resolve issue #93, #95 and #96. --- audio_file_reader.py | 7 +- camera_calibration_helper.py | 11 +-- config.ini | 9 ++- dpctf_audio_decoder.py | 2 +- global_configurations.py | 12 ++++ observation_framework.py | 13 ++-- observation_framework_processor.py | 6 +- .../audio_sample_matches_current_time.py | 2 +- observations/audio_video_synchronization.py | 49 ++++++++----- .../earliest_sample_same_presentation_time.py | 68 +++++++------------ observations/sample_matches_current_time.py | 2 +- test_code/sequential_track_playback.py | 2 +- 12 files changed, 100 insertions(+), 83 deletions(-) diff --git a/audio_file_reader.py b/audio_file_reader.py index 261fbd5..552322e 100644 --- a/audio_file_reader.py +++ b/audio_file_reader.py @@ -29,18 +29,21 @@ import logging import math import os +import platform import struct import subprocess import wave from wave import Wave_read - import numpy as np import pyaudio -import sounddevice from exceptions import ObsFrameTerminate from global_configurations import GlobalConfigurations +# to fix ALSA lib error on console output +if platform.system() == 'Linux': + import sounddevice # pylint: disable=unused-import + # audio file reader chunk size CHUNK_SIZE = 1024 * 1000 # only accept 48KHz required for dpctf WAVE diff --git a/camera_calibration_helper.py b/camera_calibration_helper.py index 4742cb2..78b0041 100644 --- a/camera_calibration_helper.py +++ b/camera_calibration_helper.py @@ -138,7 +138,9 @@ def detect_beeps(video_file: str, log_file_path: str, config: list) -> list: "Recording must be captured in duo-channel. Channels: {n_channels}" ) if frame_rate != 48000: - raise ObsFrameTerminate("Recording must be in 48kHz. Recording Rate: {frame_rate}") + raise ObsFrameTerminate( + "Recording must be in 48kHz. Recording Rate: {frame_rate}" + ) raw_data = wav_file.readframes(n_frames) audio_data = np.frombuffer(raw_data, dtype=np.int16) @@ -280,7 +282,7 @@ def calibrate_camera( "of the test has been captured. Ensure all instructions were followed carefully.\n" "If same issue persists, it may indicate that the camera is not suitable for WAVE test\n" "requirements and could produce inaccurate results. Use this camera at your discretion." - ) + ) if ( len(detected_flashes) > config["flash_and_beep_count"] or len(detected_beeps) > config["flash_and_beep_count"] @@ -303,9 +305,10 @@ def main() -> None: description="DPCTF Device Observation Framework Camera Calibration Helper." ) parser.add_argument( - "--log", nargs='+', # Allow 1 or 2 values + "--log", + nargs="+", # Allow 1 or 2 values help="Logging levels for log file writing and console output.", - default=["debug", "info"], # default to info console log and debug file writing + default=["debug", "info"], # default to info console log and debug file writing choices=["info", "debug"], ) parser.add_argument( diff --git a/config.ini b/config.ini index 16ad333..78e2066 100644 --- a/config.ini +++ b/config.ini @@ -84,13 +84,16 @@ mid_frame_num_tolerance = 10 splice_start_frame_num_tolerance = 0 splice_end_frame_num_tolerance = 0 # audio tolerances in counts -start_segment_num_tolerance = 0 +start_segment_num_tolerance = 3 end_segment_num_tolerance = 0 mid_segment_num_tolerance = 10 splice_start_segment_num_tolerance = 0 splice_end_segment_num_tolerance = 0 -# audio video synchronization tolerances in percent -av_sync_pass_rate = 80 +# audio video tolerances +earliest_sample_alignment_tolerance = 60 +av_sync_start_tolerance = 1000 +av_sync_end_tolerance = 1000 +av_sync_pass_rate = 95 [CALIBRATION] # number of flash and beep pair in the recording file diff --git a/dpctf_audio_decoder.py b/dpctf_audio_decoder.py index 54545f9..e61b651 100644 --- a/dpctf_audio_decoder.py +++ b/dpctf_audio_decoder.py @@ -245,7 +245,7 @@ def trim_audio( plt.xlabel("Time") plt.ylabel("Audio Wave") subject_data_file = ( - observation_data_export_file + "_subject_data_" + str(index) + ".png" + observation_data_export_file + "subject_data_" + str(index) + ".png" ) plt.title("subject_data") plt.plot(subject_data) diff --git a/global_configurations.py b/global_configurations.py index 1f63e3b..60132ff 100644 --- a/global_configurations.py +++ b/global_configurations.py @@ -286,6 +286,9 @@ def get_tolerances(self) -> Dict[str, int]: "mid_segment_num_tolerance": 0, "splice_start_segment_num_tolerance": 0, "splice_end_segment_num_tolerance": 0, + "earliest_sample_alignment_tolerance": 0, + "av_sync_start_tolerance": 0, + "av_sync_end_tolerance": 0, "av_sync_pass_rate": 100, } try: @@ -319,6 +322,15 @@ def get_tolerances(self) -> Dict[str, int]: tolerances["splice_end_segment_num_tolerance"] = int( self.config["TOLERANCES"]["splice_end_segment_num_tolerance"] ) + tolerances["earliest_sample_alignment_tolerance"] = int( + self.config["TOLERANCES"]["earliest_sample_alignment_tolerance"] + ) + tolerances["av_sync_start_tolerance"] = int( + self.config["TOLERANCES"]["av_sync_start_tolerance"] + ) + tolerances["av_sync_end_tolerance"] = int( + self.config["TOLERANCES"]["av_sync_end_tolerance"] + ) tolerances["av_sync_pass_rate"] = int( self.config["TOLERANCES"]["av_sync_pass_rate"] ) diff --git a/observation_framework.py b/observation_framework.py index 99008f9..f950779 100644 --- a/observation_framework.py +++ b/observation_framework.py @@ -523,10 +523,10 @@ def check_python_version() -> bool: Returns: True if version is OK. """ - if sys.version_info.major == 3 and sys.version_info.minor >= 10: + if sys.version_info.major == 3 and sys.version_info.minor >= 9: return True logger.critical( - "Aborting! Python version 3.10 or greater is required.\nCurrent Python version is %d.%d.", + "Aborting! Python version 3.9 or greater is required.\nCurrent Python version is %d.%d.", sys.version_info.major, sys.version_info.minor, ) @@ -599,7 +599,9 @@ def process_run( clear_up(global_configurations) sys.exit(1) except Exception as e: - logger.exception("Serious error is detected!\n%s: %s", e, traceback.format_exc()) + logger.exception( + "Serious error is detected!\n%s: %s", e, traceback.format_exc() + ) clear_up(global_configurations) sys.exit(1) @@ -619,9 +621,10 @@ def main() -> None: "--input", required=True, help="Input recording file / path to analyse." ) parser.add_argument( - "--log", nargs='+', # Allow 1 or 2 values + "--log", + nargs="+", # Allow 1 or 2 values help="Logging levels for log file writing and console output.", - default=["debug", "info"], # default to info console log and debug file writing + default=["debug", "info"], # default to info console log and debug file writing choices=["info", "debug"], ) parser.add_argument( diff --git a/observation_framework_processor.py b/observation_framework_processor.py index 5573cbc..ce31ec1 100644 --- a/observation_framework_processor.py +++ b/observation_framework_processor.py @@ -348,11 +348,7 @@ def _load_new_test(self) -> None: logger.info("Start a New test: %s", self.test_path) if self.session_log_path: - self.observation_data_export_file = ( - self.session_log_path - + "/" - + self.test_path.replace("/", "-").replace(".html", "") - ) + self.observation_data_export_file = self.session_log_path + "/" try: module_name = self.tests[test_code][0] diff --git a/observations/audio_sample_matches_current_time.py b/observations/audio_sample_matches_current_time.py index 45399b4..7a6c603 100644 --- a/observations/audio_sample_matches_current_time.py +++ b/observations/audio_sample_matches_current_time.py @@ -225,7 +225,7 @@ def make_observation( # Exporting time diff data to a CSV file if observation_data_export_file and time_differences: write_data_to_csv_file( - observation_data_export_file + "_audio_ct_diff.csv", + observation_data_export_file + "audio_ct_diff.csv", ["Current Time", "Time Difference"], time_differences, ) diff --git a/observations/audio_video_synchronization.py b/observations/audio_video_synchronization.py index 644ea22..8c3c36f 100644 --- a/observations/audio_video_synchronization.py +++ b/observations/audio_video_synchronization.py @@ -114,7 +114,7 @@ def _calculate_video_offsets( if logger.getEffectiveLevel() == logging.DEBUG and observation_data_export_file: write_data_to_csv_file( - observation_data_export_file + "_video_data.csv", + observation_data_export_file + "video_data.csv", [ "frame_number", "mean_media_time", @@ -160,7 +160,7 @@ def _calculate_audio_offsets( if logger.getEffectiveLevel() == logging.DEBUG and observation_data_export_file: write_data_to_csv_file( - observation_data_export_file + "_audio_data.csv", + observation_data_export_file + "audio_data.csv", ["content id", "media time", "mean_time", "offsets"], audio_offsets, ) @@ -204,17 +204,24 @@ def make_observation( audio_offsets = [] video_offsets = [] time_differences = [] - pass_count = 0 + total_count = 0 failure_count = 0 + failure_within_tolerance = 0 camera_frame_duration_ms = parameters_dict["camera_frame_duration_ms"] audio_sample_length = parameters_dict["audio_sample_length"] av_sync_tolerance = parameters_dict["av_sync_tolerance"] + av_sync_start_tolerance = self.tolerances["av_sync_start_tolerance"] + av_sync_end_tolerance = self.tolerances["av_sync_end_tolerance"] av_sync_pass_rate = self.tolerances["av_sync_pass_rate"] self.result["message"] += ( - f" The allowed tolerance range is {av_sync_tolerance}ms," - f" and required pass rate is {av_sync_pass_rate}%." + f"The allowed AV sync tolerance is {av_sync_tolerance} ms. " + f"The starting tolerance is {av_sync_start_tolerance}ms and " + f"the ending tolerance is {av_sync_end_tolerance}ms. " + f"The required pass rate is {av_sync_pass_rate}%. " ) + check_from = parameters_dict["audio_starting_time"] + av_sync_start_tolerance + check_to = parameters_dict["audio_ending_time"] - av_sync_end_tolerance # calculate video offsets video_offsets = self._calculate_video_offsets( @@ -249,24 +256,30 @@ def make_observation( time_differences.append((audio_offsets[i][2], round(time_diff, 2))) if time_diff > av_sync_tolerance[0] or time_diff < av_sync_tolerance[1]: - if failure_count == 0: - self.result["message"] += " The Audio-Video Synchronization failed." failure_count += 1 - else: - pass_count += 1 + if audio_offsets[i][2] < check_from or audio_offsets[i][2] > check_to: + failure_within_tolerance += 1 + total_count += 1 - pass_rate = (pass_count / (pass_count + failure_count)) * 100 + pass_rate = ( + (total_count - failure_count + failure_within_tolerance) / total_count + ) * 100 self.result["message"] += ( - f" Total failure count is {failure_count}, " - f"{round(pass_rate, 2)}% is in Sync." + f"Total failure count is {failure_count}, with {failure_within_tolerance} failures " + f"within the start and end tolerance. AV Sync was checked from {check_from}ms to " + f"{check_to}ms, and {round(pass_rate, 2)}% was in sync. " ) - if time_differences: - maximum_diff = max(time_differences, key=lambda x: x[1]) - minimum_diff = min(time_differences, key=lambda x: x[1]) + # get filtered time differences between check_from and check_to + filtered_time_differences = [ + item for item in time_differences if check_from <= item[0] <= check_to + ] + if filtered_time_differences: + maximum_diff = max(filtered_time_differences, key=lambda x: x[1]) + minimum_diff = min(filtered_time_differences, key=lambda x: x[1]) self.result["message"] += ( - f" AV Sync time diff range=[{round(minimum_diff[1], 2)}, " - f"{round(maximum_diff[1], 2)}]." + f"The AV Sync offset range is [{round(minimum_diff[1], 2)}, " + f"{round(maximum_diff[1], 2)}] ms." ) if pass_rate >= av_sync_pass_rate: self.result["status"] = "PASS" @@ -278,7 +291,7 @@ def make_observation( # Exporting time diff data to a CSV file and png file if logger.getEffectiveLevel() == logging.DEBUG: - file_name = observation_data_export_file + "_av_sync_diff.csv" + file_name = observation_data_export_file + "av_sync_diff.csv" write_data_to_csv_file( file_name, ["audio sample", "time diff"], diff --git a/observations/earliest_sample_same_presentation_time.py b/observations/earliest_sample_same_presentation_time.py index d934121..8f2ddff 100644 --- a/observations/earliest_sample_same_presentation_time.py +++ b/observations/earliest_sample_same_presentation_time.py @@ -29,6 +29,7 @@ from dpctf_audio_decoder import AudioSegment from dpctf_qr_decoder import MezzanineDecodedQr, TestStatusDecodedQr +from global_configurations import GlobalConfigurations from .observation import Observation @@ -41,10 +42,11 @@ class EarliestSampleSamePresentationTime(Observation): corresponds to the same presentation time as the earliest video sample. """ - def __init__(self, _): + def __init__(self, global_configurations: GlobalConfigurations): super().__init__( "[OF] The WAVE presentation starts with the earliest video and audio sample that" - " corresponds to the same presentation time as the earliest video sample." + " corresponds to the same presentation time as the earliest video sample.", + global_configurations, ) def make_observation( @@ -52,9 +54,9 @@ def make_observation( _test_type, mezzanine_qr_codes: List[MezzanineDecodedQr], audio_segments: List[AudioSegment], - test_status_qr_codes: List[TestStatusDecodedQr], + _test_status_qr_codes: List[TestStatusDecodedQr], _parameters_dict: dict, - _observation_data_export_file, + _observation_data_export_file: str, ) -> Tuple[Dict[str, str], list, list]: """ Check The WAVE presentation starts with the earliest video and audio sample that @@ -70,55 +72,37 @@ def make_observation( logger.info("[%s] %s", self.result["status"], self.result["message"]) return self.result, [], [] - # Compare video presentation time with HTML reported presentation time - starting_ct = None - for i in range(0, len(test_status_qr_codes)): - current_status = test_status_qr_codes[i] - if current_status.status == "playing" and ( - current_status.last_action == "play" - or current_status.last_action == "representation_change" - ): - starting_ct = current_status.current_time * 1000 - break - - if starting_ct == None: + # check audio when pass the video check + if not audio_segments: self.result["status"] = "NOT_RUN" - self.result["message"] = "HTML starting presentation time is not found." + self.result["message"] += " No audio segment is detected." logger.info("[%s] %s", self.result["status"], self.result["message"]) return self.result, [], [] - video_result = False + earliest_sample_alignment_tolerance = self.tolerances[ + "earliest_sample_alignment_tolerance" + ] + self.result["message"] += ( + f"The earliest video and audio sample alignment tolerance is " + f"{earliest_sample_alignment_tolerance} ms. " + ) + video_frame_duration = round(1000 / mezzanine_qr_codes[0].frame_rate) earliest_video_media_time = ( mezzanine_qr_codes[0].media_time - video_frame_duration ) - if earliest_video_media_time == starting_ct: - video_result = True - else: + earliest_audio_media_time = audio_segments[0].media_time + diff = abs(earliest_video_media_time - earliest_audio_media_time) + + if diff > earliest_sample_alignment_tolerance: self.result["status"] = "FAIL" - video_result = False + else: + self.result["status"] = "PASS" self.result["message"] += ( - f"Earliest video sample presentation time is {earliest_video_media_time} ms," - f" expected starting presentation time is {starting_ct} ms." + f"The earliest video sample presentation time is {earliest_video_media_time} ms while " + f"the earliest audio sample presentation time is {earliest_audio_media_time} ms. There " + f"is a {diff} ms time difference between video and audio sample presentation times." ) - if video_result: - # check audio when pass the video check - if not audio_segments: - self.result["status"] = "NOT_RUN" - self.result["message"] += " No audio segment is detected." - logger.info("[%s] %s", self.result["status"], self.result["message"]) - return self.result, [], [] - - earliest_audio_media_time = audio_segments[0].media_time - - if earliest_video_media_time == earliest_audio_media_time: - self.result["status"] = "PASS" - else: - self.result["status"] = "FAIL" - self.result[ - "message" - ] += f" Earliest audio sample presentation time is {earliest_audio_media_time} ms." - logger.debug("[%s] %s", self.result["status"], self.result["message"]) return self.result, [], [] diff --git a/observations/sample_matches_current_time.py b/observations/sample_matches_current_time.py index 6ad4cc5..177223a 100644 --- a/observations/sample_matches_current_time.py +++ b/observations/sample_matches_current_time.py @@ -331,7 +331,7 @@ def make_observation( # Exporting time diff data to a CSV file if observation_data_export_file and time_differences: write_data_to_csv_file( - observation_data_export_file + "_video_ct_diff.csv", + observation_data_export_file + "video_ct_diff.csv", ["Current Time", "Time Difference"], time_differences, ) diff --git a/test_code/sequential_track_playback.py b/test_code/sequential_track_playback.py index 837a167..8bdff44 100644 --- a/test_code/sequential_track_playback.py +++ b/test_code/sequential_track_playback.py @@ -377,7 +377,7 @@ def make_observations( if logger.getEffectiveLevel() == logging.DEBUG: if observation_data_export_file and audio_segments: audio_data_to_csv( - observation_data_export_file + "_audio_segment_data.csv", + observation_data_export_file + "audio_segment_data.csv", audio_segments, self.parameters_dict, )