Fix recording artifact readiness race
This commit is contained in:
@@ -167,6 +167,70 @@ async def wait_for_file_ready(file_path: str, attempts: int = 20, delay: float =
|
|||||||
return False
|
return False
|
||||||
|
|
||||||
|
|
||||||
|
async def wait_for_recording_artifacts_ready(file_path: str, attempts: int = 20, delay: float = 0.25) -> str | None:
|
||||||
|
"""Wait until either speaker tracks appear or the mixed WAV is finalized.
|
||||||
|
|
||||||
|
The voice receive library fires the post-recording callback before sink
|
||||||
|
cleanup writes ``tracks/tracks.json``. Polling for both artifact types keeps
|
||||||
|
us from failing on the corrupt mixed archive while finalized speaker tracks
|
||||||
|
are about to appear.
|
||||||
|
"""
|
||||||
|
last_size = -1
|
||||||
|
stable_count = 0
|
||||||
|
|
||||||
|
for attempt in range(1, attempts + 1):
|
||||||
|
tracks = _load_speaker_tracks(file_path)
|
||||||
|
if tracks:
|
||||||
|
logger.info(
|
||||||
|
"Speaker tracks ready: path=%s attempt=%s/%s speakers=%s",
|
||||||
|
file_path,
|
||||||
|
attempt,
|
||||||
|
attempts,
|
||||||
|
len(tracks),
|
||||||
|
)
|
||||||
|
return "tracks"
|
||||||
|
|
||||||
|
if os.path.exists(file_path):
|
||||||
|
size = os.path.getsize(file_path)
|
||||||
|
logger.info(
|
||||||
|
"Checking recording artifacts readiness: path=%s attempt=%s/%s size_bytes=%s",
|
||||||
|
file_path,
|
||||||
|
attempt,
|
||||||
|
attempts,
|
||||||
|
size,
|
||||||
|
)
|
||||||
|
if size > 0 and size == last_size:
|
||||||
|
stable_count += 1
|
||||||
|
if stable_count >= 2:
|
||||||
|
try:
|
||||||
|
with wave.open(file_path, "rb") as wav_file:
|
||||||
|
wav_file.getparams()
|
||||||
|
except (wave.Error, EOFError, OSError) as exc:
|
||||||
|
logger.info(
|
||||||
|
"Mixed recording is size-stable but WAV header is not finalized yet: path=%s error=%s",
|
||||||
|
file_path,
|
||||||
|
exc,
|
||||||
|
)
|
||||||
|
else:
|
||||||
|
logger.info("Mixed recording finalized: path=%s size_bytes=%s", file_path, size)
|
||||||
|
return "mixed"
|
||||||
|
else:
|
||||||
|
stable_count = 0
|
||||||
|
last_size = size
|
||||||
|
else:
|
||||||
|
logger.info(
|
||||||
|
"Recording file not present yet while waiting for artifacts: path=%s attempt=%s/%s",
|
||||||
|
file_path,
|
||||||
|
attempt,
|
||||||
|
attempts,
|
||||||
|
)
|
||||||
|
|
||||||
|
await asyncio.sleep(delay)
|
||||||
|
|
||||||
|
logger.warning("Recording artifacts were not ready before timeout: path=%s", file_path)
|
||||||
|
return None
|
||||||
|
|
||||||
|
|
||||||
def build_retry_notice(file_path: str, reason: str) -> str:
|
def build_retry_notice(file_path: str, reason: str) -> str:
|
||||||
file_name = Path(file_path).name
|
file_name = Path(file_path).name
|
||||||
return (
|
return (
|
||||||
@@ -287,16 +351,11 @@ async def process_recording(
|
|||||||
)
|
)
|
||||||
return
|
return
|
||||||
|
|
||||||
# Speaker tracks are written and finalized independently in MeetingSink
|
# Speaker tracks are written during MeetingSink cleanup, but the voice
|
||||||
# cleanup — they always have valid WAV headers if they exist. Check
|
# library fires this callback before cleanup runs. Wait for either the
|
||||||
# them first so we can skip the mixed-file "ready" wait (which is prone
|
# manifest to appear or the mixed archive to become a valid WAV.
|
||||||
# to timing races with the SilenceGenerator shutdown path).
|
ready_source = await wait_for_recording_artifacts_ready(file_path)
|
||||||
if _load_speaker_tracks(file_path):
|
if not ready_source:
|
||||||
logger.info(
|
|
||||||
"Speaker tracks present for guild_id=%s; skipping mixed-file readiness check",
|
|
||||||
guild_id,
|
|
||||||
)
|
|
||||||
elif not await wait_for_file_ready(file_path):
|
|
||||||
reason = "recording file was not finalized in time"
|
reason = "recording file was not finalized in time"
|
||||||
await _save_retry_state(guild_id, file_path, fallback_channel_id, reason)
|
await _save_retry_state(guild_id, file_path, fallback_channel_id, reason)
|
||||||
await safe_send_chunked(
|
await safe_send_chunked(
|
||||||
@@ -306,6 +365,11 @@ async def process_recording(
|
|||||||
purpose="file-finalization warning",
|
purpose="file-finalization warning",
|
||||||
)
|
)
|
||||||
return
|
return
|
||||||
|
logger.info(
|
||||||
|
"Recording artifacts ready for guild_id=%s via %s",
|
||||||
|
guild_id,
|
||||||
|
ready_source,
|
||||||
|
)
|
||||||
|
|
||||||
if os.path.exists(file_path):
|
if os.path.exists(file_path):
|
||||||
logger.info(
|
logger.info(
|
||||||
|
|||||||
@@ -133,6 +133,30 @@ def test_wait_for_file_ready_accepts_valid_wav(tmp_path):
|
|||||||
assert ready is True
|
assert ready is True
|
||||||
|
|
||||||
|
|
||||||
|
def test_wait_for_recording_artifacts_ready_accepts_tracks_created_during_wait(tmp_path):
|
||||||
|
meeting = tmp_path / "meeting.wav"
|
||||||
|
meeting.write_bytes(b"not a finalized mixed wav")
|
||||||
|
tracks_dir = tmp_path / "tracks"
|
||||||
|
tracks_dir.mkdir()
|
||||||
|
|
||||||
|
async def create_tracks_later():
|
||||||
|
await asyncio.sleep(0.003)
|
||||||
|
alice = tracks_dir / "track-111.wav"
|
||||||
|
alice.write_bytes(b"alice audio")
|
||||||
|
(tracks_dir / "tracks.json").write_text(
|
||||||
|
'{"tracks":[{"display_name":"Alice","path":"' + str(alice) + '"}]}'
|
||||||
|
)
|
||||||
|
|
||||||
|
async def run_wait():
|
||||||
|
writer = asyncio.create_task(create_tracks_later())
|
||||||
|
try:
|
||||||
|
return await bot.wait_for_recording_artifacts_ready(str(meeting), attempts=20, delay=0.001)
|
||||||
|
finally:
|
||||||
|
await writer
|
||||||
|
|
||||||
|
assert asyncio.run(run_wait()) == "tracks"
|
||||||
|
|
||||||
|
|
||||||
def test_load_speaker_tracks_resolves_manifest_tracks_next_to_recording(tmp_path):
|
def test_load_speaker_tracks_resolves_manifest_tracks_next_to_recording(tmp_path):
|
||||||
meeting = tmp_path / "meeting.wav"
|
meeting = tmp_path / "meeting.wav"
|
||||||
meeting.write_bytes(b"RIFFdemo")
|
meeting.write_bytes(b"RIFFdemo")
|
||||||
|
|||||||
Reference in New Issue
Block a user