From 99c2b3b4d7370d046194909aad0393fcc85bf98a Mon Sep 17 00:00:00 2001 From: SergeantPanda Date: Sun, 14 Jun 2026 11:50:50 -0500 Subject: [PATCH 1/9] fix(proxy): improve channel stop handling and logging - Enhanced the `stop_channel` method to prevent blocking during teardown by logging stop events asynchronously. - Updated stream buffer behavior to ignore late writes during shutdown, improving resource management. --- CHANGELOG.md | 1 + apps/proxy/live_proxy/input/buffer.py | 2 +- apps/proxy/live_proxy/input/manager.py | 2 + apps/proxy/live_proxy/server.py | 208 +++++++++++++++---------- 4 files changed, 130 insertions(+), 83 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index d41c6150..c5aa324a 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -43,6 +43,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Fixed +- **Live proxy channels could remain running with no clients after disconnect.** `stop_channel` called `log_system_event('channel_stop')` synchronously before local cleanup and Redis key deletion; Connect integrations or DB event writes on that path could block teardown indefinitely while the cleanup thread kept refreshing metadata TTL for a stale `stream_buffers` entry. Teardown now stops ffmpeg/output managers, releases ownership, removes local buffers and managers, deletes Redis keys, and only then logs the stop event asynchronously. Metadata TTL refresh skips channels mid-shutdown and non-owned channels; a stuck-stop watchdog forces cleanup if `stop_channel` does not return within ~30s. Stream buffers also ignore late `add_chunk()` writes once shutdown begins (`buffer.stopping` set at the start of `stream_manager.stop()`). - **Stale `channel_stream` Redis keys after a channel stopped could skip connection accounting on retune.** On `dev`, `get_stream()` reused any existing `channel_stream` / `stream_profile` assignment without reserving a new slot. If those keys were left behind after a stop, the next tune-in could reach the provider without incrementing Redis counters. `get_stream()` now releases stale assignments when proxy metadata shows the channel is inactive, then reserves fresh slots. - **EPG auto-match reliability fixes.** - Memory could spike to multiple GB on large EPG sources when building a full in-memory catalog before fuzzy matching; single-channel matching now streams rows and bounds ML work to a small candidate set. diff --git a/apps/proxy/live_proxy/input/buffer.py b/apps/proxy/live_proxy/input/buffer.py index e26ed3ff..b345ead3 100644 --- a/apps/proxy/live_proxy/input/buffer.py +++ b/apps/proxy/live_proxy/input/buffer.py @@ -64,7 +64,7 @@ class StreamBuffer: def add_chunk(self, chunk): """Add data with optimized Redis storage and TS packet alignment""" - if not chunk: + if not chunk or self.stopping: return False try: diff --git a/apps/proxy/live_proxy/input/manager.py b/apps/proxy/live_proxy/input/manager.py index ccc52318..b560923b 100644 --- a/apps/proxy/live_proxy/input/manager.py +++ b/apps/proxy/live_proxy/input/manager.py @@ -1094,6 +1094,8 @@ class StreamManager: # Add at the beginning of your stop method self.stopping = True + if self.buffer is not None: + self.buffer.stopping = True # Release stream resources if we're the owner if self.current_stream_id and hasattr(self, 'worker_id') and self.worker_id: diff --git a/apps/proxy/live_proxy/server.py b/apps/proxy/live_proxy/server.py index 879de2ec..7145fcd4 100644 --- a/apps/proxy/live_proxy/server.py +++ b/apps/proxy/live_proxy/server.py @@ -71,6 +71,7 @@ class ProxyServer: self.profile_buffers = {} # {channel_id: {profile_id: StreamBuffer}} self._channel_names = {} self._stopping_channels = set() # channels with an active stop_channel call in progress + self._stopping_since = {} # channel_id -> time.time() when stop_channel began # Generate a unique worker ID pid = os.getpid() @@ -1266,12 +1267,119 @@ class ProxyServer: for pid in list(self.profile_managers.get(channel_id, {}).keys()): self.stop_output_profile(channel_id, pid) + def _collect_channel_stop_event_data(self, channel_id): + """Snapshot metadata for channel_stop logging before Redis keys are deleted.""" + channel_name = self._channel_names.pop(channel_id, None) or str(channel_id) + runtime = None + total_bytes = None + if self.redis_client: + metadata_key = RedisKeys.channel_metadata(channel_id) + metadata = self.redis_client.hgetall(metadata_key) + if metadata: + if 'init_time' in metadata: + try: + init_time = float(metadata['init_time']) + runtime = round(time.time() - init_time, 2) + except Exception: + pass + if 'total_bytes' in metadata: + try: + total_bytes = int(metadata['total_bytes']) + except Exception: + pass + return { + 'channel_id': channel_id, + 'channel_name': channel_name, + 'runtime': runtime, + 'total_bytes': total_bytes, + } + + def _spawn_channel_stop_event(self, stop_event_data): + """Log channel_stop without blocking teardown (DB/connect dispatch can hang).""" + if not stop_event_data: + return + + def _log_stop(): + try: + close_old_connections() + log_system_event('channel_stop', **stop_event_data) + except Exception as e: + logger.error(f"Could not log channel stop event: {e}") + + gevent.spawn(_log_stop) + + def _cleanup_stopped_channel_local(self, channel_id): + """Remove local managers/buffers for a channel that is shutting down.""" + if channel_id in self.stream_managers: + del self.stream_managers[channel_id] + logger.info(f"Removed stream manager for channel {channel_id}") + + if channel_id in self.stream_buffers: + buffer = self.stream_buffers[channel_id] + if hasattr(buffer, 'stop'): + try: + buffer.stop() + logger.debug(f"Buffer for channel {channel_id} properly stopped") + except Exception as e: + logger.error(f"Error stopping buffer: {e}") + + try: + if channel_id in self.stream_buffers: + del self.stream_buffers[channel_id] + logger.info(f"Removed stream buffer for channel {channel_id}") + except KeyError: + logger.debug(f"Buffer for channel {channel_id} already removed") + + if channel_id in self.client_managers: + try: + client_manager = self.client_managers[channel_id] + if hasattr(client_manager, 'stop'): + client_manager.stop() + del self.client_managers[channel_id] + logger.info(f"Removed client manager for channel {channel_id}") + except KeyError: + logger.debug(f"Client manager for channel {channel_id} already removed") + + self.profile_managers.pop(channel_id, None) + self.profile_buffers.pop(channel_id, None) + + def _recover_stuck_channel_stops(self): + """Force cleanup when stop_channel never finishes (e.g. blocked on logging).""" + if not self._stopping_channels: + return + + now = time.time() + stuck_threshold = max(30, ConfigHelper.channel_shutdown_delay() * 2) + + for channel_id in list(self._stopping_channels): + started = self._stopping_since.get(channel_id, now) + if now - started < stuck_threshold: + continue + + logger.error( + f"Channel {channel_id} stop_channel stuck for {now - started:.0f}s " + f"- forcing local and Redis cleanup" + ) + self._stopping_channels.discard(channel_id) + self._stopping_since.pop(channel_id, None) + + if (channel_id in self.stream_buffers + or channel_id in self.client_managers + or channel_id in self.stream_managers): + try: + self._cleanup_stopped_channel_local(channel_id) + self._clean_redis_keys(channel_id) + except Exception as e: + logger.error(f"Error during forced cleanup for channel {channel_id}: {e}") + def stop_channel(self, channel_id): """Stop a channel with proper ownership handling""" if channel_id in self._stopping_channels: logger.debug(f"stop_channel already in progress for {channel_id}, ignoring duplicate call") return self._stopping_channels.add(channel_id) + self._stopping_since[channel_id] = time.time() + stop_event_data = None try: logger.info(f"Stopping channel {channel_id}") @@ -1319,90 +1427,16 @@ class ProxyServer: # Stop all output profile transcodes before releasing ownership self.stop_all_output_profiles(channel_id) + stop_event_data = self._collect_channel_stop_event_data(channel_id) + # Release ownership self.release_ownership(channel_id) - # Log channel stop event (after cleanup, before releasing ownership section ends) - try: - channel_name = self._channel_names.pop(channel_id, None) or str(channel_id) - - # Calculate runtime and get total bytes from metadata - runtime = None - total_bytes = None - if self.redis_client: - metadata_key = RedisKeys.channel_metadata(channel_id) - metadata = self.redis_client.hgetall(metadata_key) - if metadata: - # Calculate runtime from init_time - if 'init_time' in metadata: - try: - init_time = float(metadata['init_time']) - runtime = round(time.time() - init_time, 2) - except Exception: - pass - # Get total bytes transferred - if 'total_bytes' in metadata: - try: - total_bytes = int(metadata['total_bytes']) - except Exception: - pass - - log_system_event( - 'channel_stop', - channel_id=channel_id, - channel_name=channel_name, - runtime=runtime, - total_bytes=total_bytes - ) - except Exception as e: - logger.error(f"Could not log channel stop event: {e}") - - # Always clean up local resources - WITH SAFE CHECKS - if channel_id in self.stream_managers: - del self.stream_managers[channel_id] - logger.info(f"Removed stream manager for channel {channel_id}") - - # Stop buffer and ensure all its timers are cancelled - SAFE CHECK HERE - if channel_id in self.stream_buffers: - buffer = self.stream_buffers[channel_id] - # Call stop on buffer to properly shut it down - if hasattr(buffer, 'stop'): - try: - buffer.stop() - logger.debug(f"Buffer for channel {channel_id} properly stopped") - except Exception as e: - logger.error(f"Error stopping buffer: {e}") - - # Save reference and check again before deleting - try: - if channel_id in self.stream_buffers: # Check again to prevent race conditions - del self.stream_buffers[channel_id] - logger.info(f"Removed stream buffer for channel {channel_id}") - except KeyError: - logger.debug(f"Buffer for channel {channel_id} already removed") - - # Clean up client manager - SAFE CHECK HERE TOO - if channel_id in self.client_managers: - try: - client_manager = self.client_managers[channel_id] - # Stop the heartbeat thread before deleting - if hasattr(client_manager, 'stop'): - client_manager.stop() - del self.client_managers[channel_id] - logger.info(f"Removed client manager for channel {channel_id}") - except KeyError: - logger.debug(f"Client manager for channel {channel_id} already removed") - - # Clean up profile managers and buffers. Owner workers clean profile_managers - # (and their profile_buffers) via stop_all_output_profiles above. Non-owner - # workers only populate profile_buffers (not profile_managers), and that block - # is skipped for them, so we always clean both here to avoid stale entries on - # the next connect. - self.profile_managers.pop(channel_id, None) - self.profile_buffers.pop(channel_id, None) - - # Clean up Redis keys + # Always clean up local resources before Redis/logging so teardown + # cannot be blocked by connect integrations or DB event writes. + self._cleanup_stopped_channel_local(channel_id) self._clean_redis_keys(channel_id) + self._spawn_channel_stop_event(stop_event_data) return True except Exception as e: @@ -1410,6 +1444,7 @@ class ProxyServer: return False finally: self._stopping_channels.discard(channel_id) + self._stopping_since.pop(channel_id, None) def check_inactive_channels(self): """Check for inactive channels (no clients) and stop them""" @@ -1450,6 +1485,9 @@ class ProxyServer: # Refresh channel registry self.refresh_channel_registry() + # Recover channels whose stop_channel call never returned + self._recover_stuck_channel_stops() + # Create a unified list of all channels we have locally all_local_channels = set(self.stream_managers.keys()) | set(self.client_managers.keys()) @@ -1927,9 +1965,15 @@ class ProxyServer: if not self.redis_client: return - # Refresh registry entries for channels we own + # Refresh registry entries for channels we own and are actively serving. + # Skip channels mid-shutdown. Refreshing their TTL keeps zombie metadata alive. for channel_id in list(self.stream_buffers.keys()): - # Use standard key pattern + if channel_id in self._stopping_channels: + continue + + if not self.am_i_owner(channel_id): + continue + metadata_key = RedisKeys.channel_metadata(channel_id) # Update activity timestamp in metadata only From 9393f72cc120200537709ec6996483cd846db170 Mon Sep 17 00:00:00 2001 From: SergeantPanda Date: Sun, 14 Jun 2026 18:59:59 -0500 Subject: [PATCH 2/9] fix(proxy): enhance channel teardown and client management - Improved handling of channel teardown to prevent client reconnect issues across uWSGI workers, ensuring proper resource cleanup and ownership management. - Added functionality to clear all client entries from Redis for a channel, enhancing client management during shutdown. - Updated logging and response mechanisms to inform clients of channel availability during teardown,. - Enhanced stream manager behavior to ensure upstream connections are properly managed during ownership transitions. --- CHANGELOG.md | 2 + apps/channels/tests/test_ts_proxy_teardown.py | 232 ++++++++++++++ apps/proxy/live_proxy/client_manager.py | 16 + apps/proxy/live_proxy/input/manager.py | 60 +++- apps/proxy/live_proxy/server.py | 294 +++++++++++++----- .../live_proxy/services/channel_service.py | 99 +++++- apps/proxy/live_proxy/views.py | 21 +- 7 files changed, 625 insertions(+), 99 deletions(-) create mode 100644 apps/channels/tests/test_ts_proxy_teardown.py diff --git a/CHANGELOG.md b/CHANGELOG.md index c5aa324a..2622dfc2 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -44,6 +44,8 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Fixed - **Live proxy channels could remain running with no clients after disconnect.** `stop_channel` called `log_system_event('channel_stop')` synchronously before local cleanup and Redis key deletion; Connect integrations or DB event writes on that path could block teardown indefinitely while the cleanup thread kept refreshing metadata TTL for a stale `stream_buffers` entry. Teardown now stops ffmpeg/output managers, releases ownership, removes local buffers and managers, deletes Redis keys, and only then logs the stop event asynchronously. Metadata TTL refresh skips channels mid-shutdown and non-owned channels; a stuck-stop watchdog forces cleanup if `stop_channel` does not return within ~30s. Stream buffers also ignore late `add_chunk()` writes once shutdown begins (`buffer.stopping` set at the start of `stream_manager.stop()`). +- **Client reconnect during channel teardown could wedge the channel across uWSGI workers.** The disconnect path called `proxy_server.stop_channel()` directly, so other workers were not notified and reconnecting clients could attach while ownership was released on the owner worker. The cleanup thread then re-acquired expired ownership and looped on orphaned clients while the upstream connection stayed open. All lifecycle stops now go through coordinated Redis teardown (`channel_stopping` flag, metadata `stopping` state, and `CHANNEL_STOP` pubsub). New stream requests are rejected with `503 Retry-After` during pending shutdown or active teardown; `initialize_channel()` and ownership re-acquisition refuse to proceed in those states; non-owner workers clean local resources only on pubsub; and orphaned-client sweeps force cleanup when teardown is already active. (Fixes #1342) +- **Orphaned upstream threads kept writing Redis after teardown.** Partial cleanup could remove a channel from `stream_managers` while the `stream-{uuid}` OS thread kept running, so orphan metadata sweeps only deleted Redis keys and chunks/metadata were immediately recreated (bare `total_bytes` hash with TTL -1). Stream managers now stop upstream when ownership is lost, orphan cleanup stops local ffmpeg/stream threads even when registry entries are gone (`_live_stream_managers` tracks managers until the thread exits), and forced recovery stops processes before Redis deletion instead of dropping dict entries without calling `stop()`. - **Stale `channel_stream` Redis keys after a channel stopped could skip connection accounting on retune.** On `dev`, `get_stream()` reused any existing `channel_stream` / `stream_profile` assignment without reserving a new slot. If those keys were left behind after a stop, the next tune-in could reach the provider without incrementing Redis counters. `get_stream()` now releases stale assignments when proxy metadata shows the channel is inactive, then reserves fresh slots. - **EPG auto-match reliability fixes.** - Memory could spike to multiple GB on large EPG sources when building a full in-memory catalog before fuzzy matching; single-channel matching now streams rows and bounds ML work to a small candidate set. diff --git a/apps/channels/tests/test_ts_proxy_teardown.py b/apps/channels/tests/test_ts_proxy_teardown.py new file mode 100644 index 00000000..14b4e898 --- /dev/null +++ b/apps/channels/tests/test_ts_proxy_teardown.py @@ -0,0 +1,232 @@ +"""Tests for multi-worker channel teardown coordination.""" +import time +from unittest.mock import MagicMock, patch + +from django.test import TestCase + +from apps.proxy.live_proxy.constants import ChannelMetadataField, ChannelState +from apps.proxy.live_proxy.input.manager import StreamManager +from apps.proxy.live_proxy.redis_keys import RedisKeys +from apps.proxy.live_proxy.server import ProxyServer +from apps.proxy.live_proxy.services.channel_service import ChannelService + + +CHANNEL_ID = "00000000-0000-0000-0000-000000000099" + + +def _mock_proxy_server(redis_client=None): + server = MagicMock() + server.redis_client = redis_client or MagicMock() + return server + + +class ChannelTeardownAvailabilityTests(TestCase): + @patch("apps.proxy.live_proxy.services.channel_service.ProxyServer.get_instance") + def test_teardown_active_when_stopping_key_exists(self, mock_get_instance): + redis = MagicMock() + redis.exists.side_effect = lambda key: key == RedisKeys.channel_stopping(CHANNEL_ID) + mock_get_instance.return_value = _mock_proxy_server(redis) + + self.assertTrue(ChannelService.is_channel_teardown_active(CHANNEL_ID)) + + @patch("apps.proxy.live_proxy.services.channel_service.ProxyServer.get_instance") + def test_teardown_active_when_metadata_state_is_stopping(self, mock_get_instance): + redis = MagicMock() + redis.exists.return_value = False + redis.hget.return_value = ChannelState.STOPPING.encode() + mock_get_instance.return_value = _mock_proxy_server(redis) + + self.assertTrue(ChannelService.is_channel_teardown_active(CHANNEL_ID)) + + @patch("apps.proxy.live_proxy.services.channel_service.ConfigHelper.channel_shutdown_delay") + @patch("apps.proxy.live_proxy.services.channel_service.ProxyServer.get_instance") + def test_shutdown_pending_within_delay_window(self, mock_get_instance, mock_delay): + mock_delay.return_value = 5 + redis = MagicMock() + redis.exists.return_value = False + redis.get.return_value = str(time.time() - 2).encode() + mock_get_instance.return_value = _mock_proxy_server(redis) + + self.assertTrue(ChannelService.is_shutdown_pending(CHANNEL_ID)) + self.assertTrue(ChannelService.is_channel_unavailable_for_new_clients(CHANNEL_ID)) + + @patch("apps.proxy.live_proxy.services.channel_service.ConfigHelper.channel_shutdown_delay") + @patch("apps.proxy.live_proxy.services.channel_service.ProxyServer.get_instance") + def test_shutdown_pending_expired_after_delay(self, mock_get_instance, mock_delay): + mock_delay.return_value = 5 + redis = MagicMock() + redis.exists.return_value = False + redis.get.return_value = str(time.time() - 10).encode() + mock_get_instance.return_value = _mock_proxy_server(redis) + + self.assertFalse(ChannelService.is_shutdown_pending(CHANNEL_ID)) + + +class LocalStreamActivityTests(TestCase): + def _make_server(self): + with patch("apps.proxy.live_proxy.server.RedisClient.get_client", return_value=MagicMock()): + server = ProxyServer() + server.worker_id = "testhost:1" + server.stream_managers = {} + server.stream_buffers = {} + server.client_managers = {} + server.profile_managers = {} + server.profile_buffers = {} + server._live_stream_managers = {} + server._stopping_channels = set() + server.redis_client = MagicMock() + server.stop_all_output_formats = MagicMock() + server.stop_all_output_profiles = MagicMock() + return server + + def test_has_local_stream_activity_from_live_registry(self): + server = self._make_server() + server._live_stream_managers[CHANNEL_ID] = MagicMock() + self.assertTrue(server._has_local_stream_activity(CHANNEL_ID)) + + @patch.object(ProxyServer, "_join_stream_thread") + def test_stop_local_stream_activity_stops_live_manager(self, mock_join): + server = self._make_server() + manager = MagicMock() + server._live_stream_managers[CHANNEL_ID] = manager + + server._stop_local_stream_activity(CHANNEL_ID) + + manager.stop.assert_called_once() + mock_join.assert_called_once_with(CHANNEL_ID) + self.assertNotIn(CHANNEL_ID, server._live_stream_managers) + + +class OrphanMetadataCleanupTests(TestCase): + def _make_server(self): + with patch("apps.proxy.live_proxy.server.RedisClient.get_client", return_value=MagicMock()): + server = ProxyServer() + server.worker_id = "testhost:1" + server.stream_managers = {} + server.stream_buffers = {} + server.client_managers = {} + server.profile_managers = {} + server.profile_buffers = {} + server._live_stream_managers = {} + server._stopping_channels = set() + server.redis_client = MagicMock() + return server + + @patch.object(ProxyServer, "_clean_redis_keys") + @patch.object(ProxyServer, "_stop_local_stream_activity") + @patch.object(ProxyServer, "_has_local_stream_activity", return_value=True) + def test_orphan_metadata_stops_local_processes_before_redis( + self, mock_has_local, mock_stop_local, mock_clean_redis + ): + server = self._make_server() + metadata_key = RedisKeys.channel_metadata(CHANNEL_ID) + server.redis_client.keys.return_value = [metadata_key.encode()] + server.redis_client.hgetall.return_value = { + b"owner": b"", + b"state": b"unknown", + } + server.redis_client.exists.return_value = False + server.redis_client.scard.return_value = 0 + + server._check_orphaned_metadata() + + mock_has_local.assert_called_with(CHANNEL_ID) + mock_stop_local.assert_called_once_with(CHANNEL_ID) + mock_clean_redis.assert_called_once_with(CHANNEL_ID) + + @patch.object(ProxyServer, "_clean_redis_keys") + @patch.object(ProxyServer, "_stop_local_stream_activity") + @patch.object(ProxyServer, "_has_local_stream_activity", return_value=False) + def test_orphan_metadata_remote_channel_only_cleans_redis( + self, mock_has_local, mock_stop_local, mock_clean_redis + ): + server = self._make_server() + metadata_key = RedisKeys.channel_metadata(CHANNEL_ID) + server.redis_client.keys.return_value = [metadata_key.encode()] + server.redis_client.hgetall.return_value = {b"owner": b"", b"state": b"unknown"} + server.redis_client.exists.return_value = False + server.redis_client.scard.return_value = 0 + + server._check_orphaned_metadata() + + mock_stop_local.assert_not_called() + mock_clean_redis.assert_called_once_with(CHANNEL_ID) + + +class OrphanChannelCleanupTests(TestCase): + def _make_server(self): + with patch("apps.proxy.live_proxy.server.RedisClient.get_client", return_value=MagicMock()): + server = ProxyServer() + server.worker_id = "testhost:1" + server.stream_managers = {} + server.stream_buffers = {} + server.client_managers = {} + server.profile_managers = {} + server.profile_buffers = {} + server._live_stream_managers = {} + server._stopping_channels = set() + server.redis_client = MagicMock() + server.get_channel_owner = MagicMock(return_value=None) + return server + + @patch.object(ProxyServer, "_clean_redis_keys") + @patch.object(ProxyServer, "_stop_local_stream_activity") + @patch.object(ProxyServer, "_has_local_stream_activity", return_value=True) + def test_orphan_channel_stops_local_before_redis( + self, mock_has_local, mock_stop_local, mock_clean_redis + ): + server = self._make_server() + metadata_key = RedisKeys.channel_metadata(CHANNEL_ID) + server.redis_client.keys.return_value = [metadata_key.encode()] + server.redis_client.scard.return_value = 0 + + server._check_orphaned_channels() + + mock_stop_local.assert_called_once_with(CHANNEL_ID) + mock_clean_redis.assert_called_once_with(CHANNEL_ID) + + +class StreamManagerOwnershipTests(TestCase): + def test_still_owner_false_when_different_worker(self): + buffer = MagicMock() + buffer.redis_client.get.side_effect = lambda key: ( + None if "stopping" in key else b"worker-b" + ) + buffer.redis_client.exists.return_value = False + manager = StreamManager( + CHANNEL_ID, "http://example/stream", buffer, worker_id="worker-a" + ) + + self.assertFalse(manager._still_owner()) + + def test_still_owner_true_when_owner_lock_expired_but_not_stopping(self): + buffer = MagicMock() + buffer.redis_client.get.return_value = None + buffer.redis_client.exists.return_value = False + manager = StreamManager( + CHANNEL_ID, "http://example/stream", buffer, worker_id="worker-a" + ) + + self.assertTrue(manager._still_owner()) + + def test_still_owner_false_when_channel_stopping_key_set(self): + buffer = MagicMock() + buffer.redis_client.exists.return_value = True + manager = StreamManager( + CHANNEL_ID, "http://example/stream", buffer, worker_id="worker-a" + ) + + self.assertFalse(manager._still_owner()) + + def test_update_bytes_skipped_after_ownership_lost(self): + buffer = MagicMock() + buffer.redis_client.get.return_value = b"other-worker" + buffer.redis_client.exists.return_value = False + manager = StreamManager( + CHANNEL_ID, "http://example/stream", buffer, worker_id="worker-a" + ) + manager.bytes_processed = 1000 + + manager._update_bytes_processed(500) + + buffer.redis_client.hincrby.assert_not_called() diff --git a/apps/proxy/live_proxy/client_manager.py b/apps/proxy/live_proxy/client_manager.py index 3ab1861c..3771d55c 100644 --- a/apps/proxy/live_proxy/client_manager.py +++ b/apps/proxy/live_proxy/client_manager.py @@ -442,3 +442,19 @@ class ClientManager: ) return stale_ids + + @staticmethod + def clear_all_clients(redis_client, channel_id): + """Remove every client entry from Redis for a channel.""" + client_set_key = RedisKeys.clients(channel_id) + client_ids = redis_client.smembers(client_set_key) + if not client_ids: + return 0 + + pipe = redis_client.pipeline(transaction=False) + for cid in client_ids: + cid_str = cid.decode() if isinstance(cid, bytes) else cid + pipe.delete(RedisKeys.client_metadata(channel_id, cid_str)) + pipe.delete(client_set_key) + pipe.execute() + return len(client_ids) diff --git a/apps/proxy/live_proxy/input/manager.py b/apps/proxy/live_proxy/input/manager.py index b560923b..06b12644 100644 --- a/apps/proxy/live_proxy/input/manager.py +++ b/apps/proxy/live_proxy/input/manager.py @@ -182,6 +182,47 @@ class StreamManager: logger.warning(f"Timeout waiting for existing processes to close for channel {self.channel_id} after {timeout}s") return False + def _still_owner(self): + """Return True while this worker should keep the upstream connection open.""" + if self.stopping or self.stop_requested: + return False + + if not self.worker_id: + return True + + redis_client = getattr(self.buffer, 'redis_client', None) + if not redis_client: + return True + + try: + stop_key = RedisKeys.channel_stopping(self.channel_id) + if redis_client.exists(stop_key): + return False + + owner_key = RedisKeys.channel_owner(self.channel_id) + current_owner = redis_client.get(owner_key) + if not current_owner: + # Owner lock TTL may lapse briefly between cleanup-thread renewals. + # Keep running unless coordinated teardown has started (checked above). + return True + if isinstance(current_owner, bytes): + current_owner = current_owner.decode() + return current_owner == self.worker_id + except Exception as e: + logger.debug(f"Ownership check failed for channel {self.channel_id}: {e}") + return False + + def _ensure_owner_or_stop(self): + if self._still_owner(): + return True + + logger.warning( + f"Stream manager for channel {self.channel_id} lost ownership " + f"(worker {self.worker_id}) - stopping upstream" + ) + self.stop() + return False + def run(self): """Main execution loop using HTTP streaming with improved connection handling and stream switching""" # Add a stop flag to the class properties @@ -203,6 +244,8 @@ class StreamManager: # Main stream switching loop - we'll try different streams if needed while self.running and stream_switch_attempts <= max_stream_switches: close_old_connections() + if not self._ensure_owner_or_stop(): + break # Check for stuck switching state if self.url_switching and time.time() - self.url_switch_start_time > self.url_switch_timeout: logger.warning(f"URL switching state appears stuck for channel {self.channel_id} " @@ -255,6 +298,8 @@ class StreamManager: continue # Connection retry loop for current URL while self.running and self.retry_count < self.max_retries and not url_failed and not self.needs_stream_switch: + if not self._ensure_owner_or_stop(): + break logger.info(f"Connection attempt {self.retry_count + 1}/{self.max_retries} for URL: {self.url} for channel {self.channel_id}") @@ -382,6 +427,12 @@ class StreamManager: except Exception as e: logger.error(f"Stream error: {e}", exc_info=True) finally: + try: + from ..server import ProxyServer + ProxyServer.get_instance()._live_stream_managers.pop(self.channel_id, None) + except Exception: + pass + # Enhanced cleanup in the finally block self.connected = False @@ -1020,6 +1071,9 @@ class StreamManager: def _update_bytes_processed(self, chunk_size): """Update the total bytes processed in Redis metadata""" + if not self._still_owner(): + return + try: # Update local counter self.bytes_processed += chunk_size @@ -1584,6 +1638,10 @@ class StreamManager: self.connected = False return False + if not self._still_owner(): + self.stop() + return False + # Track chunk size before adding to buffer chunk_size = len(chunk) self._update_bytes_processed(chunk_size) @@ -1592,7 +1650,7 @@ class StreamManager: success = self.buffer.add_chunk(chunk) # Update last data timestamp in Redis if successful - if success and hasattr(self.buffer, 'redis_client') and self.buffer.redis_client: + if success and self._still_owner() and hasattr(self.buffer, 'redis_client') and self.buffer.redis_client: last_data_key = RedisKeys.last_data(self.buffer.channel_id) self.buffer.redis_client.set(last_data_key, str(time.time()), ex=60) diff --git a/apps/proxy/live_proxy/server.py b/apps/proxy/live_proxy/server.py index 7145fcd4..a348c876 100644 --- a/apps/proxy/live_proxy/server.py +++ b/apps/proxy/live_proxy/server.py @@ -72,6 +72,8 @@ class ProxyServer: self._channel_names = {} self._stopping_channels = set() # channels with an active stop_channel call in progress self._stopping_since = {} # channel_id -> time.time() when stop_channel began + # Managers kept until the stream OS thread exits (may outlive stream_managers dict) + self._live_stream_managers = {} # Generate a unique worker ID pid = os.getpid() @@ -295,22 +297,36 @@ class ProxyServer: json.dumps(switch_result) ) elif event_type == EventType.CHANNEL_STOP: - logger.info(f"Received {EventType.CHANNEL_STOP} event for channel {channel_id}") - # First mark channel as stopping in Redis - if self.redis_client: - # Set stopping state in metadata - metadata_key = RedisKeys.channel_metadata(channel_id) - if self.redis_client.exists(metadata_key): - self.redis_client.hset(metadata_key, mapping={ - "state": ChannelState.STOPPING, - "state_changed_at": str(time.time()) - }) + requester_worker_id = data.get("requester_worker_id") + logger.info( + f"Received {EventType.CHANNEL_STOP} event for channel {channel_id} " + f"from worker {requester_worker_id}" + ) - # If we have local resources for this channel, clean them up - if channel_id in self.stream_buffers or channel_id in self.client_managers: - # Use existing stop_channel method - logger.info(f"Stopping local resources for channel {channel_id}") + # Initiating worker already runs local stop_channel() + if requester_worker_id and requester_worker_id == self.worker_id: + logger.debug( + f"Ignoring {EventType.CHANNEL_STOP} for {channel_id}; " + f"this worker initiated teardown" + ) + elif ( + channel_id in self.stream_managers + or channel_id in self._live_stream_managers + ): + logger.info( + f"Owner worker stopping local upstream for channel {channel_id}" + ) self.stop_channel(channel_id) + elif ( + channel_id in self.stream_buffers + or channel_id in self.client_managers + or channel_id in self.profile_managers + or channel_id in self.output_managers + ): + logger.info( + f"Non-owner worker cleaning local resources for channel {channel_id}" + ) + self._cleanup_local_resources(channel_id) # Acknowledge stop by publishing a response stop_response = { @@ -491,8 +507,16 @@ class ProxyServer: current = self.redis_client.get(lock_key) if current is None: - # Key expired — re-acquire if we have the stream_manager + # Key expired, re-acquire if we have the stream_manager, but never + # during coordinated teardown (multi-worker reconnect-during-stop race). if channel_id in self.stream_managers: + if self._channel_unavailable_for_new_clients(channel_id): + logger.info( + f"Refusing ownership re-acquisition for {channel_id}; " + f"teardown or pending shutdown active" + ) + return False + acquired = self.redis_client.set(lock_key, self.worker_id, nx=True, ex=ttl) if acquired: logger.warning(f"Re-acquired expired ownership for channel {channel_id}") @@ -515,6 +539,13 @@ class ProxyServer: def initialize_channel(self, url, channel_id, user_agent=None, transcode=False, stream_id=None): """Initialize a channel without redundant active key""" try: + if self._channel_unavailable_for_new_clients(channel_id): + logger.warning( + f"Refusing to initialize channel {channel_id}; " + f"teardown or pending shutdown active" + ) + return False + if self.redis_client: metadata_key = RedisKeys.channel_metadata(channel_id) if self.redis_client.exists(metadata_key): @@ -721,6 +752,7 @@ class ProxyServer: self.client_managers[channel_id] = client_manager # Start stream manager thread only for the owner + self._live_stream_managers[channel_id] = stream_manager thread = threading.Thread(target=stream_manager.run, daemon=True) thread.name = f"stream-{channel_id}" thread.start() @@ -970,10 +1002,34 @@ class ProxyServer: self.redis_client.delete(disconnect_key) return - self.stop_channel(channel_id) + self._coordinated_stop_channel(channel_id) except Exception as e: logger.error(f"Error handling client disconnect for channel {channel_id}: {e}") + def _channel_unavailable_for_new_clients(self, channel_id): + """True when new clients or ownership re-acquisition should be refused.""" + from .services.channel_service import ChannelService + return ChannelService.is_channel_unavailable_for_new_clients(channel_id) + + def _channel_teardown_active(self, channel_id): + """True when a coordinated stop is in progress (Redis-visible to all workers).""" + from .services.channel_service import ChannelService + return ChannelService.is_channel_teardown_active(channel_id) + + def _coordinated_stop_channel(self, channel_id): + """Stop a channel with Redis markers and pubsub visible to all uWSGI workers.""" + from .services.channel_service import ChannelService + return ChannelService.stop_channel(channel_id) + + def _force_clear_channel_clients(self, channel_id): + """Remove all client entries from Redis for a wedged channel.""" + if not self.redis_client: + return 0 + removed = ClientManager.clear_all_clients(self.redis_client, channel_id) + if removed: + logger.warning(f"Force-cleared {removed} client(s) from channel {channel_id}") + return removed + # ------------------------------------------------------------------ # Output format lifecycle # ------------------------------------------------------------------ @@ -1308,40 +1364,90 @@ class ProxyServer: gevent.spawn(_log_stop) - def _cleanup_stopped_channel_local(self, channel_id): - """Remove local managers/buffers for a channel that is shutting down.""" + def _get_stream_thread(self, channel_id): + thread_name = f"stream-{channel_id}" + for thread in threading.enumerate(): + if thread.name == thread_name: + return thread + return None + + def _has_local_stream_activity(self, channel_id): if channel_id in self.stream_managers: - del self.stream_managers[channel_id] - logger.info(f"Removed stream manager for channel {channel_id}") + return True + if channel_id in self._live_stream_managers: + return True + if channel_id in self.stream_buffers: + return True + if channel_id in self.client_managers: + return True + thread = self._get_stream_thread(channel_id) + return thread is not None and thread.is_alive() + + def _join_stream_thread(self, channel_id, timeout=2.0): + thread = self._get_stream_thread(channel_id) + if thread and thread.is_alive(): + logger.info(f"Waiting for stream thread to terminate for channel {channel_id}") + try: + thread.join(timeout=timeout) + if thread.is_alive(): + logger.warning( + f"Stream thread for channel {channel_id} did not terminate within {timeout}s" + ) + except RuntimeError: + logger.debug(f"Could not join stream thread for channel {channel_id}") + + def _resolve_stream_manager(self, channel_id): + manager = self.stream_managers.pop(channel_id, None) + if manager is None: + manager = self._live_stream_managers.pop(channel_id, None) + return manager + + def _stop_local_stream_activity(self, channel_id): + """Stop local ffmpeg/stream threads regardless of registry state.""" + stream_manager = self._resolve_stream_manager(channel_id) + if stream_manager is not None: + if hasattr(stream_manager, 'stop'): + try: + stream_manager.stop() + except Exception as e: + logger.error(f"Error stopping stream manager for channel {channel_id}: {e}") + logger.info(f"Stopped stream manager for channel {channel_id}") + elif self._get_stream_thread(channel_id): + logger.warning( + f"Found live stream thread for channel {channel_id} without a manager reference" + ) + if channel_id in self.stream_buffers: + self.stream_buffers[channel_id].stopping = True + + self._join_stream_thread(channel_id) if channel_id in self.stream_buffers: - buffer = self.stream_buffers[channel_id] + buffer = self.stream_buffers.pop(channel_id) if hasattr(buffer, 'stop'): try: buffer.stop() - logger.debug(f"Buffer for channel {channel_id} properly stopped") except Exception as e: - logger.error(f"Error stopping buffer: {e}") - - try: - if channel_id in self.stream_buffers: - del self.stream_buffers[channel_id] - logger.info(f"Removed stream buffer for channel {channel_id}") - except KeyError: - logger.debug(f"Buffer for channel {channel_id} already removed") + logger.error(f"Error stopping buffer for channel {channel_id}: {e}") + logger.info(f"Removed stream buffer for channel {channel_id}") if channel_id in self.client_managers: try: - client_manager = self.client_managers[channel_id] + client_manager = self.client_managers.pop(channel_id) if hasattr(client_manager, 'stop'): client_manager.stop() - del self.client_managers[channel_id] logger.info(f"Removed client manager for channel {channel_id}") except KeyError: logger.debug(f"Client manager for channel {channel_id} already removed") + self.stop_all_output_formats(channel_id) + self.stop_all_output_profiles(channel_id) self.profile_managers.pop(channel_id, None) self.profile_buffers.pop(channel_id, None) + self._live_stream_managers.pop(channel_id, None) + + def _cleanup_stopped_channel_local(self, channel_id): + """Remove local managers/buffers for a channel that is shutting down.""" + self._stop_local_stream_activity(channel_id) def _recover_stuck_channel_stops(self): """Force cleanup when stop_channel never finishes (e.g. blocked on logging).""" @@ -1363,14 +1469,11 @@ class ProxyServer: self._stopping_channels.discard(channel_id) self._stopping_since.pop(channel_id, None) - if (channel_id in self.stream_buffers - or channel_id in self.client_managers - or channel_id in self.stream_managers): - try: - self._cleanup_stopped_channel_local(channel_id) - self._clean_redis_keys(channel_id) - except Exception as e: - logger.error(f"Error during forced cleanup for channel {channel_id}: {e}") + try: + self._stop_local_stream_activity(channel_id) + self._clean_redis_keys(channel_id) + except Exception as e: + logger.error(f"Error during forced cleanup for channel {channel_id}: {e}") def stop_channel(self, channel_id): """Stop a channel with proper ownership handling""" @@ -1386,7 +1489,10 @@ class ProxyServer: # First set a stopping key that clients will check if self.redis_client: stop_key = RedisKeys.channel_stopping(channel_id) - self.redis_client.setex(stop_key, 10, "true") + if self.redis_client.exists(stop_key): + self.redis_client.expire(stop_key, 60) + else: + self.redis_client.setex(stop_key, 60, "true") # Only stop the actual stream manager if we're the owner if self.am_i_owner(channel_id): @@ -1456,7 +1562,7 @@ class ProxyServer: for channel_id in channels_to_stop: logger.info(f"Auto-stopping inactive channel {channel_id}") - self.stop_channel(channel_id) + self._coordinated_stop_channel(channel_id) def _cleanup_channel(self, channel_id: str) -> None: """Remove channel resources""" @@ -1467,7 +1573,7 @@ class ProxyServer: def shutdown(self) -> None: """Stop all channels and cleanup""" for channel_id in list(self.stream_managers.keys()): - self.stop_channel(channel_id) + self._coordinated_stop_channel(channel_id) def _start_cleanup_thread(self): """Start background thread to maintain ownership and clean up resources""" @@ -1577,7 +1683,7 @@ class ProxyServer: f"Channel {channel_id} in {channel_state} state with 0 clients for {time_since_ready:.1f}s " f"(after reaching ready, shutdown_delay: {shutdown_delay}s) - stopping channel" ) - self.stop_channel(channel_id) + self._coordinated_stop_channel(channel_id) continue else: # Never reached ready - use grace_period timeout @@ -1589,7 +1695,7 @@ class ProxyServer: f"Channel {channel_id} stuck in {channel_state} state for {time_since_start:.1f}s " f"with no clients (timeout: {connecting_timeout}s) - stopping channel due to upstream issues" ) - self.stop_channel(channel_id) + self._coordinated_stop_channel(channel_id) continue elif connection_ready_time: # We have clients now, but check grace period for state transition @@ -1643,7 +1749,7 @@ class ProxyServer: elif current_time - disconnect_time > ConfigHelper.channel_shutdown_delay(): # We've had no clients for the shutdown delay period logger.warning(f"No clients for {current_time - disconnect_time:.1f}s, stopping channel {channel_id}") - self.stop_channel(channel_id) + self._coordinated_stop_channel(channel_id) else: # Still in shutdown delay period logger.debug(f"Channel {channel_id} shutdown timer: " @@ -1663,6 +1769,15 @@ class ProxyServer: # don't fight the shutdown by trying to re-acquire. if channel_id in self._stopping_channels: continue + + if self._channel_unavailable_for_new_clients(channel_id): + logger.info( + f"Channel {channel_id} teardown active with local stream_manager; " + f"finishing stop instead of re-acquiring ownership" + ) + self.stop_channel(channel_id) + continue + logger.warning( f"Ownership gap for {channel_id}: this worker has stream_manager " f"but am_i_owner returned False. Attempting re-acquisition." @@ -1815,13 +1930,12 @@ class ProxyServer: # Orphaned channel with no clients - clean it up logger.info(f"Cleaning up orphaned channel {channel_id}") - # If we have it locally, stop it properly to clean up processes - if channel_id in self.stream_managers or channel_id in self.client_managers: - logger.info(f"Orphaned channel {channel_id} is local - calling stop_channel") - self.stop_channel(channel_id) - else: - # Just clean up Redis keys for remote channels - self._clean_redis_keys(channel_id) + if self._has_local_stream_activity(channel_id): + logger.info( + f"Orphaned channel {channel_id} has local stream activity - stopping processes" + ) + self._stop_local_stream_activity(channel_id) + self._clean_redis_keys(channel_id) except Exception as e: logger.error(f"Error processing channel key {key}: {e}") @@ -1850,11 +1964,9 @@ class ProxyServer: if not metadata: # Empty metadata - clean it up logger.warning(f"Found empty metadata for channel {channel_id} - cleaning up") - # If we have it locally, stop it properly - if channel_id in self.stream_managers or channel_id in self.client_managers: - self.stop_channel(channel_id) - else: - self._clean_redis_keys(channel_id) + if self._has_local_stream_activity(channel_id): + self._stop_local_stream_activity(channel_id) + self._clean_redis_keys(channel_id) continue # Get owner @@ -1875,13 +1987,12 @@ class ProxyServer: state = metadata.get('state', 'unknown') logger.warning(f"Found orphaned metadata for channel {channel_id} (state: {state}, owner: {owner}, clients: {client_count}) - cleaning up") - # If we have it locally, stop it properly to clean up transcode/proxy processes - if channel_id in self.stream_managers or channel_id in self.client_managers: - logger.info(f"Channel {channel_id} is local - calling stop_channel to clean up processes") - self.stop_channel(channel_id) - else: - # Just clean up Redis keys for remote channels - self._clean_redis_keys(channel_id) + if self._has_local_stream_activity(channel_id): + logger.info( + f"Channel {channel_id} has local stream activity - stopping processes" + ) + self._stop_local_stream_activity(channel_id) + self._clean_redis_keys(channel_id) elif not owner_alive and client_count > 0: # SCARD may include ghost entries from a dead worker's # expired metadata hashes. Validate before deciding. @@ -1897,16 +2008,25 @@ class ProxyServer: f"owner: {owner}) had {client_count} ghost client(s) " f"- cleaning up" ) - if channel_id in self.stream_managers or channel_id in self.client_managers: - self.stop_channel(channel_id) - else: - self._clean_redis_keys(channel_id) + if self._has_local_stream_activity(channel_id): + self._stop_local_stream_activity(channel_id) + self._clean_redis_keys(channel_id) else: - logger.warning( - f"Orphaned channel {channel_id} still has " - f"{real_count} live client(s) after ghost removal " - f"- may need ownership takeover" - ) + if self._channel_teardown_active(channel_id): + logger.warning( + f"Orphaned channel {channel_id} still has " + f"{real_count} client(s) during teardown; forcing cleanup" + ) + self._force_clear_channel_clients(channel_id) + if self._has_local_stream_activity(channel_id): + self._stop_local_stream_activity(channel_id) + self._clean_redis_keys(channel_id) + else: + logger.warning( + f"Orphaned channel {channel_id} still has " + f"{real_count} live client(s) after ghost removal " + f"- may need ownership takeover" + ) except Exception as e: logger.error(f"Error processing metadata key {key}: {e}", exc_info=True) @@ -2023,14 +2143,28 @@ class ProxyServer: def _cleanup_local_resources(self, channel_id): """Clean up local resources for a channel without affecting Redis keys""" try: - if channel_id in self.stream_managers: - if hasattr(self.stream_managers[channel_id], 'stop'): - self.stream_managers[channel_id].stop() - del self.stream_managers[channel_id] - logger.info(f"Non-owner cleanup: Removed stream manager for channel {channel_id}") + stream_manager = self._resolve_stream_manager(channel_id) + if stream_manager is not None: + if hasattr(stream_manager, 'stop'): + stream_manager.stop() + logger.info(f"Non-owner cleanup: Stopped stream manager for channel {channel_id}") + elif self._get_stream_thread(channel_id): + logger.warning( + f"Non-owner cleanup: Found orphaned stream thread for channel {channel_id}" + ) + if channel_id in self.stream_buffers: + self.stream_buffers[channel_id].stopping = True + + self._join_stream_thread(channel_id) + self._live_stream_managers.pop(channel_id, None) if channel_id in self.stream_buffers: - del self.stream_buffers[channel_id] + buffer = self.stream_buffers.pop(channel_id) + if hasattr(buffer, 'stop'): + try: + buffer.stop() + except Exception as e: + logger.error(f"Non-owner cleanup: Error stopping buffer for {channel_id}: {e}") logger.info(f"Non-owner cleanup: Removed stream buffer for channel {channel_id}") if channel_id in self.client_managers: diff --git a/apps/proxy/live_proxy/services/channel_service.py b/apps/proxy/live_proxy/services/channel_service.py index 8cc4a030..6671e444 100644 --- a/apps/proxy/live_proxy/services/channel_service.py +++ b/apps/proxy/live_proxy/services/channel_service.py @@ -10,6 +10,7 @@ from apps.channels.models import Channel, Stream from ..server import ProxyServer from ..redis_keys import RedisKeys from ..constants import EventType, ChannelState, ChannelMetadataField +from ..config_helper import ConfigHelper from ..url_utils import get_stream_info_for_switch from core.utils import log_system_event from .log_parsers import LogParserFactory @@ -19,6 +20,82 @@ logger = logging.getLogger("live_proxy") class ChannelService: """Service class for channel operations""" + @staticmethod + def mark_channel_stopping(channel_id, broadcast=False): + """Mark a channel as stopping in Redis so all uWSGI workers converge on teardown.""" + proxy_server = ProxyServer.get_instance() + if not proxy_server.redis_client: + return False + + try: + metadata_key = RedisKeys.channel_metadata(channel_id) + if proxy_server.redis_client.exists(metadata_key): + proxy_server.redis_client.hset(metadata_key, mapping={ + ChannelMetadataField.STATE: ChannelState.STOPPING, + ChannelMetadataField.STATE_CHANGED_AT: str(time.time()), + }) + + stop_key = RedisKeys.channel_stopping(channel_id) + proxy_server.redis_client.setex(stop_key, 60, "true") + + if broadcast: + ChannelService._publish_channel_stop_event(channel_id) + return True + except Exception as e: + logger.error(f"Error marking channel {channel_id} as stopping: {e}") + return False + + @staticmethod + def is_shutdown_pending(channel_id): + """True while the post-disconnect shutdown delay has started but stop has not run.""" + proxy_server = ProxyServer.get_instance() + if not proxy_server.redis_client: + return False + + delay = ConfigHelper.channel_shutdown_delay() + if delay <= 0: + return False + + disconnect_value = proxy_server.redis_client.get( + RedisKeys.last_client_disconnect(channel_id) + ) + if not disconnect_value: + return False + + try: + disconnect_time = float(disconnect_value) + except (ValueError, TypeError): + return False + + return (time.time() - disconnect_time) < delay + + @staticmethod + def is_channel_teardown_active(channel_id): + """True when a coordinated channel stop is in progress (visible to all workers).""" + proxy_server = ProxyServer.get_instance() + if not proxy_server.redis_client: + return False + + if proxy_server.redis_client.exists(RedisKeys.channel_stopping(channel_id)): + return True + + metadata_key = RedisKeys.channel_metadata(channel_id) + state = proxy_server.redis_client.hget(metadata_key, ChannelMetadataField.STATE) + if state: + state_str = state.decode() if isinstance(state, bytes) else state + if state_str == ChannelState.STOPPING: + return True + + return False + + @staticmethod + def is_channel_unavailable_for_new_clients(channel_id): + """Reject new stream requests while teardown is active or shutdown is pending.""" + return ( + ChannelService.is_channel_teardown_active(channel_id) + or ChannelService.is_shutdown_pending(channel_id) + ) + @staticmethod def initialize_channel(channel_id, stream_url, user_agent, transcode=False, stream_profile_value=None, stream_id=None, m3u_profile_id=None, channel_name=None, stream_name=None): """ @@ -39,6 +116,7 @@ class ChannelService: bool: Success status """ proxy_server = ProxyServer.get_instance() + if stream_id and proxy_server.redis_client: metadata_key = RedisKeys.channel_metadata(channel_id) # Check if metadata already exists @@ -263,29 +341,16 @@ class ChannelService: try: metadata = proxy_server.redis_client.hgetall(metadata_key) if metadata and 'state' in metadata: - state = metadata['state'] - channel_info = {"state": state} - - # Immediately mark as stopping in metadata so clients detect it faster - proxy_server.redis_client.hset(metadata_key, ChannelMetadataField.STATE, ChannelState.STOPPING) - proxy_server.redis_client.hset(metadata_key, ChannelMetadataField.STATE_CHANGED_AT, str(time.time())) + channel_info = {"state": metadata['state']} except Exception as e: logger.error(f"Error fetching channel state: {e}") - # Set stopping flag with higher TTL to ensure it persists + # Mark stopping in Redis and notify all workers before local teardown if proxy_server.redis_client: - stop_key = RedisKeys.channel_stopping(channel_id) - proxy_server.redis_client.setex(stop_key, 60, "true") # Higher TTL of 60 seconds - logger.info(f"Set channel stopping flag with 60s TTL for channel {channel_id}") - - # Broadcast stop event to all workers via PubSub - if proxy_server.redis_client: - ChannelService._publish_channel_stop_event(channel_id) - - # Also stop locally to ensure this worker cleans up right away + ChannelService.mark_channel_stopping(channel_id, broadcast=True) + logger.info(f"Marked channel {channel_id} stopping and broadcast stop to all workers") local_result = proxy_server.stop_channel(channel_id) else: - # No Redis, just stop locally local_result = proxy_server.stop_channel(channel_id) # Release the channel in the channel model if applicable diff --git a/apps/proxy/live_proxy/views.py b/apps/proxy/live_proxy/views.py index d60d9703..b547cefd 100644 --- a/apps/proxy/live_proxy/views.py +++ b/apps/proxy/live_proxy/views.py @@ -43,6 +43,15 @@ from apps.proxy.utils import check_user_stream_limits logger = get_logger() +def _channel_stopping_response(): + response = JsonResponse( + {"error": "Channel is stopping, retry shortly"}, + status=503, + ) + response["Retry-After"] = "1" + return response + + def _resolve_output_format(user, force=None, request=None): """Return the output format string to use for this client.""" _FORMAT_ALIASES = { @@ -123,6 +132,12 @@ def stream_ts(request, channel_id, user=None, force_output_format=None): status=429 ) + if ChannelService.is_channel_unavailable_for_new_clients(channel_id): + logger.info( + f"[{client_id}] Channel {channel_id} unavailable. Teardown or pending shutdown" + ) + return _channel_stopping_response() + # Check if we need to reinitialize the channel needs_initialization = True channel_state = None @@ -144,7 +159,6 @@ def stream_ts(request, channel_id, user=None, force_output_format=None): ChannelState.BUFFERING, ChannelState.INITIALIZING, ChannelState.CONNECTING, - ChannelState.STOPPING, ]: needs_initialization = False logger.debug( @@ -160,6 +174,11 @@ def stream_ts(request, channel_id, user=None, force_output_format=None): logger.debug( f"[{client_id}] Channel {channel_id} is still initializing, client will wait" ) + elif channel_state == ChannelState.STOPPING: + logger.info( + f"[{client_id}] Channel {channel_id} is stopping, rejecting request" + ) + return _channel_stopping_response() # Terminal states - channel needs cleanup before reinitialization elif channel_state in [ ChannelState.ERROR, From 67239d921d2c51190caa7b54f123d1562fc04201 Mon Sep 17 00:00:00 2001 From: SergeantPanda Date: Sun, 14 Jun 2026 21:41:50 -0500 Subject: [PATCH 3/9] fix(proxy): enhance channel teardown and client management - Improved channel teardown process to prevent lingering upstream connections and ensure proper resource cleanup. - Enhanced client management by implementing checks for ghost clients and ensuring accurate client disconnection handling. - Updated logging to provide clearer insights during channel initialization and teardown, including handling of unavailable channels. - Refined stream manager behavior to manage ownership transitions more effectively and prevent blocking during shutdown. --- CHANGELOG.md | 4 +- apps/channels/models.py | 28 +- apps/channels/tests/test_ts_proxy_teardown.py | 452 +++++++++++++++++- apps/proxy/live_proxy/client_manager.py | 116 +++-- apps/proxy/live_proxy/input/buffer.py | 42 +- apps/proxy/live_proxy/input/manager.py | 160 +++++-- apps/proxy/live_proxy/output/ts/generator.py | 107 ++++- apps/proxy/live_proxy/server.py | 279 ++++++----- .../live_proxy/services/channel_service.py | 33 +- apps/proxy/live_proxy/views.py | 26 + 10 files changed, 945 insertions(+), 302 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 2622dfc2..4de12ded 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -43,9 +43,11 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Fixed -- **Live proxy channels could remain running with no clients after disconnect.** `stop_channel` called `log_system_event('channel_stop')` synchronously before local cleanup and Redis key deletion; Connect integrations or DB event writes on that path could block teardown indefinitely while the cleanup thread kept refreshing metadata TTL for a stale `stream_buffers` entry. Teardown now stops ffmpeg/output managers, releases ownership, removes local buffers and managers, deletes Redis keys, and only then logs the stop event asynchronously. Metadata TTL refresh skips channels mid-shutdown and non-owned channels; a stuck-stop watchdog forces cleanup if `stop_channel` does not return within ~30s. Stream buffers also ignore late `add_chunk()` writes once shutdown begins (`buffer.stopping` set at the start of `stream_manager.stop()`). +- **Live proxy channels could remain running with no clients after disconnect.** `stop_channel` called `log_system_event('channel_stop')` synchronously before local cleanup and Redis key deletion; Connect integrations or DB event writes on that path could block teardown indefinitely while the cleanup thread kept refreshing metadata TTL for a stale `stream_buffers` entry. Teardown now signals shutdown (`buffer.stopping`), runs model `release_stream()` and Redis key deletion, releases ownership, stops ffmpeg/output managers and local buffers, and only then logs the stop event asynchronously. Metadata TTL refresh skips channels mid-shutdown and non-owned channels; a stuck-stop watchdog forces cleanup if `stop_channel` does not return within ~10s (or 2× `channel_shutdown_delay`, whichever is greater). Stream buffers ignore late `add_chunk()` writes once shutdown begins (`buffer.stopping` set at teardown start). - **Client reconnect during channel teardown could wedge the channel across uWSGI workers.** The disconnect path called `proxy_server.stop_channel()` directly, so other workers were not notified and reconnecting clients could attach while ownership was released on the owner worker. The cleanup thread then re-acquired expired ownership and looped on orphaned clients while the upstream connection stayed open. All lifecycle stops now go through coordinated Redis teardown (`channel_stopping` flag, metadata `stopping` state, and `CHANNEL_STOP` pubsub). New stream requests are rejected with `503 Retry-After` during pending shutdown or active teardown; `initialize_channel()` and ownership re-acquisition refuse to proceed in those states; non-owner workers clean local resources only on pubsub; and orphaned-client sweeps force cleanup when teardown is already active. (Fixes #1342) - **Orphaned upstream threads kept writing Redis after teardown.** Partial cleanup could remove a channel from `stream_managers` while the `stream-{uuid}` OS thread kept running, so orphan metadata sweeps only deleted Redis keys and chunks/metadata were immediately recreated (bare `total_bytes` hash with TTL -1). Stream managers now stop upstream when ownership is lost, orphan cleanup stops local ffmpeg/stream threads even when registry entries are gone (`_live_stream_managers` tracks managers until the thread exits), and forced recovery stops processes before Redis deletion instead of dropping dict entries without calling `stop()`. +- **Rapid channel switching could leave bare `buffer:index` keys in Redis.** `buffer.stop()` flushed a final partial chunk via `INCR` during teardown, creating a persistent index key (TTL -1) after chunk keys expired; under load overlapping disconnect and cleanup-thread stops could race on `_stop_local_stream_activity`, blocking on ffmpeg stderr join before `_clean_redis_keys` ever ran. Teardown no longer writes to Redis from `buffer.stop()`, disconnect uses coordinated stop only (no duplicate upstream stop), model `release_stream()` runs before Redis keys are scanned/deleted (so `profile_connections` counters are not left stuck), ownership is released after Redis cleanup but before the blocking local ffmpeg stop, and a `finally` block guarantees Redis cleanup if local teardown raises. +- **Zombie ffmpeg could survive owner-lock expiry and orphan Redis sweeps.** When the 30s owner lock lapsed under single-worker load, disconnect handling treated the worker as non-owner so coordinated stop never ran, while ffmpeg kept writing and the orphan sweeper only deleted Redis keys (recreating them immediately). Disconnect now re-acquires ownership when local upstream is still active, stops locally when the last client leaves without a lock, orphan cleanup stops local ffmpeg before Redis deletion via `_has_local_upstream_activity`, re-init stops lingering upstream before starting a duplicate thread, and `is_channel_teardown_active` includes channels mid-`stop_channel` on this worker so rapid reconnect gets 503 during teardown. - **Stale `channel_stream` Redis keys after a channel stopped could skip connection accounting on retune.** On `dev`, `get_stream()` reused any existing `channel_stream` / `stream_profile` assignment without reserving a new slot. If those keys were left behind after a stop, the next tune-in could reach the provider without incrementing Redis counters. `get_stream()` now releases stale assignments when proxy metadata shows the channel is inactive, then reserves fresh slots. - **EPG auto-match reliability fixes.** - Memory could spike to multiple GB on large EPG sources when building a full in-memory catalog before fuzzy matching; single-channel matching now streams rows and bounds ML work to a small candidate set. diff --git a/apps/channels/models.py b/apps/channels/models.py index f900a817..ef1d0cff 100644 --- a/apps/channels/models.py +++ b/apps/channels/models.py @@ -626,11 +626,11 @@ class Channel(models.Model): def _release_stale_stream_assignment(self, redis_client, stream_id: int) -> None: """Release pool counters and remove stale channel/stream assignment keys.""" + profile_id = None profile_id_bytes = redis_client.get(f"stream_profile:{stream_id}") if profile_id_bytes: try: profile_id = int(profile_id_bytes) - release_profile_slot(profile_id, redis_client) except (ValueError, TypeError): logger.debug( "Invalid profile ID for stale assignment on stream %s: %s", @@ -638,6 +638,32 @@ class Channel(models.Model): profile_id_bytes, ) + if profile_id is None: + metadata_key = RedisKeys.channel_metadata(str(self.uuid)) + meta_profile_id = redis_client.hget( + metadata_key, ChannelMetadataField.M3U_PROFILE + ) + if meta_profile_id: + try: + profile_id = int(meta_profile_id) + except (ValueError, TypeError): + logger.debug( + "Invalid profile ID in metadata for stale assignment on " + "channel %s: %s", + self.uuid, + meta_profile_id, + ) + + if profile_id is not None: + release_profile_slot(profile_id, redis_client) + else: + logger.warning( + "Channel %s: releasing stale stream %s assignment without profile " + "info - profile_connections may leak", + self.uuid, + stream_id, + ) + redis_client.delete(f"channel_stream:{self.id}") redis_client.delete(f"stream_profile:{stream_id}") diff --git a/apps/channels/tests/test_ts_proxy_teardown.py b/apps/channels/tests/test_ts_proxy_teardown.py index 14b4e898..3bc92f18 100644 --- a/apps/channels/tests/test_ts_proxy_teardown.py +++ b/apps/channels/tests/test_ts_proxy_teardown.py @@ -5,6 +5,7 @@ from unittest.mock import MagicMock, patch from django.test import TestCase from apps.proxy.live_proxy.constants import ChannelMetadataField, ChannelState +from apps.proxy.live_proxy.input.buffer import StreamBuffer from apps.proxy.live_proxy.input.manager import StreamManager from apps.proxy.live_proxy.redis_keys import RedisKeys from apps.proxy.live_proxy.server import ProxyServer @@ -14,6 +15,29 @@ from apps.proxy.live_proxy.services.channel_service import ChannelService CHANNEL_ID = "00000000-0000-0000-0000-000000000099" +def _configure_ownership_pipeline( + redis, + *, + stop_exists=0, + metadata_exists=1, + client_count=0, + owner=None, + disconnect=None, + state=None, +): + pipe = MagicMock() + redis.pipeline.return_value = pipe + pipe.execute.return_value = ( + stop_exists, + metadata_exists, + client_count, + owner, + disconnect, + state, + ) + return pipe + + def _mock_proxy_server(redis_client=None): server = MagicMock() server.redis_client = redis_client or MagicMock() @@ -79,11 +103,6 @@ class LocalStreamActivityTests(TestCase): server.stop_all_output_profiles = MagicMock() return server - def test_has_local_stream_activity_from_live_registry(self): - server = self._make_server() - server._live_stream_managers[CHANNEL_ID] = MagicMock() - self.assertTrue(server._has_local_stream_activity(CHANNEL_ID)) - @patch.object(ProxyServer, "_join_stream_thread") def test_stop_local_stream_activity_stops_live_manager(self, mock_join): server = self._make_server() @@ -114,9 +133,9 @@ class OrphanMetadataCleanupTests(TestCase): @patch.object(ProxyServer, "_clean_redis_keys") @patch.object(ProxyServer, "_stop_local_stream_activity") - @patch.object(ProxyServer, "_has_local_stream_activity", return_value=True) + @patch.object(ProxyServer, "_has_local_upstream_activity", return_value=True) def test_orphan_metadata_stops_local_processes_before_redis( - self, mock_has_local, mock_stop_local, mock_clean_redis + self, mock_has_upstream, mock_stop_local, mock_clean_redis ): server = self._make_server() metadata_key = RedisKeys.channel_metadata(CHANNEL_ID) @@ -130,15 +149,16 @@ class OrphanMetadataCleanupTests(TestCase): server._check_orphaned_metadata() - mock_has_local.assert_called_with(CHANNEL_ID) + mock_has_upstream.assert_called_with(CHANNEL_ID) mock_stop_local.assert_called_once_with(CHANNEL_ID) mock_clean_redis.assert_called_once_with(CHANNEL_ID) @patch.object(ProxyServer, "_clean_redis_keys") + @patch.object(ProxyServer, "_broadcast_upstream_stop") @patch.object(ProxyServer, "_stop_local_stream_activity") - @patch.object(ProxyServer, "_has_local_stream_activity", return_value=False) - def test_orphan_metadata_remote_channel_only_cleans_redis( - self, mock_has_local, mock_stop_local, mock_clean_redis + @patch.object(ProxyServer, "_has_local_upstream_activity", return_value=False) + def test_orphan_metadata_remote_channel_broadcasts_stop( + self, mock_has_upstream, mock_stop_local, mock_broadcast, mock_clean_redis ): server = self._make_server() metadata_key = RedisKeys.channel_metadata(CHANNEL_ID) @@ -149,6 +169,7 @@ class OrphanMetadataCleanupTests(TestCase): server._check_orphaned_metadata() + mock_broadcast.assert_called_once_with(CHANNEL_ID) mock_stop_local.assert_not_called() mock_clean_redis.assert_called_once_with(CHANNEL_ID) @@ -171,9 +192,9 @@ class OrphanChannelCleanupTests(TestCase): @patch.object(ProxyServer, "_clean_redis_keys") @patch.object(ProxyServer, "_stop_local_stream_activity") - @patch.object(ProxyServer, "_has_local_stream_activity", return_value=True) + @patch.object(ProxyServer, "_has_local_upstream_activity", return_value=True) def test_orphan_channel_stops_local_before_redis( - self, mock_has_local, mock_stop_local, mock_clean_redis + self, mock_has_upstream, mock_stop_local, mock_clean_redis ): server = self._make_server() metadata_key = RedisKeys.channel_metadata(CHANNEL_ID) @@ -189,10 +210,10 @@ class OrphanChannelCleanupTests(TestCase): class StreamManagerOwnershipTests(TestCase): def test_still_owner_false_when_different_worker(self): buffer = MagicMock() - buffer.redis_client.get.side_effect = lambda key: ( - None if "stopping" in key else b"worker-b" + _configure_ownership_pipeline( + buffer.redis_client, + owner=b"worker-b", ) - buffer.redis_client.exists.return_value = False manager = StreamManager( CHANNEL_ID, "http://example/stream", buffer, worker_id="worker-a" ) @@ -201,8 +222,12 @@ class StreamManagerOwnershipTests(TestCase): def test_still_owner_true_when_owner_lock_expired_but_not_stopping(self): buffer = MagicMock() - buffer.redis_client.get.return_value = None - buffer.redis_client.exists.return_value = False + _configure_ownership_pipeline( + buffer.redis_client, + client_count=0, + owner=None, + state=ChannelState.CONNECTING.encode(), + ) manager = StreamManager( CHANNEL_ID, "http://example/stream", buffer, worker_id="worker-a" ) @@ -211,7 +236,10 @@ class StreamManagerOwnershipTests(TestCase): def test_still_owner_false_when_channel_stopping_key_set(self): buffer = MagicMock() - buffer.redis_client.exists.return_value = True + _configure_ownership_pipeline( + buffer.redis_client, + stop_exists=1, + ) manager = StreamManager( CHANNEL_ID, "http://example/stream", buffer, worker_id="worker-a" ) @@ -220,8 +248,10 @@ class StreamManagerOwnershipTests(TestCase): def test_update_bytes_skipped_after_ownership_lost(self): buffer = MagicMock() - buffer.redis_client.get.return_value = b"other-worker" - buffer.redis_client.exists.return_value = False + _configure_ownership_pipeline( + buffer.redis_client, + owner=b"other-worker", + ) manager = StreamManager( CHANNEL_ID, "http://example/stream", buffer, worker_id="worker-a" ) @@ -230,3 +260,383 @@ class StreamManagerOwnershipTests(TestCase): manager._update_bytes_processed(500) buffer.redis_client.hincrby.assert_not_called() + + +class StreamBufferStopTests(TestCase): + def test_stop_discards_local_data_without_redis_writes(self): + redis = MagicMock() + buffer = StreamBuffer(channel_id=CHANNEL_ID, redis_client=redis) + buffer._write_buffer = bytearray(b"x" * 376) + + buffer.stop() + + self.assertTrue(buffer.stopping) + self.assertEqual(len(buffer._write_buffer), 0) + redis.incr.assert_not_called() + redis.setex.assert_not_called() + redis.delete.assert_not_called() + + +class StopChannelTeardownTests(TestCase): + def _make_server(self): + with patch("apps.proxy.live_proxy.server.RedisClient.get_client", return_value=MagicMock()): + server = ProxyServer() + server.worker_id = "testhost:1" + server.stream_managers = {} + server.stream_buffers = {} + server.client_managers = {} + server.profile_managers = {} + server.profile_buffers = {} + server._live_stream_managers = {} + server._stopping_channels = set() + server._stopping_since = {} + server.redis_client = MagicMock() + server.redis_client.exists.return_value = False + server.am_i_owner = MagicMock(return_value=False) + server._collect_channel_stop_event_data = MagicMock(return_value=None) + server.release_ownership = MagicMock() + return server + + @patch.object(ProxyServer, "_spawn_channel_stop_event") + @patch.object(ProxyServer, "_clean_redis_keys") + @patch.object(ProxyServer, "_stop_local_stream_activity") + def test_stop_channel_cleans_redis_before_blocking_local_stop( + self, mock_stop_local, mock_clean_redis, mock_spawn_event + ): + server = self._make_server() + call_order = [] + + def stop_local(channel_id): + call_order.append("local") + + def clean_redis(channel_id): + call_order.append("redis") + + mock_stop_local.side_effect = stop_local + mock_clean_redis.side_effect = clean_redis + + server.stop_channel(CHANNEL_ID) + + self.assertEqual(call_order, ["redis", "local"]) + mock_spawn_event.assert_called_once_with(None) + + @patch.object(ProxyServer, "_spawn_channel_stop_event") + @patch.object(ProxyServer, "_clean_redis_keys") + @patch.object(ProxyServer, "_stop_local_stream_activity", side_effect=RuntimeError("boom")) + def test_stop_channel_cleans_redis_in_finally_when_local_stop_fails( + self, mock_stop_local, mock_clean_redis, mock_spawn_event + ): + server = self._make_server() + + result = server.stop_channel(CHANNEL_ID) + + self.assertFalse(result) + mock_clean_redis.assert_called_once_with(CHANNEL_ID) + mock_spawn_event.assert_not_called() + self.assertNotIn(CHANNEL_ID, server._stopping_channels) + + @patch.object(ProxyServer, "_spawn_channel_stop_event") + @patch.object(ProxyServer, "_clean_redis_keys") + @patch.object(ProxyServer, "_stop_local_stream_activity") + def test_stop_channel_owner_releases_after_redis_cleanup( + self, mock_stop_local, mock_clean_redis, mock_spawn_event + ): + server = self._make_server() + server.am_i_owner.return_value = True + stop_data = {"channel_id": CHANNEL_ID} + server._collect_channel_stop_event_data.return_value = stop_data + call_order = [] + + def stop_local(channel_id): + call_order.append("local") + + def release(channel_id): + call_order.append("release") + + def clean_redis(channel_id): + call_order.append("redis") + + mock_stop_local.side_effect = stop_local + server.release_ownership.side_effect = release + mock_clean_redis.side_effect = clean_redis + + server.stop_channel(CHANNEL_ID) + + self.assertEqual(call_order, ["redis", "release", "local"]) + server._collect_channel_stop_event_data.assert_called_once_with(CHANNEL_ID) + mock_spawn_event.assert_called_once_with(stop_data) + + +class CleanRedisKeysOrderTests(TestCase): + @patch("apps.proxy.live_proxy.server.Stream.objects.get") + @patch("apps.proxy.live_proxy.server.Channel.objects.get") + def test_clean_redis_keys_releases_profile_slot_before_live_keys_deleted( + self, mock_channel_get, mock_stream_get + ): + from apps.channels.models import Channel, Stream + + with patch("apps.proxy.live_proxy.server.RedisClient.get_client", return_value=MagicMock()): + server = ProxyServer() + server.redis_client = MagicMock() + call_order = [] + + channel = MagicMock() + channel.release_stream.return_value = True + + def channel_get(uuid): + call_order.append("release") + return channel + + mock_channel_get.side_effect = channel_get + mock_stream_get.side_effect = Stream.DoesNotExist + + def scan(*args, **kwargs): + call_order.append("redis") + return (0, [b"live:channel:foo:buffer:index"]) + + server.redis_client.scan.side_effect = scan + + server._clean_redis_keys(CHANNEL_ID) + + self.assertEqual(call_order, ["release", "redis"]) + channel.release_stream.assert_called_once() + server.redis_client.delete.assert_called_once() + + +class LocalUpstreamActivityTests(TestCase): + def _make_server(self): + with patch("apps.proxy.live_proxy.server.RedisClient.get_client", return_value=MagicMock()): + server = ProxyServer() + server.worker_id = "testhost:1" + server.stream_managers = {} + server.stream_buffers = {} + server.client_managers = {} + server._live_stream_managers = {} + return server + + def test_upstream_activity_excludes_reader_only_client_manager(self): + server = self._make_server() + server.client_managers[CHANNEL_ID] = MagicMock() + server.stream_buffers[CHANNEL_ID] = MagicMock() + self.assertFalse(server._has_local_upstream_activity(CHANNEL_ID)) + + def test_upstream_activity_from_live_registry(self): + server = self._make_server() + server._live_stream_managers[CHANNEL_ID] = MagicMock() + self.assertTrue(server._has_local_upstream_activity(CHANNEL_ID)) + + +class ClientDisconnectOwnershipTests(TestCase): + def test_last_client_triggers_stop_when_upstream_active_without_owner_lock(self): + from apps.proxy.live_proxy.client_manager import ClientManager + + proxy_server = MagicMock() + proxy_server.worker_id = "testhost:1" + proxy_server.am_i_owner.return_value = False + proxy_server._has_local_upstream_activity.return_value = True + proxy_server.extend_ownership.return_value = False + + redis = MagicMock() + redis.hget.return_value = b"viewer" + redis.scard.return_value = 0 + + manager = ClientManager( + channel_id=CHANNEL_ID, + redis_client=redis, + worker_id="testhost:1", + ) + manager.proxy_server = proxy_server + manager.clients = {"client-1"} + manager.client_set_key = RedisKeys.clients(CHANNEL_ID) + manager._notify_owner_of_activity = MagicMock() + manager._trigger_stats_update = MagicMock() + manager.get_total_client_count = MagicMock(return_value=0) + proxy_server._spawn_on_hub = MagicMock() + + manager.remove_client("client-1") + + proxy_server._spawn_on_hub.assert_called_once_with( + proxy_server.handle_client_disconnect, CHANNEL_ID + ) + + +class TeardownActiveLocalStopTests(TestCase): + @patch("apps.proxy.live_proxy.services.channel_service.ProxyServer.get_instance") + def test_teardown_active_when_local_stop_in_progress(self, mock_get_instance): + server = MagicMock() + server._stopping_channels = {CHANNEL_ID} + server.redis_client = MagicMock() + server.redis_client.exists.return_value = False + mock_get_instance.return_value = server + + self.assertTrue(ChannelService.is_channel_teardown_active(CHANNEL_ID)) + + +class HandleClientDisconnectUpstreamFirstTests(TestCase): + def _make_server(self): + with patch("apps.proxy.live_proxy.server.RedisClient.get_client", return_value=MagicMock()): + server = ProxyServer() + server.worker_id = "testhost:1" + server.client_managers = {CHANNEL_ID: MagicMock()} + server.stream_managers = {CHANNEL_ID: MagicMock()} + server._live_stream_managers = {} + server.profile_managers = {} + server.output_managers = {} + server.redis_client = MagicMock() + server.redis_client.scard.return_value = 0 + server._stopping_channels = set() + return server + + @patch.object(ProxyServer, "_coordinated_stop_channel") + @patch.object(ProxyServer, "_stop_upstream_before_redis_cleanup") + @patch.object(ProxyServer, "_has_local_upstream_activity", return_value=True) + def test_last_client_uses_coordinated_stop_only( + self, _mock_upstream, mock_stop_upstream, mock_coordinated + ): + server = self._make_server() + + with patch( + "apps.proxy.live_proxy.server.ConfigHelper.channel_shutdown_delay", + return_value=0, + ): + server.handle_client_disconnect(CHANNEL_ID) + + mock_stop_upstream.assert_not_called() + mock_coordinated.assert_called_once_with(CHANNEL_ID) + + +class InitWaitAbortTests(TestCase): + def _make_generator(self): + from apps.proxy.live_proxy.output.ts.generator import StreamGenerator + + return StreamGenerator( + CHANNEL_ID, + "client-1", + "127.0.0.1", + "test-agent", + channel_initializing=True, + ) + + def test_abort_when_client_removed_locally(self): + generator = self._make_generator() + server = MagicMock() + client_manager = MagicMock() + client_manager.clients = set() + server.client_managers = {CHANNEL_ID: client_manager} + server.redis_client = MagicMock() + + self.assertEqual(generator._init_wait_abort_reason(server, time.time()), "client_gone") + + def test_abort_when_connect_stalled_without_buffer(self): + from apps.proxy.config import TSConfig as Config + + generator = self._make_generator() + server = MagicMock() + client_manager = MagicMock() + client_manager.clients = {"client-1"} + server.client_managers = {CHANNEL_ID: client_manager} + buffer = MagicMock() + buffer.index = 0 + server.stream_buffers = {CHANNEL_ID: buffer} + server.redis_client = MagicMock() + server.redis_client.hget.return_value = b"connecting" + server.redis_client.get.return_value = None + + started = time.time() - (getattr(Config, "CONNECTION_TIMEOUT", 10) + 1) + self.assertEqual(generator._init_wait_abort_reason(server, started), "stalled") + + +class UpstreamStopBroadcastTests(TestCase): + def _make_server(self): + with patch("apps.proxy.live_proxy.server.RedisClient.get_client", return_value=MagicMock()): + server = ProxyServer() + server.worker_id = "testhost:1" + server.stream_managers = {} + server._live_stream_managers = {} + server.redis_client = MagicMock() + return server + + @patch.object(ProxyServer, "_stop_local_stream_activity") + @patch.object(ProxyServer, "_broadcast_upstream_stop") + @patch.object(ProxyServer, "_has_local_upstream_activity", return_value=True) + def test_local_upstream_stops_locally_without_broadcast( + self, _mock_has, mock_broadcast, mock_stop_local + ): + server = self._make_server() + server._stop_upstream_before_redis_cleanup(CHANNEL_ID) + mock_stop_local.assert_called_once_with(CHANNEL_ID) + mock_broadcast.assert_not_called() + + @patch.object(ProxyServer, "_stop_local_stream_activity") + @patch.object(ProxyServer, "_broadcast_upstream_stop") + @patch.object(ProxyServer, "_has_local_upstream_activity", return_value=False) + def test_orphan_cleanup_broadcasts_when_no_local_upstream( + self, _mock_has, mock_broadcast, mock_stop_local + ): + server = self._make_server() + server._stop_upstream_before_redis_cleanup(CHANNEL_ID) + mock_broadcast.assert_called_once_with(CHANNEL_ID) + mock_stop_local.assert_not_called() + + +class StreamManagerStillOwnerTests(TestCase): + def _make_manager(self, redis_client): + buffer = MagicMock() + buffer.redis_client = redis_client + buffer.channel_id = CHANNEL_ID + manager = StreamManager( + CHANNEL_ID, + "http://example/stream.ts", + buffer, + worker_id="testhost:1", + ) + return manager + + def test_stops_when_metadata_removed(self): + redis = MagicMock() + _configure_ownership_pipeline(redis, metadata_exists=0) + manager = self._make_manager(redis) + self.assertFalse(manager._still_owner()) + + def test_keeps_running_during_connecting_before_client_registered(self): + redis = MagicMock() + _configure_ownership_pipeline( + redis, + client_count=0, + owner=b"testhost:1", + state=ChannelState.CONNECTING.encode(), + ) + manager = self._make_manager(redis) + self.assertTrue(manager._still_owner()) + + def test_stops_after_disconnect_when_shutdown_delay_is_zero(self): + redis = MagicMock() + _configure_ownership_pipeline( + redis, + client_count=0, + owner=b"testhost:1", + disconnect=b"1700000000.0", + state=ChannelState.ACTIVE.encode(), + ) + manager = self._make_manager(redis) + with patch( + "apps.proxy.live_proxy.input.manager.ConfigHelper.channel_shutdown_delay", + return_value=0, + ): + self.assertFalse(manager._still_owner()) + + def test_keeps_running_during_shutdown_delay(self): + redis = MagicMock() + _configure_ownership_pipeline( + redis, + client_count=0, + owner=b"testhost:1", + disconnect=str(time.time()).encode(), + state=ChannelState.ACTIVE.encode(), + ) + manager = self._make_manager(redis) + with patch( + "apps.proxy.live_proxy.input.manager.ConfigHelper.channel_shutdown_delay", + return_value=5, + ): + self.assertTrue(manager._still_owner()) diff --git a/apps/proxy/live_proxy/client_manager.py b/apps/proxy/live_proxy/client_manager.py index 3771d55c..3767a25a 100644 --- a/apps/proxy/live_proxy/client_manager.py +++ b/apps/proxy/live_proxy/client_manager.py @@ -102,6 +102,7 @@ class ClientManager: break # Send heartbeat for all local clients + clients_to_remove = set() with self.lock: # Skip this cycle if we have no local clients if not self.clients: @@ -109,7 +110,6 @@ class ClientManager: # IMPROVED GHOST DETECTION: Check for stale clients before sending heartbeats current_time = time.time() - clients_to_remove = set() # First identify clients that should be removed for client_id in self.clients: @@ -132,12 +132,11 @@ class ClientManager: logger.debug(f"Client {client_id} inactive for {current_time - last_active_time:.1f}s, removing as ghost") clients_to_remove.add(client_id) - # Remove ghost clients in a separate step - for client_id in clients_to_remove: - self.remove_client(client_id) - if clients_to_remove: - logger.info(f"Removed {len(clients_to_remove)} ghost clients from channel {self.channel_id}") + logger.info( + f"Identified {len(clients_to_remove)} ghost clients " + f"for channel {self.channel_id}" + ) # Now send heartbeats only for remaining clients pipe = self.redis_client.pipeline() @@ -172,6 +171,9 @@ class ClientManager: if self.clients and not all(c in clients_to_remove for c in self.clients): self._notify_owner_of_activity() + for client_id in clients_to_remove: + self.remove_client(client_id) + except Exception as e: logger.error(f"Error in client heartbeat thread: {e}") @@ -305,6 +307,9 @@ class ClientManager: def remove_client(self, client_id): """Remove a client from this channel and Redis""" + client_username = "unknown" + remaining = None + with self.lock: if client_id in self.clients: self.clients.remove(client_id) @@ -315,61 +320,80 @@ class ClientManager: self.last_active_time = time.time() if self.redis_client: - # Get client data before removing the data client_key = f"live:channel:{self.channel_id}:clients:{client_id}" client_username = self.redis_client.hget(client_key, "username") or "unknown" if isinstance(client_username, bytes): client_username = client_username.decode("utf-8") - # Remove from channel's client set self.redis_client.srem(self.client_set_key, client_id) - - client_key = f"live:channel:{self.channel_id}:clients:{client_id}" self.redis_client.delete(client_key) - - # Check if this was the last client remaining = self.redis_client.scard(self.client_set_key) or 0 - if remaining == 0: - logger.warning(f"Last client removed: {client_id} - channel may shut down soon") - # Trigger disconnect time tracking even if we're not the owner - disconnect_key = RedisKeys.last_client_disconnect(self.channel_id) - self.redis_client.setex(disconnect_key, 60, str(time.time())) + local_count = len(self.clients) - self._notify_owner_of_activity() + if not self.redis_client: + return local_count - # Check if we're the owner - if so, handle locally; if not, publish event - am_i_owner = self.proxy_server and self.proxy_server.am_i_owner(self.channel_id) + if remaining == 0: + logger.warning(f"Last client removed: {client_id} - channel may shut down soon") + disconnect_key = RedisKeys.last_client_disconnect(self.channel_id) + self.redis_client.setex(disconnect_key, 60, str(time.time())) - if am_i_owner: - # We're the owner - handle the disconnect directly - logger.debug(f"Owner handling CLIENT_DISCONNECTED for client {client_id} locally (not publishing)") - if (remaining == 0 - or self.proxy_server.output_managers.get(self.channel_id) - or self.proxy_server.profile_managers.get(self.channel_id)): - import gevent - gevent.spawn(self.proxy_server.handle_client_disconnect, self.channel_id) - else: - # We're not the owner - publish event so owner can handle it - logger.debug(f"Non-owner publishing CLIENT_DISCONNECTED event for client {client_id} on channel {self.channel_id} from worker {self.worker_id}") - event_data = json.dumps({ - "event": EventType.CLIENT_DISCONNECTED, - "channel_id": self.channel_id, - "client_id": client_id, - "worker_id": self.worker_id or "unknown", - "timestamp": time.time(), - "remaining_clients": remaining, - "username": client_username - }) - self.redis_client.publish(RedisKeys.events_channel(self.channel_id), event_data) + self._notify_owner_of_activity() - # Trigger channel stats update via WebSocket - self._trigger_stats_update() + am_i_owner = self.proxy_server and self.proxy_server.am_i_owner(self.channel_id) - total_clients = self.get_total_client_count() - logger.info(f"Client disconnected: {client_id} (local: {len(self.clients)}, total: {total_clients})") + # Owner lock TTL can expire while local ffmpeg is still running on this worker. + if (not am_i_owner and self.proxy_server + and self.proxy_server._has_local_upstream_activity(self.channel_id)): + if self.proxy_server.extend_ownership(self.channel_id): + am_i_owner = True - return len(self.clients) + schedule_disconnect = False + if am_i_owner: + logger.debug( + f"Owner handling CLIENT_DISCONNECTED for client {client_id} locally (not publishing)" + ) + if (remaining == 0 + or self.proxy_server.output_managers.get(self.channel_id) + or self.proxy_server.profile_managers.get(self.channel_id)): + schedule_disconnect = True + elif (remaining == 0 and self.proxy_server + and self.proxy_server._has_local_upstream_activity(self.channel_id)): + logger.warning( + f"Last client removed while local upstream still active for " + f"{self.channel_id} without owner lock - stopping channel" + ) + schedule_disconnect = True + else: + logger.debug( + f"Non-owner publishing CLIENT_DISCONNECTED event for client {client_id} " + f"on channel {self.channel_id} from worker {self.worker_id}" + ) + event_data = json.dumps({ + "event": EventType.CLIENT_DISCONNECTED, + "channel_id": self.channel_id, + "client_id": client_id, + "worker_id": self.worker_id or "unknown", + "timestamp": time.time(), + "remaining_clients": remaining, + "username": client_username + }) + self.redis_client.publish(RedisKeys.events_channel(self.channel_id), event_data) + + if schedule_disconnect and self.proxy_server: + self.proxy_server._spawn_on_hub( + self.proxy_server.handle_client_disconnect, self.channel_id + ) + + self._trigger_stats_update() + + total_clients = self.get_total_client_count() + logger.info( + f"Client disconnected: {client_id} (local: {local_count}, total: {total_clients})" + ) + + return local_count def get_client_count(self): """Get local client count""" diff --git a/apps/proxy/live_proxy/input/buffer.py b/apps/proxy/live_proxy/input/buffer.py index b345ead3..3d3fb091 100644 --- a/apps/proxy/live_proxy/input/buffer.py +++ b/apps/proxy/live_proxy/input/buffer.py @@ -309,38 +309,16 @@ class StreamBuffer: self.fill_timers.clear() try: - # Flush any remaining data in the write buffer - if hasattr(self, '_write_buffer') and len(self._write_buffer) > 0: - # Ensure remaining data is aligned to TS packets - complete_size = (len(self._write_buffer) // 188) * 188 - - if complete_size > 0: - final_chunk = self._write_buffer[:complete_size] - - # Write final chunk to Redis - with self.lock: - if self.redis_client: - try: - chunk_index = self.redis_client.incr(self.buffer_index_key) - chunk_key = f"{self.buffer_prefix}{chunk_index}" - self.redis_client.setex(chunk_key, self.chunk_ttl, bytes(final_chunk)) - self.index = chunk_index - logger.info(f"Flushed final chunk of {len(final_chunk)} bytes to Redis") - except Exception as e: - logger.error(f"Error flushing final chunk: {e}") - - # Clear buffers - self._write_buffer = bytearray() - if hasattr(self, '_partial_packet'): - self._partial_packet = bytearray() - - # Clean up the chunk timestamps sorted set - if self.redis_client and self.chunk_timestamps_key: - try: - self.redis_client.delete(self.chunk_timestamps_key) - except Exception as e: - logger.error(f"Error deleting chunk timestamps key: {e}") - + with self.lock: + if hasattr(self, '_write_buffer') and len(self._write_buffer) > 0: + discarded = len(self._write_buffer) + self._write_buffer = bytearray() + if hasattr(self, '_partial_packet'): + self._partial_packet = bytearray() + logger.debug( + f"Discarded {discarded} bytes from local write buffer " + f"for channel {self.channel_id}" + ) except Exception as e: logger.error(f"Error during buffer stop: {e}") diff --git a/apps/proxy/live_proxy/input/manager.py b/apps/proxy/live_proxy/input/manager.py index 06b12644..ae744473 100644 --- a/apps/proxy/live_proxy/input/manager.py +++ b/apps/proxy/live_proxy/input/manager.py @@ -112,6 +112,11 @@ class StreamManager: # Add tracking for data throughput self.bytes_processed = 0 self.last_bytes_update = time.time() + + # Cached result of the pipelined Redis ownership audit (hot read path). + self._ownership_cache_valid_until = 0.0 + self._ownership_cached = True + self._OWNERSHIP_CHECK_INTERVAL = 1.0 self.bytes_update_interval = 5 # Update Redis every 5 seconds # Add stderr reader thread property @@ -182,7 +187,90 @@ class StreamManager: logger.warning(f"Timeout waiting for existing processes to close for channel {self.channel_id} after {timeout}s") return False - def _still_owner(self): + def _invalidate_ownership_cache(self): + self._ownership_cache_valid_until = 0.0 + + @staticmethod + def _decode_redis_value(value): + if value is None: + return None + if isinstance(value, bytes): + return value.decode() + return value + + def _disconnect_shutdown_ready(self, disconnect_value): + """True when last-client disconnect has passed the configured shutdown delay.""" + if not disconnect_value: + return False + + shutdown_delay = ConfigHelper.channel_shutdown_delay() + if shutdown_delay <= 0: + return True + + disconnect_value = self._decode_redis_value(disconnect_value) + try: + disconnect_time = float(disconnect_value) + except (ValueError, TypeError): + return False + return (time.time() - disconnect_time) >= shutdown_delay + + def _evaluate_ownership_from_redis(self, redis_client): + """Single pipelined Redis round-trip for the full ownership audit.""" + stop_key = RedisKeys.channel_stopping(self.channel_id) + metadata_key = RedisKeys.channel_metadata(self.channel_id) + clients_key = RedisKeys.clients(self.channel_id) + owner_key = RedisKeys.channel_owner(self.channel_id) + disconnect_key = RedisKeys.last_client_disconnect(self.channel_id) + + pipe = redis_client.pipeline(transaction=False) + pipe.exists(stop_key) + pipe.exists(metadata_key) + pipe.scard(clients_key) + pipe.get(owner_key) + pipe.get(disconnect_key) + pipe.hget(metadata_key, ChannelMetadataField.STATE) + ( + stop_exists, + metadata_exists, + client_count, + current_owner, + disconnect_value, + state_raw, + ) = pipe.execute() + + if stop_exists: + return False + + if not metadata_exists: + logger.warning( + f"Channel {self.channel_id} metadata removed from Redis - stopping upstream" + ) + return False + + client_count = client_count or 0 + state = self._decode_redis_value(state_raw) + current_owner = self._decode_redis_value(current_owner) + + if current_owner and current_owner != self.worker_id: + return False + + if not current_owner: + if client_count == 0 and state not in ChannelState.PRE_ACTIVE: + logger.warning( + f"Channel {self.channel_id} has no owner and no clients - stopping upstream" + ) + return False + return True + + if client_count == 0 and self._disconnect_shutdown_ready(disconnect_value): + logger.info( + f"Channel {self.channel_id} disconnect shutdown ready - stopping upstream" + ) + return False + + return True + + def _still_owner(self, *, force=False): """Return True while this worker should keep the upstream connection open.""" if self.stopping or self.stop_requested: return False @@ -194,26 +282,49 @@ class StreamManager: if not redis_client: return True - try: - stop_key = RedisKeys.channel_stopping(self.channel_id) - if redis_client.exists(stop_key): - return False + now = time.time() + if not force and now < self._ownership_cache_valid_until: + return self._ownership_cached - owner_key = RedisKeys.channel_owner(self.channel_id) - current_owner = redis_client.get(owner_key) - if not current_owner: - # Owner lock TTL may lapse briefly between cleanup-thread renewals. - # Keep running unless coordinated teardown has started (checked above). - return True - if isinstance(current_owner, bytes): - current_owner = current_owner.decode() - return current_owner == self.worker_id + try: + result = self._evaluate_ownership_from_redis(redis_client) + self._ownership_cached = result + self._ownership_cache_valid_until = now + self._OWNERSHIP_CHECK_INTERVAL + return result except Exception as e: logger.debug(f"Ownership check failed for channel {self.channel_id}: {e}") + return True + + def _upstream_may_continue(self): + """ + Per-chunk gate for the hot read path. + + Local stop flags are checked every chunk. The coordinated-teardown Redis + flag is checked every chunk (one EXISTS). The full ownership audit is + pipelined and cached for ~1s — enough for loop boundaries while avoiding + 6+ Redis round-trips per chunk during steady streaming. + """ + if self.stopping or self.stop_requested or not self.running: + return False + if self.buffer is not None and self.buffer.stopping: return False + redis_client = getattr(self.buffer, 'redis_client', None) + if redis_client and self.worker_id: + try: + if redis_client.exists(RedisKeys.channel_stopping(self.channel_id)): + self._ownership_cached = False + self._ownership_cache_valid_until = 0.0 + return False + except Exception as e: + logger.debug( + f"Channel stopping check failed for {self.channel_id}: {e}" + ) + + return self._still_owner() + def _ensure_owner_or_stop(self): - if self._still_owner(): + if self._still_owner(force=True): return True logger.warning( @@ -539,6 +650,7 @@ class StreamManager: logger.debug(f"Closing existing HTTP connections before establishing transcode connection for channel {self.channel_id}") self._close_connection() + close_old_connections() channel = get_stream_object(self.channel_id) # Use FFmpeg specifically for HLS streams @@ -1071,7 +1183,7 @@ class StreamManager: def _update_bytes_processed(self, chunk_size): """Update the total bytes processed in Redis metadata""" - if not self._still_owner(): + if not self._upstream_may_continue(): return try: @@ -1146,17 +1258,11 @@ class StreamManager: """Stop the stream manager and cancel all timers""" logger.info(f"Stopping stream manager for channel {self.channel_id}") - # Add at the beginning of your stop method self.stopping = True + self._invalidate_ownership_cache() if self.buffer is not None: self.buffer.stopping = True - # Release stream resources if we're the owner - if self.current_stream_id and hasattr(self, 'worker_id') and self.worker_id: - if hasattr(self.buffer, 'redis_client') and self.buffer.redis_client: - owner_key = RedisKeys.channel_owner(self.channel_id) - current_owner = self.buffer.redis_client.get(owner_key) - # Cancel all buffer check timers for timer in list(self._buffer_check_timers): try: @@ -1545,7 +1651,8 @@ class StreamManager: if hasattr(self, 'stderr_reader_thread') and self.stderr_reader_thread and self.stderr_reader_thread.is_alive(): try: logger.debug(f"Waiting for stderr reader thread to terminate for channel {self.channel_id}") - self.stderr_reader_thread.join(timeout=2.0) + stderr_join_timeout = 0.25 if self.stopping else 2.0 + self.stderr_reader_thread.join(timeout=stderr_join_timeout) if self.stderr_reader_thread.is_alive(): logger.warning(f"Stderr reader thread did not terminate within timeout for channel {self.channel_id}") except Exception as e: @@ -1638,7 +1745,7 @@ class StreamManager: self.connected = False return False - if not self._still_owner(): + if not self._upstream_may_continue(): self.stop() return False @@ -1649,8 +1756,7 @@ class StreamManager: # Add directly to buffer without TS-specific processing success = self.buffer.add_chunk(chunk) - # Update last data timestamp in Redis if successful - if success and self._still_owner() and hasattr(self.buffer, 'redis_client') and self.buffer.redis_client: + if success and hasattr(self.buffer, 'redis_client') and self.buffer.redis_client: last_data_key = RedisKeys.last_data(self.buffer.channel_id) self.buffer.redis_client.set(last_data_key, str(time.time()), ex=60) diff --git a/apps/proxy/live_proxy/output/ts/generator.py b/apps/proxy/live_proxy/output/ts/generator.py index 64bb4e1d..efde02ad 100644 --- a/apps/proxy/live_proxy/output/ts/generator.py +++ b/apps/proxy/live_proxy/output/ts/generator.py @@ -139,12 +139,75 @@ class StreamGenerator: finally: self._cleanup() + def _init_wait_abort_reason(self, proxy_server, initialization_start): + """Return a reason string when init wait should end early, else None.""" + from ...services.channel_service import ChannelService + + if ChannelService.is_channel_teardown_active(self.channel_id): + return "stopping" + + client_mgr = proxy_server.client_managers.get(self.channel_id) + if client_mgr is not None: + if self.client_id not in client_mgr.clients: + return "client_gone" + elif proxy_server.redis_client: + client_key = RedisKeys.client_metadata(self.channel_id, self.client_id) + if not proxy_server.redis_client.exists(client_key): + total = proxy_server.redis_client.scard(RedisKeys.clients(self.channel_id)) or 0 + if total == 0: + return "client_gone" + + elapsed = time.time() - initialization_start + connection_timeout = getattr(Config, 'CONNECTION_TIMEOUT', 10) + if elapsed < connection_timeout or not proxy_server.redis_client: + return None + + metadata_key = RedisKeys.channel_metadata(self.channel_id) + state_raw = proxy_server.redis_client.hget(metadata_key, 'state') + if not state_raw: + return None + + state = state_raw.decode() if isinstance(state_raw, bytes) else state_raw + if state not in ('connecting', 'initializing', 'buffering'): + return None + + buffer = proxy_server.stream_buffers.get(self.channel_id) + if buffer is not None and buffer.index > 0: + return None + + if proxy_server.redis_client.get(RedisKeys.last_data(self.channel_id)): + return None + + return "stalled" + def _wait_for_initialization(self): initialization_start = time.time() max_init_wait = ConfigHelper.client_wait_timeout() proxy_server = ProxyServer.get_instance() while time.time() - initialization_start < max_init_wait: + abort_reason = self._init_wait_abort_reason(proxy_server, initialization_start) + if abort_reason == "stopping": + logger.error( + f"[{self.client_id}] Channel {self.channel_id} teardown active during initialization" + ) + yield create_ts_packet('error', "Error: Channel is stopping") + return False + if abort_reason == "client_gone": + logger.info( + f"[{self.client_id}] Client disconnected during initialization wait, aborting" + ) + yield create_ts_packet('error', "Error: Client disconnected") + return False + if abort_reason == "stalled": + logger.warning( + f"[{self.client_id}] Channel {self.channel_id} stalled in connecting state " + f"with no buffer data after " + f"{getattr(Config, 'CONNECTION_TIMEOUT', 10)}s, aborting init wait" + ) + yield create_ts_packet('error', "Error: Connection stalled") + return False + if proxy_server.redis_client: metadata_key = RedisKeys.channel_metadata(self.channel_id) metadata = proxy_server.redis_client.hgetall(metadata_key) @@ -537,35 +600,31 @@ class StreamGenerator: stream_released = False if proxy_server.redis_client: try: - metadata_key = RedisKeys.channel_metadata(self.channel_id) - metadata = proxy_server.redis_client.hgetall(metadata_key) - if metadata: - stream_id_bytes = proxy_server.redis_client.hget(metadata_key, ChannelMetadataField.STREAM_ID) - if stream_id_bytes: - # Check if we're the last client - if self.channel_id in proxy_server.client_managers: - client_count = proxy_server.client_managers[self.channel_id].get_total_client_count() - # Only the last client or owner should release the stream - if client_count <= 1 and proxy_server.am_i_owner(self.channel_id): - try: - # Try Channel first (normal flow), fall back to Stream (preview flow) - try: - obj = Channel.objects.get(uuid=self.channel_id) - except (Channel.DoesNotExist, Exception): - obj = Stream.objects.get(stream_hash=self.channel_id) - stream_released = obj.release_stream() - if stream_released: - logger.debug(f"[{self.client_id}] Released stream for channel {self.channel_id}") - else: - logger.warning(f"[{self.client_id}] release_stream found no keys for channel {self.channel_id}") - except Exception as e: - logger.error(f"[{self.client_id}] Error releasing stream for channel {self.channel_id}: {e}") + if self.channel_id in proxy_server.client_managers: + client_count = proxy_server.client_managers[self.channel_id].get_total_client_count() + # Pool slots are global; the last client on any worker must release. + if client_count <= 1: + try: + try: + obj = Channel.objects.get(uuid=self.channel_id) + except (Channel.DoesNotExist, Exception): + obj = Stream.objects.get(stream_hash=self.channel_id) + stream_released = obj.release_stream() + if stream_released: + logger.debug(f"[{self.client_id}] Released stream for channel {self.channel_id}") + else: + logger.warning(f"[{self.client_id}] release_stream found no keys for channel {self.channel_id}") + except Exception as e: + logger.error(f"[{self.client_id}] Error releasing stream for channel {self.channel_id}: {e}") except Exception as e: logger.error(f"[{self.client_id}] Error checking stream data for release: {e}") if self.channel_id in proxy_server.client_managers: client_manager = proxy_server.client_managers[self.channel_id] - local_clients = client_manager.remove_client(self.client_id) + if self.client_id in client_manager.clients: + local_clients = client_manager.remove_client(self.client_id) + else: + local_clients = client_manager.get_client_count() total_clients = client_manager.get_total_client_count() logger.info(f"[{self.client_id}] Disconnected after {elapsed:.2f}s (local: {local_clients}, total: {total_clients})") diff --git a/apps/proxy/live_proxy/server.py b/apps/proxy/live_proxy/server.py index a348c876..667daf2f 100644 --- a/apps/proxy/live_proxy/server.py +++ b/apps/proxy/live_proxy/server.py @@ -72,6 +72,7 @@ class ProxyServer: self._channel_names = {} self._stopping_channels = set() # channels with an active stop_channel call in progress self._stopping_since = {} # channel_id -> time.time() when stop_channel began + self._local_stop_locks = {} # Managers kept until the stream OS thread exits (may outlive stream_managers dict) self._live_stream_managers = {} @@ -141,6 +142,18 @@ class ProxyServer: logger.error(f"Redis command error: {e}") return None + def _spawn_on_hub(self, fn, *args, **kwargs): + """Schedule fn on the gevent hub from any thread without blocking the caller.""" + import gevent + + try: + hub = gevent.get_hub() + hub.loop.run_callback_threadsafe( + lambda: gevent.spawn(fn, *args, **kwargs) + ) + except Exception as e: + logger.error(f"Failed to schedule {getattr(fn, '__name__', fn)} on hub: {e}") + def _start_event_listener(self): """Listen for events from other workers""" if not self.redis_client: @@ -507,9 +520,9 @@ class ProxyServer: current = self.redis_client.get(lock_key) if current is None: - # Key expired, re-acquire if we have the stream_manager, but never + # Key expired, re-acquire if we still run local upstream, but never # during coordinated teardown (multi-worker reconnect-during-stop race). - if channel_id in self.stream_managers: + if channel_id in self.stream_managers or channel_id in self._live_stream_managers: if self._channel_unavailable_for_new_clients(channel_id): logger.info( f"Refusing ownership re-acquisition for {channel_id}; " @@ -546,6 +559,12 @@ class ProxyServer: ) return False + if self._has_local_upstream_activity(channel_id): + logger.warning( + f"Stopping lingering local upstream before initializing channel {channel_id}" + ) + self._stop_local_stream_activity(channel_id) + if self.redis_client: metadata_key = RedisKeys.channel_metadata(channel_id) if self.redis_client.exists(metadata_key): @@ -879,26 +898,7 @@ class ProxyServer: owner = metadata.get('owner', 'unknown') logger.info(f"Zombie channel details - state: {state}, owner: {owner}") - # Clean up Redis keys self._clean_redis_keys(channel_id) - - # Force release resources in the Channel model - try: - channel = Channel.objects.get(uuid=channel_id) - if not channel.release_stream(): - logger.warning(f"Failed to release stream for zombie channel {channel_id}") - else: - logger.info(f"Released stream allocation for zombie channel {channel_id}") - except Exception as e: - try: - stream = Stream.objects.get(stream_hash=channel_id) - if not stream.release_stream(): - logger.warning(f"Failed to release stream for zombie channel {channel_id}") - else: - logger.info(f"Released stream allocation for zombie channel {channel_id}") - except Exception as e: - logger.error(f"Error releasing stream for zombie channel {channel_id}: {e}") - return True except Exception as e: logger.error(f"Error cleaning zombie channel {channel_id}: {e}", exc_info=True) @@ -914,8 +914,10 @@ class ProxyServer: # to manage for this channel at all. if (channel_id not in self.client_managers and channel_id not in self.stream_managers + and channel_id not in self._live_stream_managers and channel_id not in self.profile_managers - and channel_id not in self.output_managers): + and channel_id not in self.output_managers + and not self._has_local_upstream_activity(channel_id)): return try: @@ -987,12 +989,12 @@ class ProxyServer: if total == 0: logger.debug(f"No clients left after disconnect event - stopping channel {channel_id}") - disconnect_key = RedisKeys.last_client_disconnect(channel_id) - self.redis_client.setex(disconnect_key, 60, str(time.time())) shutdown_delay = ConfigHelper.channel_shutdown_delay() + disconnect_key = RedisKeys.last_client_disconnect(channel_id) if shutdown_delay > 0: + self.redis_client.setex(disconnect_key, 60, str(time.time())) logger.info(f"Waiting {shutdown_delay}s before stopping channel...") gevent.sleep(shutdown_delay) @@ -1002,6 +1004,13 @@ class ProxyServer: self.redis_client.delete(disconnect_key) return + if shutdown_delay <= 0: + self.redis_client.setex(disconnect_key, 60, str(time.time())) + + # Coordinated stop runs local teardown + Redis cleanup once. + # Do not call _stop_upstream_before_redis_cleanup here — it races + # with stop_channel and can leave stop_channel blocked on stderr join + # before _clean_redis_keys ever runs (orphaned buffer:index keys). self._coordinated_stop_channel(channel_id) except Exception as e: logger.error(f"Error handling client disconnect for channel {channel_id}: {e}") @@ -1371,18 +1380,41 @@ class ProxyServer: return thread return None - def _has_local_stream_activity(self, channel_id): + def _has_local_upstream_activity(self, channel_id): + """True when this worker runs a local ffmpeg / stream-{uuid} OS thread.""" if channel_id in self.stream_managers: return True if channel_id in self._live_stream_managers: return True - if channel_id in self.stream_buffers: - return True - if channel_id in self.client_managers: - return True thread = self._get_stream_thread(channel_id) return thread is not None and thread.is_alive() + def _broadcast_upstream_stop(self, channel_id): + """Ask every uWSGI worker to stop local ffmpeg for this channel.""" + from .services.channel_service import ChannelService + + if not self.redis_client: + return + try: + ChannelService.mark_channel_stopping(channel_id, broadcast=True) + logger.info( + f"Broadcast upstream stop for channel {channel_id} to all workers" + ) + except Exception as e: + logger.error( + f"Error broadcasting upstream stop for channel {channel_id}: {e}" + ) + + def _stop_upstream_before_redis_cleanup(self, channel_id): + """Stop local ffmpeg before deleting Redis keys (prevents delete/recreate loops).""" + if self._has_local_upstream_activity(channel_id): + logger.info( + f"Channel {channel_id} has local upstream activity - stopping processes" + ) + self._stop_local_stream_activity(channel_id) + return + self._broadcast_upstream_stop(channel_id) + def _join_stream_thread(self, channel_id, timeout=2.0): thread = self._get_stream_thread(channel_id) if thread and thread.is_alive(): @@ -1402,8 +1434,41 @@ class ProxyServer: manager = self._live_stream_managers.pop(channel_id, None) return manager + def _signal_upstream_shutdown(self, channel_id): + """Halt upstream Redis writes immediately without blocking on ffmpeg join.""" + if channel_id in self.stream_buffers: + self.stream_buffers[channel_id].stopping = True + for registry in (self.stream_managers, self._live_stream_managers): + manager = registry.get(channel_id) + if manager is None: + continue + manager.stopping = True + manager.stop_requested = True + if getattr(manager, 'buffer', None) is not None: + manager.buffer.stopping = True + + def _get_local_stop_lock(self, channel_id): + lock = self._local_stop_locks.get(channel_id) + if lock is None: + lock = threading.Lock() + self._local_stop_locks[channel_id] = lock + return lock + def _stop_local_stream_activity(self, channel_id): """Stop local ffmpeg/stream threads regardless of registry state.""" + lock = self._get_local_stop_lock(channel_id) + if not lock.acquire(blocking=False): + logger.debug( + f"Local stop already in progress for channel {channel_id}, skipping duplicate" + ) + return + try: + self._stop_local_stream_activity_locked(channel_id) + finally: + lock.release() + self._local_stop_locks.pop(channel_id, None) + + def _stop_local_stream_activity_locked(self, channel_id): stream_manager = self._resolve_stream_manager(channel_id) if stream_manager is not None: if hasattr(stream_manager, 'stop'): @@ -1445,17 +1510,13 @@ class ProxyServer: self.profile_buffers.pop(channel_id, None) self._live_stream_managers.pop(channel_id, None) - def _cleanup_stopped_channel_local(self, channel_id): - """Remove local managers/buffers for a channel that is shutting down.""" - self._stop_local_stream_activity(channel_id) - def _recover_stuck_channel_stops(self): """Force cleanup when stop_channel never finishes (e.g. blocked on logging).""" if not self._stopping_channels: return now = time.time() - stuck_threshold = max(30, ConfigHelper.channel_shutdown_delay() * 2) + stuck_threshold = max(10, ConfigHelper.channel_shutdown_delay() * 2) for channel_id in list(self._stopping_channels): started = self._stopping_since.get(channel_id, now) @@ -1483,10 +1544,10 @@ class ProxyServer: self._stopping_channels.add(channel_id) self._stopping_since[channel_id] = time.time() stop_event_data = None + redis_cleaned = False try: logger.info(f"Stopping channel {channel_id}") - # First set a stopping key that clients will check if self.redis_client: stop_key = RedisKeys.channel_stopping(channel_id) if self.redis_client.exists(stop_key): @@ -1494,54 +1555,26 @@ class ProxyServer: else: self.redis_client.setex(stop_key, 60, "true") - # Only stop the actual stream manager if we're the owner - if self.am_i_owner(channel_id): - logger.info(f"This worker ({self.worker_id}) is the owner - closing provider connection") - if channel_id in self.stream_managers: - stream_manager = self.stream_managers[channel_id] - - # Signal thread to stop and close resources - if hasattr(stream_manager, 'stop'): - stream_manager.stop() - else: - stream_manager.running = False - if hasattr(stream_manager, '_close_socket'): - stream_manager._close_socket() - - # Wait for stream thread to finish - stream_thread_name = f"stream-{channel_id}" - stream_thread = None - - for thread in threading.enumerate(): - if thread.name == stream_thread_name: - stream_thread = thread - break - - if stream_thread and stream_thread.is_alive(): - logger.info(f"Waiting for stream thread to terminate") - try: - # Very short timeout to prevent hanging the app - stream_thread.join(timeout=2.0) - if stream_thread.is_alive(): - logger.warning(f"Stream thread did not terminate within timeout") - except RuntimeError: - logger.debug(f"Could not join stream thread (may be current thread)") - - # Stop all output format managers before releasing ownership - self.stop_all_output_formats(channel_id) - - # Stop all output profile transcodes before releasing ownership - self.stop_all_output_profiles(channel_id) - + was_owner = self.am_i_owner(channel_id) + if was_owner: + logger.info( + f"This worker ({self.worker_id}) is the owner - closing provider connection" + ) stop_event_data = self._collect_channel_stop_event_data(channel_id) - # Release ownership + # Stop new chunk writes before Redis cleanup; do not block on ffmpeg join yet. + self._signal_upstream_shutdown(channel_id) + + # Release profile slots and delete Redis keys before any blocking local stop. + # A concurrent disconnect + cleanup-thread stop used to wedge here behind a + # 2s stderr join, never reaching scan/delete (bare buffer:index with TTL -1). + self._clean_redis_keys(channel_id) + redis_cleaned = True + + if was_owner: self.release_ownership(channel_id) - # Always clean up local resources before Redis/logging so teardown - # cannot be blocked by connect integrations or DB event writes. - self._cleanup_stopped_channel_local(channel_id) - self._clean_redis_keys(channel_id) + self._stop_local_stream_activity(channel_id) self._spawn_channel_stop_event(stop_event_data) return True @@ -1549,6 +1582,13 @@ class ProxyServer: logger.error(f"Error stopping channel {channel_id}: {e}") return False finally: + if not redis_cleaned: + try: + self._clean_redis_keys(channel_id) + except Exception as e: + logger.error( + f"Error cleaning Redis keys for channel {channel_id} during finally: {e}" + ) self._stopping_channels.discard(channel_id) self._stopping_since.pop(channel_id, None) @@ -1595,7 +1635,11 @@ class ProxyServer: self._recover_stuck_channel_stops() # Create a unified list of all channels we have locally - all_local_channels = set(self.stream_managers.keys()) | set(self.client_managers.keys()) + all_local_channels = ( + set(self.stream_managers.keys()) + | set(self.client_managers.keys()) + | set(self._live_stream_managers.keys()) + ) # Single loop through all channels - process each exactly once for channel_id in list(all_local_channels): @@ -1764,7 +1808,8 @@ class ProxyServer: # === NON-OWNER CHANNEL HANDLING === # Safety: if we have a stream_manager, we ARE the real owner # but the Redis key may have expired. Try to re-acquire. - if channel_id in self.stream_managers: + if (channel_id in self.stream_managers + or channel_id in self._live_stream_managers): # Ownership was explicitly released by an active stop_channel call - # don't fight the shutdown by trying to re-acquire. if channel_id in self._stopping_channels: @@ -1930,11 +1975,7 @@ class ProxyServer: # Orphaned channel with no clients - clean it up logger.info(f"Cleaning up orphaned channel {channel_id}") - if self._has_local_stream_activity(channel_id): - logger.info( - f"Orphaned channel {channel_id} has local stream activity - stopping processes" - ) - self._stop_local_stream_activity(channel_id) + self._stop_upstream_before_redis_cleanup(channel_id) self._clean_redis_keys(channel_id) except Exception as e: logger.error(f"Error processing channel key {key}: {e}") @@ -1964,8 +2005,7 @@ class ProxyServer: if not metadata: # Empty metadata - clean it up logger.warning(f"Found empty metadata for channel {channel_id} - cleaning up") - if self._has_local_stream_activity(channel_id): - self._stop_local_stream_activity(channel_id) + self._stop_upstream_before_redis_cleanup(channel_id) self._clean_redis_keys(channel_id) continue @@ -1987,11 +2027,7 @@ class ProxyServer: state = metadata.get('state', 'unknown') logger.warning(f"Found orphaned metadata for channel {channel_id} (state: {state}, owner: {owner}, clients: {client_count}) - cleaning up") - if self._has_local_stream_activity(channel_id): - logger.info( - f"Channel {channel_id} has local stream activity - stopping processes" - ) - self._stop_local_stream_activity(channel_id) + self._stop_upstream_before_redis_cleanup(channel_id) self._clean_redis_keys(channel_id) elif not owner_alive and client_count > 0: # SCARD may include ghost entries from a dead worker's @@ -2008,8 +2044,7 @@ class ProxyServer: f"owner: {owner}) had {client_count} ghost client(s) " f"- cleaning up" ) - if self._has_local_stream_activity(channel_id): - self._stop_local_stream_activity(channel_id) + self._stop_upstream_before_redis_cleanup(channel_id) self._clean_redis_keys(channel_id) else: if self._channel_teardown_active(channel_id): @@ -2018,8 +2053,7 @@ class ProxyServer: f"{real_count} client(s) during teardown; forcing cleanup" ) self._force_clear_channel_clients(channel_id) - if self._has_local_stream_activity(channel_id): - self._stop_local_stream_activity(channel_id) + self._stop_upstream_before_redis_cleanup(channel_id) self._clean_redis_keys(channel_id) else: logger.warning( @@ -2036,7 +2070,11 @@ class ProxyServer: def _clean_redis_keys(self, channel_id): """Clean up all Redis keys for a channel more efficiently""" - # Release the channel, stream, and profile keys from the channel + total_deleted = 0 + + # Release the M3U profile slot while channel_stream / metadata still exist. + # Scanning live:channel keys first deletes metadata and breaks release_stream() + # fallback, leaving profile_connections counters stuck (e.g. profile_connections:70 = 1). try: channel = Channel.objects.get(uuid=channel_id) if not channel.release_stream(): @@ -2049,36 +2087,29 @@ class ProxyServer: except (Stream.DoesNotExist, Exception): logger.debug(f"No Channel or Stream found for {channel_id}") - if not self.redis_client: - return 0 + if self.redis_client: + try: + patterns = [ + f"live:channel:{channel_id}:*", + RedisKeys.events_channel(channel_id), + ] - try: - # Define key patterns to scan for - patterns = [ - f"live:channel:{channel_id}:*", # All channel keys - RedisKeys.events_channel(channel_id) # Event channel - ] + for pattern in patterns: + cursor = 0 + while True: + cursor, keys = self.redis_client.scan(cursor, match=pattern, count=100) + if keys: + self.redis_client.delete(*keys) + total_deleted += len(keys) - total_deleted = 0 + if cursor == 0: + break - for pattern in patterns: - cursor = 0 - while True: - cursor, keys = self.redis_client.scan(cursor, match=pattern, count=100) - if keys: - self.redis_client.delete(*keys) - total_deleted += len(keys) + logger.info(f"Cleaned up {total_deleted} Redis keys for channel {channel_id}") + except Exception as e: + logger.error(f"Error cleaning Redis keys for channel {channel_id}: {e}") - # Exit when cursor returns to 0 - if cursor == 0: - break - - logger.info(f"Cleaned up {total_deleted} Redis keys for channel {channel_id}") - return total_deleted - - except Exception as e: - logger.error(f"Error cleaning Redis keys for channel {channel_id}: {e}") - return 0 + return total_deleted def refresh_channel_registry(self): """Refresh TTL for active channels using standard keys""" diff --git a/apps/proxy/live_proxy/services/channel_service.py b/apps/proxy/live_proxy/services/channel_service.py index 6671e444..dcd0b5e1 100644 --- a/apps/proxy/live_proxy/services/channel_service.py +++ b/apps/proxy/live_proxy/services/channel_service.py @@ -73,6 +73,9 @@ class ChannelService: def is_channel_teardown_active(channel_id): """True when a coordinated channel stop is in progress (visible to all workers).""" proxy_server = ProxyServer.get_instance() + if channel_id in proxy_server._stopping_channels: + return True + if not proxy_server.redis_client: return False @@ -345,41 +348,19 @@ class ChannelService: except Exception as e: logger.error(f"Error fetching channel state: {e}") - # Mark stopping in Redis and notify all workers before local teardown + # Mark stopping in Redis and notify all workers before local teardown. + # stop_channel() releases profile slots via _clean_redis_keys() before Redis deletion. if proxy_server.redis_client: ChannelService.mark_channel_stopping(channel_id, broadcast=True) logger.info(f"Marked channel {channel_id} stopping and broadcast stop to all workers") - local_result = proxy_server.stop_channel(channel_id) - else: - local_result = proxy_server.stop_channel(channel_id) - - # Release the channel in the channel model if applicable - try: - channel = Channel.objects.get(uuid=channel_id) - model_released = channel.release_stream() - if model_released: - logger.info(f"Released channel {channel_id} stream allocation") - else: - logger.warning(f"Channel {channel_id}: release_stream found no keys to clean") - except (Channel.DoesNotExist, Exception): - logger.warning(f"Could not find Channel model for UUID {channel_id}, attempting stream hash") - try: - stream = Stream.objects.get(stream_hash=channel_id) - model_released = stream.release_stream() - if model_released: - logger.info(f"Released stream {channel_id} stream allocation") - else: - logger.warning(f"Stream {channel_id}: release_stream found no keys to clean") - except (Stream.DoesNotExist, Exception) as e: - logger.error(f"No Channel or Stream found for {channel_id}: {e}") - model_released = False + local_result = proxy_server.stop_channel(channel_id) return { 'status': 'success', 'message': 'Channel stop request sent', 'channel_id': channel_id, 'previous_state': channel_info, - 'model_released': model_released, + 'model_released': bool(local_result), 'local_stop_result': local_result } diff --git a/apps/proxy/live_proxy/views.py b/apps/proxy/live_proxy/views.py index b547cefd..2119b4bd 100644 --- a/apps/proxy/live_proxy/views.py +++ b/apps/proxy/live_proxy/views.py @@ -211,6 +211,12 @@ def stream_ts(request, channel_id, user=None, force_output_format=None): # Start initialization if needed if needs_initialization or not proxy_server.check_if_channel_exists(channel_id): + if ChannelService.is_channel_unavailable_for_new_clients(channel_id): + logger.info( + f"[{client_id}] Channel {channel_id} became unavailable before init, rejecting" + ) + return _channel_stopping_response() + logger.info(f"[{client_id}] Starting channel {channel_id} initialization") # Force cleanup of any previous instance if in terminal state if channel_state in [ @@ -433,6 +439,16 @@ def stream_ts(request, channel_id, user=None, force_output_format=None): ) # 502 Bad Gateway # Initialize channel with the stream's user agent (not the client's) + if ChannelService.is_channel_unavailable_for_new_clients(channel_id): + if connection_allocated: + if not channel.release_stream(): + logger.warning(f"[{client_id}] Failed to release stream before teardown reject") + connection_allocated = False + logger.info( + f"[{client_id}] Channel {channel_id} unavailable before init call, rejecting" + ) + return _channel_stopping_response() + success = ChannelService.initialize_channel( channel_id, stream_url, @@ -541,6 +557,16 @@ def stream_ts(request, channel_id, user=None, force_output_format=None): f"[{client_id}] Successfully initialized channel {channel_id} locally" ) + if ChannelService.is_channel_unavailable_for_new_clients(channel_id): + if _client_pre_registered: + mgr = proxy_server.client_managers.get(channel_id) + if mgr: + mgr.remove_client(client_id) + logger.info( + f"[{client_id}] Channel {channel_id} became unavailable during setup, rejecting" + ) + return _channel_stopping_response() + # Register client output_profile = _resolve_output_profile(request, user) if output_profile: From 8f40f6065f5664fe27f48f31a0fd8fc596dc2a95 Mon Sep 17 00:00:00 2001 From: SergeantPanda Date: Sun, 14 Jun 2026 21:55:57 -0500 Subject: [PATCH 4/9] fix(proxy): improve resource cleanup and connection management - Added calls to close_old_connections in various components to ensure proper resource cleanup and prevent connection leaks. --- CHANGELOG.md | 1 + apps/proxy/live_proxy/input/manager.py | 3 + .../proxy/live_proxy/output/fmp4/generator.py | 82 +++++++------- apps/proxy/live_proxy/output/ts/generator.py | 102 +++++++++--------- apps/proxy/live_proxy/server.py | 65 +++++------ core/utils.py | 5 + 6 files changed, 140 insertions(+), 118 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 4de12ded..7e40e04a 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -47,6 +47,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - **Client reconnect during channel teardown could wedge the channel across uWSGI workers.** The disconnect path called `proxy_server.stop_channel()` directly, so other workers were not notified and reconnecting clients could attach while ownership was released on the owner worker. The cleanup thread then re-acquired expired ownership and looped on orphaned clients while the upstream connection stayed open. All lifecycle stops now go through coordinated Redis teardown (`channel_stopping` flag, metadata `stopping` state, and `CHANNEL_STOP` pubsub). New stream requests are rejected with `503 Retry-After` during pending shutdown or active teardown; `initialize_channel()` and ownership re-acquisition refuse to proceed in those states; non-owner workers clean local resources only on pubsub; and orphaned-client sweeps force cleanup when teardown is already active. (Fixes #1342) - **Orphaned upstream threads kept writing Redis after teardown.** Partial cleanup could remove a channel from `stream_managers` while the `stream-{uuid}` OS thread kept running, so orphan metadata sweeps only deleted Redis keys and chunks/metadata were immediately recreated (bare `total_bytes` hash with TTL -1). Stream managers now stop upstream when ownership is lost, orphan cleanup stops local ffmpeg/stream threads even when registry entries are gone (`_live_stream_managers` tracks managers until the thread exits), and forced recovery stops processes before Redis deletion instead of dropping dict entries without calling `stop()`. - **Rapid channel switching could leave bare `buffer:index` keys in Redis.** `buffer.stop()` flushed a final partial chunk via `INCR` during teardown, creating a persistent index key (TTL -1) after chunk keys expired; under load overlapping disconnect and cleanup-thread stops could race on `_stop_local_stream_activity`, blocking on ffmpeg stderr join before `_clean_redis_keys` ever ran. Teardown no longer writes to Redis from `buffer.stop()`, disconnect uses coordinated stop only (no duplicate upstream stop), model `release_stream()` runs before Redis keys are scanned/deleted (so `profile_connections` counters are not left stuck), ownership is released after Redis cleanup but before the blocking local ffmpeg stop, and a `finally` block guarantees Redis cleanup if local teardown raises. +- **Live proxy could leak geventpool DB checkouts outside HTTP requests.** With `django-db-geventpool`, `connection.close()` returns handles to the per-worker pool (`MAX_CONNS=8`); without it, greenlets and OS threads keep connections checked out until the pool blocks on `pool.get()`. Proxy paths that touch the ORM outside Django's request cycle now call `close_old_connections()` after work completes: `log_system_event()` (all system events), `_clean_redis_keys()`, channel init/start logging, client disconnect cleanup (TS and fMP4 generators), and profile lookup in `_establish_transcode_connection()` before spawning ffmpeg. - **Zombie ffmpeg could survive owner-lock expiry and orphan Redis sweeps.** When the 30s owner lock lapsed under single-worker load, disconnect handling treated the worker as non-owner so coordinated stop never ran, while ffmpeg kept writing and the orphan sweeper only deleted Redis keys (recreating them immediately). Disconnect now re-acquires ownership when local upstream is still active, stops locally when the last client leaves without a lock, orphan cleanup stops local ffmpeg before Redis deletion via `_has_local_upstream_activity`, re-init stops lingering upstream before starting a duplicate thread, and `is_channel_teardown_active` includes channels mid-`stop_channel` on this worker so rapid reconnect gets 503 during teardown. - **Stale `channel_stream` Redis keys after a channel stopped could skip connection accounting on retune.** On `dev`, `get_stream()` reused any existing `channel_stream` / `stream_profile` assignment without reserving a new slot. If those keys were left behind after a stop, the next tune-in could reach the provider without incrementing Redis counters. `get_stream()` now releases stale assignments when proxy metadata shows the channel is inactive, then reserves fresh slots. - **EPG auto-match reliability fixes.** diff --git a/apps/proxy/live_proxy/input/manager.py b/apps/proxy/live_proxy/input/manager.py index ae744473..e8315006 100644 --- a/apps/proxy/live_proxy/input/manager.py +++ b/apps/proxy/live_proxy/input/manager.py @@ -690,6 +690,9 @@ class StreamManager: self.transcode_cmd = [arg for arg in self.transcode_cmd if self.user_agent not in arg and 'user-agent' not in arg.lower() and 'user_agent' not in arg.lower()] logger.debug(f"Removed user_agent parameters from UDP stream command for channel: {self.channel_id}") + # Profile lookup is done; release the pool slot before a long-lived ffmpeg process. + close_old_connections() + logger.debug(f"Starting transcode process: {self.transcode_cmd} for channel: {self.channel_id}") import os as _os diff --git a/apps/proxy/live_proxy/output/fmp4/generator.py b/apps/proxy/live_proxy/output/fmp4/generator.py index 65a8c5c7..e979008c 100644 --- a/apps/proxy/live_proxy/output/fmp4/generator.py +++ b/apps/proxy/live_proxy/output/fmp4/generator.py @@ -11,6 +11,7 @@ import time import gevent from apps.channels.models import Channel, Stream from core.utils import log_system_event +from django.db import close_old_connections from ...server import ProxyServer from ...redis_keys import RedisKeys from ...constants import ChannelMetadataField @@ -331,46 +332,49 @@ class FMP4StreamGenerator: # ------------------------------------------------------------------ def _cleanup(self): - elapsed = time.time() - self.stream_start_time - proxy_server = ProxyServer.get_instance() + try: + elapsed = time.time() - self.stream_start_time + proxy_server = ProxyServer.get_instance() - # Release stream allocation if last client (mirrors StreamGenerator) - if proxy_server.redis_client: - try: - meta_key = RedisKeys.channel_metadata(self.channel_id) - stream_id_bytes = proxy_server.redis_client.hget( - meta_key, ChannelMetadataField.STREAM_ID - ) - if stream_id_bytes: - if self.channel_id in proxy_server.client_managers: - client_count = proxy_server.client_managers[ - self.channel_id - ].get_total_client_count() - if client_count <= 1 and proxy_server.am_i_owner(self.channel_id): - try: + # Release stream allocation if last client (mirrors StreamGenerator) + if proxy_server.redis_client: + try: + meta_key = RedisKeys.channel_metadata(self.channel_id) + stream_id_bytes = proxy_server.redis_client.hget( + meta_key, ChannelMetadataField.STREAM_ID + ) + if stream_id_bytes: + if self.channel_id in proxy_server.client_managers: + client_count = proxy_server.client_managers[ + self.channel_id + ].get_total_client_count() + if client_count <= 1 and proxy_server.am_i_owner(self.channel_id): try: - obj = Channel.objects.get(uuid=self.channel_id) - except (Channel.DoesNotExist, Exception): - obj = Stream.objects.get(stream_hash=self.channel_id) - obj.release_stream() - except Exception as e: - logger.error( - f"[{self.client_id}] Error releasing stream: {e}" - ) - except Exception as e: - logger.error(f"[{self.client_id}] Error in stream release check: {e}") + try: + obj = Channel.objects.get(uuid=self.channel_id) + except (Channel.DoesNotExist, Exception): + obj = Stream.objects.get(stream_hash=self.channel_id) + obj.release_stream() + except Exception as e: + logger.error( + f"[{self.client_id}] Error releasing stream: {e}" + ) + except Exception as e: + logger.error(f"[{self.client_id}] Error in stream release check: {e}") - # Remove from MAIN ClientManager - this is what triggers handle_client_disconnect - # and the zero-clients → stop_channel path, same as TS clients. - local_clients = 0 - total_clients = 0 - if self.channel_id in proxy_server.client_managers: - client_manager = proxy_server.client_managers[self.channel_id] - local_clients = client_manager.remove_client(self.client_id) - total_clients = client_manager.get_total_client_count() + # Remove from MAIN ClientManager - this is what triggers handle_client_disconnect + # and the zero-clients → stop_channel path, same as TS clients. + local_clients = 0 + total_clients = 0 + if self.channel_id in proxy_server.client_managers: + client_manager = proxy_server.client_managers[self.channel_id] + local_clients = client_manager.remove_client(self.client_id) + total_clients = client_manager.get_total_client_count() - logger.info( - f"[{self.client_id}] fMP4 client disconnected after {elapsed:.2f}s " - f"({self.bytes_sent / 1024:.1f} KB sent, " - f"local: {local_clients}, total: {total_clients})" - ) + logger.info( + f"[{self.client_id}] fMP4 client disconnected after {elapsed:.2f}s " + f"({self.bytes_sent / 1024:.1f} KB sent, " + f"local: {local_clients}, total: {total_clients})" + ) + finally: + close_old_connections() diff --git a/apps/proxy/live_proxy/output/ts/generator.py b/apps/proxy/live_proxy/output/ts/generator.py index efde02ad..69dc341f 100644 --- a/apps/proxy/live_proxy/output/ts/generator.py +++ b/apps/proxy/live_proxy/output/ts/generator.py @@ -8,6 +8,7 @@ import gevent from apps.proxy.config import TSConfig as Config from apps.channels.models import Channel, Stream from core.utils import log_system_event +from django.db import close_old_connections from ...server import ProxyServer from ...utils import create_ts_packet, get_logger from ...redis_keys import RedisKeys @@ -590,59 +591,62 @@ class StreamGenerator: def _cleanup(self): """Clean up resources and report final statistics.""" - # Client cleanup - elapsed = time.time() - self.stream_start_time - local_clients = 0 - total_clients = 0 - proxy_server = ProxyServer.get_instance() + try: + # Client cleanup + elapsed = time.time() - self.stream_start_time + local_clients = 0 + total_clients = 0 + proxy_server = ProxyServer.get_instance() - # Release M3U profile stream allocation if this is the last client - stream_released = False - if proxy_server.redis_client: - try: - if self.channel_id in proxy_server.client_managers: - client_count = proxy_server.client_managers[self.channel_id].get_total_client_count() - # Pool slots are global; the last client on any worker must release. - if client_count <= 1: - try: + # Release M3U profile stream allocation if this is the last client + stream_released = False + if proxy_server.redis_client: + try: + if self.channel_id in proxy_server.client_managers: + client_count = proxy_server.client_managers[self.channel_id].get_total_client_count() + # Pool slots are global; the last client on any worker must release. + if client_count <= 1: try: - obj = Channel.objects.get(uuid=self.channel_id) - except (Channel.DoesNotExist, Exception): - obj = Stream.objects.get(stream_hash=self.channel_id) - stream_released = obj.release_stream() - if stream_released: - logger.debug(f"[{self.client_id}] Released stream for channel {self.channel_id}") - else: - logger.warning(f"[{self.client_id}] release_stream found no keys for channel {self.channel_id}") - except Exception as e: - logger.error(f"[{self.client_id}] Error releasing stream for channel {self.channel_id}: {e}") - except Exception as e: - logger.error(f"[{self.client_id}] Error checking stream data for release: {e}") + try: + obj = Channel.objects.get(uuid=self.channel_id) + except (Channel.DoesNotExist, Exception): + obj = Stream.objects.get(stream_hash=self.channel_id) + stream_released = obj.release_stream() + if stream_released: + logger.debug(f"[{self.client_id}] Released stream for channel {self.channel_id}") + else: + logger.warning(f"[{self.client_id}] release_stream found no keys for channel {self.channel_id}") + except Exception as e: + logger.error(f"[{self.client_id}] Error releasing stream for channel {self.channel_id}: {e}") + except Exception as e: + logger.error(f"[{self.client_id}] Error checking stream data for release: {e}") - if self.channel_id in proxy_server.client_managers: - client_manager = proxy_server.client_managers[self.channel_id] - if self.client_id in client_manager.clients: - local_clients = client_manager.remove_client(self.client_id) - else: - local_clients = client_manager.get_client_count() - total_clients = client_manager.get_total_client_count() - logger.info(f"[{self.client_id}] Disconnected after {elapsed:.2f}s (local: {local_clients}, total: {total_clients})") + if self.channel_id in proxy_server.client_managers: + client_manager = proxy_server.client_managers[self.channel_id] + if self.client_id in client_manager.clients: + local_clients = client_manager.remove_client(self.client_id) + else: + local_clients = client_manager.get_client_count() + total_clients = client_manager.get_total_client_count() + logger.info(f"[{self.client_id}] Disconnected after {elapsed:.2f}s (local: {local_clients}, total: {total_clients})") - # Log client disconnect event - try: - log_system_event( - 'client_disconnect', - channel_id=self.channel_id, - channel_name=self.channel_name, - client_ip=self.client_ip, - client_id=self.client_id, - user_agent=self.client_user_agent[:100] if self.client_user_agent else None, - duration=round(elapsed, 2), - bytes_sent=self.bytes_sent, - username=self.user.username if self.user else None - ) - except Exception as e: - logger.error(f"Could not log client disconnect event: {e}") + # Log client disconnect event + try: + log_system_event( + 'client_disconnect', + channel_id=self.channel_id, + channel_name=self.channel_name, + client_ip=self.client_ip, + client_id=self.client_id, + user_agent=self.client_user_agent[:100] if self.client_user_agent else None, + duration=round(elapsed, 2), + bytes_sent=self.bytes_sent, + username=self.user.username if self.user else None + ) + except Exception as e: + logger.error(f"Could not log client disconnect event: {e}") + finally: + close_old_connections() def create_stream_generator(channel_id, client_id, client_ip, client_user_agent, channel_initializing=False, user=None, buffer=None): diff --git a/apps/proxy/live_proxy/server.py b/apps/proxy/live_proxy/server.py index 667daf2f..98346676 100644 --- a/apps/proxy/live_proxy/server.py +++ b/apps/proxy/live_proxy/server.py @@ -760,6 +760,8 @@ class ProxyServer: ) except Exception as e: logger.error(f"Could not log channel start event: {e}") + finally: + close_old_connections() # Create client manager with channel_id, redis_client AND worker_id (only if not already exists) if channel_id not in self.client_managers: @@ -2072,42 +2074,45 @@ class ProxyServer: """Clean up all Redis keys for a channel more efficiently""" total_deleted = 0 - # Release the M3U profile slot while channel_stream / metadata still exist. - # Scanning live:channel keys first deletes metadata and breaks release_stream() - # fallback, leaving profile_connections counters stuck (e.g. profile_connections:70 = 1). try: - channel = Channel.objects.get(uuid=channel_id) - if not channel.release_stream(): - logger.debug(f"Channel {channel_id}: release_stream found no keys to clean") - except (Channel.DoesNotExist, Exception): + # Release the M3U profile slot while channel_stream / metadata still exist. + # Scanning live:channel keys first deletes metadata and breaks release_stream() + # fallback, leaving profile_connections counters stuck (e.g. profile_connections:70 = 1). try: - stream = Stream.objects.get(stream_hash=channel_id) - if not stream.release_stream(): - logger.debug(f"Stream {channel_id}: release_stream found no keys to clean") - except (Stream.DoesNotExist, Exception): - logger.debug(f"No Channel or Stream found for {channel_id}") + channel = Channel.objects.get(uuid=channel_id) + if not channel.release_stream(): + logger.debug(f"Channel {channel_id}: release_stream found no keys to clean") + except (Channel.DoesNotExist, Exception): + try: + stream = Stream.objects.get(stream_hash=channel_id) + if not stream.release_stream(): + logger.debug(f"Stream {channel_id}: release_stream found no keys to clean") + except (Stream.DoesNotExist, Exception): + logger.debug(f"No Channel or Stream found for {channel_id}") - if self.redis_client: - try: - patterns = [ - f"live:channel:{channel_id}:*", - RedisKeys.events_channel(channel_id), - ] + if self.redis_client: + try: + patterns = [ + f"live:channel:{channel_id}:*", + RedisKeys.events_channel(channel_id), + ] - for pattern in patterns: - cursor = 0 - while True: - cursor, keys = self.redis_client.scan(cursor, match=pattern, count=100) - if keys: - self.redis_client.delete(*keys) - total_deleted += len(keys) + for pattern in patterns: + cursor = 0 + while True: + cursor, keys = self.redis_client.scan(cursor, match=pattern, count=100) + if keys: + self.redis_client.delete(*keys) + total_deleted += len(keys) - if cursor == 0: - break + if cursor == 0: + break - logger.info(f"Cleaned up {total_deleted} Redis keys for channel {channel_id}") - except Exception as e: - logger.error(f"Error cleaning Redis keys for channel {channel_id}: {e}") + logger.info(f"Cleaned up {total_deleted} Redis keys for channel {channel_id}") + except Exception as e: + logger.error(f"Error cleaning Redis keys for channel {channel_id}: {e}") + finally: + close_old_connections() return total_deleted diff --git a/core/utils.py b/core/utils.py index 08dda3dc..5931d985 100644 --- a/core/utils.py +++ b/core/utils.py @@ -715,6 +715,7 @@ def log_system_event(event_type, channel_id=None, channel_name=None, **details): stream_url='http://...', user='admin') """ from core.models import SystemEvent, CoreSettings + from django.db import close_old_connections try: # Create the event @@ -750,6 +751,10 @@ def log_system_event(event_type, channel_id=None, channel_name=None, **details): except Exception as e: # Don't let event logging break the main application logger.error(f"Failed to log system event {event_type}: {e}") + finally: + # geventpool keeps checked-out connections until close(); release promptly + # when logging from proxy greenlets/threads outside a normal request cycle. + close_old_connections() def _send_async(channel_layer, group, message): From db40421faa228b59e47125f8e40b188f2d103d7b Mon Sep 17 00:00:00 2001 From: SergeantPanda Date: Mon, 15 Jun 2026 16:50:08 -0500 Subject: [PATCH 5/9] fix(plugins): ensure proper database connection management in plugin actions - Added calls to `close_old_connections()` in `run_action()` and `stop_plugin()` methods to prevent connection leaks after plugin execution. - Updated documentation to clarify connection handling for plugins, emphasizing the importance of cleanup in long-running tasks and event hooks. --- CHANGELOG.md | 1 + Plugins.md | 12 ++ apps/plugins/loader.py | 120 +++++++++--------- apps/plugins/tests/__init__.py | 0 .../tests/test_run_action_db_cleanup.py | 64 ++++++++++ 5 files changed, 140 insertions(+), 57 deletions(-) create mode 100644 apps/plugins/tests/__init__.py create mode 100644 apps/plugins/tests/test_run_action_db_cleanup.py diff --git a/CHANGELOG.md b/CHANGELOG.md index 7e40e04a..01ab218f 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -48,6 +48,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - **Orphaned upstream threads kept writing Redis after teardown.** Partial cleanup could remove a channel from `stream_managers` while the `stream-{uuid}` OS thread kept running, so orphan metadata sweeps only deleted Redis keys and chunks/metadata were immediately recreated (bare `total_bytes` hash with TTL -1). Stream managers now stop upstream when ownership is lost, orphan cleanup stops local ffmpeg/stream threads even when registry entries are gone (`_live_stream_managers` tracks managers until the thread exits), and forced recovery stops processes before Redis deletion instead of dropping dict entries without calling `stop()`. - **Rapid channel switching could leave bare `buffer:index` keys in Redis.** `buffer.stop()` flushed a final partial chunk via `INCR` during teardown, creating a persistent index key (TTL -1) after chunk keys expired; under load overlapping disconnect and cleanup-thread stops could race on `_stop_local_stream_activity`, blocking on ffmpeg stderr join before `_clean_redis_keys` ever ran. Teardown no longer writes to Redis from `buffer.stop()`, disconnect uses coordinated stop only (no duplicate upstream stop), model `release_stream()` runs before Redis keys are scanned/deleted (so `profile_connections` counters are not left stuck), ownership is released after Redis cleanup but before the blocking local ffmpeg stop, and a `finally` block guarantees Redis cleanup if local teardown raises. - **Live proxy could leak geventpool DB checkouts outside HTTP requests.** With `django-db-geventpool`, `connection.close()` returns handles to the per-worker pool (`MAX_CONNS=8`); without it, greenlets and OS threads keep connections checked out until the pool blocks on `pool.get()`. Proxy paths that touch the ORM outside Django's request cycle now call `close_old_connections()` after work completes: `log_system_event()` (all system events), `_clean_redis_keys()`, channel init/start logging, client disconnect cleanup (TS and fMP4 generators), and profile lookup in `_establish_transcode_connection()` before spawning ffmpeg. +- **Plugins could leak geventpool DB checkouts after UI or Connect event runs.** Third-party plugins run inline on uWSGI greenlets (manual actions and Connect `"events"` hooks) with no guaranteed connection cleanup at the plugin boundary. `PluginManager.run_action()` and `stop_plugin()` now call `close_old_connections()` in a `finally` block so each action returns its pool slot whether the plugin succeeds or raises. - **Zombie ffmpeg could survive owner-lock expiry and orphan Redis sweeps.** When the 30s owner lock lapsed under single-worker load, disconnect handling treated the worker as non-owner so coordinated stop never ran, while ffmpeg kept writing and the orphan sweeper only deleted Redis keys (recreating them immediately). Disconnect now re-acquires ownership when local upstream is still active, stops locally when the last client leaves without a lock, orphan cleanup stops local ffmpeg before Redis deletion via `_has_local_upstream_activity`, re-init stops lingering upstream before starting a duplicate thread, and `is_channel_teardown_active` includes channels mid-`stop_channel` on this worker so rapid reconnect gets 503 during teardown. - **Stale `channel_stream` Redis keys after a channel stopped could skip connection accounting on retune.** On `dev`, `get_stream()` reused any existing `channel_stream` / `stream_profile` assignment without reserving a new slot. If those keys were left behind after a stop, the next tune-in could reach the provider without incrementing Redis counters. `get_stream()` now releases stale assignments when proxy metadata shows the channel is inactive, then reserves fresh slots. - **EPG auto-match reliability fixes.** diff --git a/Plugins.md b/Plugins.md index d528f1e4..97e95ed2 100644 --- a/Plugins.md +++ b/Plugins.md @@ -307,6 +307,18 @@ Plugins are server-side Python code running within the Django application. You c Prefer Celery tasks (`.delay()`) to keep `run` fast and non-blocking. +### Database connections + +Dispatcharr uses `django-db-geventpool` with a bounded per-uWSGI-worker pool (`MAX_CONNS=8`). Each greenlet or OS thread that runs ORM code checks out a connection until Django closes it. + +`PluginManager.run_action()` and `stop_plugin()` always call `close_old_connections()` in a `finally` block after your plugin returns (success or error). That returns the current greenlet's checkout to the pool. **You do not need to call `close_old_connections()` yourself for normal inline ORM inside `run()` or `stop()`.** + +Still follow these rules: + +- **Heavy or long work:** dispatch a Celery task (`.delay()`) and return quickly from `run()`. Celery workers close connections after each task; blocking the uWSGI gevent hub with `time.sleep`, sync HTTP, or large CPU work can freeze the whole worker regardless of DB cleanup. +- **Background threads or greenlets you spawn:** each thread/greenlet that uses the ORM must call `close_old_connections()` (or `connection.close()`) in its own `finally` block when done. The wrapper only covers the thread/greenlet that called `run_action()`. +- **Connect event hooks:** actions with an `"events"` list run synchronously inside whatever caller triggered the event (for example a live-proxy system event). Keep event handlers short or defer to Celery. + ### Important: Don’t Ask Users for URL/User/Password Dispatcharr plugins run **inside** the Dispatcharr backend process. That means they already have direct access to the app’s models, tasks, and internal utilities. Plugins **should not** ask users for “Dispatcharr URL”, “Admin Username”, or “Admin Password” just to call the API. That is unnecessary and unsafe because: diff --git a/apps/plugins/loader.py b/apps/plugins/loader.py index a7ecb255..3c275f69 100644 --- a/apps/plugins/loader.py +++ b/apps/plugins/loader.py @@ -10,7 +10,7 @@ import types from dataclasses import dataclass, field from typing import Any, Dict, List, Optional -from django.db import transaction +from django.db import close_old_connections, transaction from .models import PluginConfig @@ -492,79 +492,85 @@ class PluginManager: return cfg.settings def run_action(self, key: str, action_id: str, params: Optional[Dict[str, Any]] = None) -> Dict[str, Any]: - lp = self.get_plugin(key) - if not lp or not lp.instance: - # Attempt a lightweight re-discovery in case the registry was rebuilt - self.discover_plugins(sync_db=False, force_reload=False, use_cache=False) + try: lp = self.get_plugin(key) if not lp or not lp.instance: - raise ValueError(f"Plugin '{key}' not found") + # Attempt a lightweight re-discovery in case the registry was rebuilt + self.discover_plugins(sync_db=False, force_reload=False, use_cache=False) + lp = self.get_plugin(key) + if not lp or not lp.instance: + raise ValueError(f"Plugin '{key}' not found") - cfg = PluginConfig.objects.get(key=key) - if not cfg.enabled: - raise PermissionError(f"Plugin '{key}' is disabled") - params = params or {} + cfg = PluginConfig.objects.get(key=key) + if not cfg.enabled: + raise PermissionError(f"Plugin '{key}' is disabled") + params = params or {} - context = self._build_context(lp, cfg) + context = self._build_context(lp, cfg) - # Run either via Celery if plugin provides a delayed method, or inline - run_method = getattr(lp.instance, "run", None) - if not callable(run_method): - raise ValueError(f"Plugin '{key}' has no runnable 'run' method") + run_method = getattr(lp.instance, "run", None) + if not callable(run_method): + raise ValueError(f"Plugin '{key}' has no runnable 'run' method") - try: - result = run_method(action_id, params, context) - except Exception: - logger.exception(f"Plugin '{key}' action '{action_id}' failed") - raise + try: + result = run_method(action_id, params, context) + except Exception: + logger.exception(f"Plugin '{key}' action '{action_id}' failed") + raise - # Normalize return - if isinstance(result, dict): - return result - return {"status": "ok", "result": result} + if isinstance(result, dict): + return result + return {"status": "ok", "result": result} + finally: + # Return geventpool checkouts for this greenlet/thread after every action, + # including Connect event hooks and manual UI runs. + close_old_connections() def stop_plugin(self, key: str, reason: Optional[str] = None) -> bool: - lp = self.get_plugin(key) - if not lp or not lp.instance: - return False try: - cfg = PluginConfig.objects.get(key=key) - except PluginConfig.DoesNotExist: - return False - if not cfg.enabled: - return False - - context = self._build_context(lp, cfg) - if reason: - context["reason"] = reason - - stop_method = getattr(lp.instance, "stop", None) - if callable(stop_method): + lp = self.get_plugin(key) + if not lp or not lp.instance: + return False try: - stop_method(context) - return True - except TypeError: + cfg = PluginConfig.objects.get(key=key) + except PluginConfig.DoesNotExist: + return False + if not cfg.enabled: + return False + + context = self._build_context(lp, cfg) + if reason: + context["reason"] = reason + + stop_method = getattr(lp.instance, "stop", None) + if callable(stop_method): try: - stop_method() + stop_method(context) return True + except TypeError: + try: + stop_method() + return True + except Exception: + logger.exception("Plugin '%s' stop() failed", key) + return False except Exception: logger.exception("Plugin '%s' stop() failed", key) return False - except Exception: - logger.exception("Plugin '%s' stop() failed", key) - return False - run_method = getattr(lp.instance, "run", None) - if callable(run_method): - actions = {a.get("id") for a in (lp.actions or []) if isinstance(a, dict)} - if "stop" in actions: - try: - run_method("stop", {}, context) - return True - except Exception: - logger.exception("Plugin '%s' stop action failed", key) - return False - return False + run_method = getattr(lp.instance, "run", None) + if callable(run_method): + actions = {a.get("id") for a in (lp.actions or []) if isinstance(a, dict)} + if "stop" in actions: + try: + run_method("stop", {}, context) + return True + except Exception: + logger.exception("Plugin '%s' stop action failed", key) + return False + return False + finally: + close_old_connections() def stop_all_plugins(self, reason: Optional[str] = None) -> int: stopped = 0 diff --git a/apps/plugins/tests/__init__.py b/apps/plugins/tests/__init__.py new file mode 100644 index 00000000..e69de29b diff --git a/apps/plugins/tests/test_run_action_db_cleanup.py b/apps/plugins/tests/test_run_action_db_cleanup.py new file mode 100644 index 00000000..d9a45c88 --- /dev/null +++ b/apps/plugins/tests/test_run_action_db_cleanup.py @@ -0,0 +1,64 @@ +"""PluginManager must release geventpool checkouts after every run/stop.""" + +from contextlib import contextmanager +from unittest.mock import MagicMock, patch + +from django.test import SimpleTestCase + +from apps.plugins.loader import LoadedPlugin, PluginManager + + +class PluginRunActionDbCleanupTests(SimpleTestCase): + @contextmanager + def _manager_with_plugin(self, run_impl): + instance = MagicMock() + instance.run = run_impl + lp = LoadedPlugin( + key="test_plugin", + name="Test Plugin", + instance=instance, + actions=[{"id": "do_work"}], + ) + pm = PluginManager() + cfg = MagicMock(enabled=True, settings={}) + with patch.object(pm, "get_plugin", return_value=lp), patch( + "apps.plugins.loader.PluginConfig.objects.get", return_value=cfg + ): + yield pm + + @patch("apps.plugins.loader.close_old_connections") + def test_run_action_closes_connections_on_success(self, mock_close): + with self._manager_with_plugin(lambda *_a, **_k: {"status": "ok"}) as pm: + result = pm.run_action("test_plugin", "do_work") + + self.assertEqual(result, {"status": "ok"}) + mock_close.assert_called_once() + + @patch("apps.plugins.loader.close_old_connections") + def test_run_action_closes_connections_on_plugin_error(self, mock_close): + def _boom(*_a, **_k): + raise RuntimeError("plugin failed") + + with self._manager_with_plugin(_boom) as pm: + with self.assertRaises(RuntimeError): + pm.run_action("test_plugin", "do_work") + + mock_close.assert_called_once() + + @patch("apps.plugins.loader.close_old_connections") + def test_stop_plugin_closes_connections(self, mock_close): + instance = MagicMock() + instance.stop = MagicMock() + lp = LoadedPlugin( + key="test_plugin", + name="Test Plugin", + instance=instance, + ) + pm = PluginManager() + cfg = MagicMock(enabled=True, settings={}) + with patch.object(pm, "get_plugin", return_value=lp), patch( + "apps.plugins.loader.PluginConfig.objects.get", return_value=cfg + ): + self.assertTrue(pm.stop_plugin("test_plugin", reason="shutdown")) + + mock_close.assert_called_once() From c389462dde4b672accd7547217cc969e20519da8 Mon Sep 17 00:00:00 2001 From: SergeantPanda Date: Mon, 15 Jun 2026 17:14:48 -0500 Subject: [PATCH 6/9] fix(proxy): enhance connection management and event handling during streaming operations - Improved database connection management by ensuring `close_old_connections()` is called in various methods to prevent connection leaks. - Updated event dispatching to run asynchronously in gevent, preventing blocking during live-proxy and streaming paths. --- CHANGELOG.md | 3 +- Plugins.md | 2 +- apps/proxy/live_proxy/input/manager.py | 74 +++++++------- apps/proxy/live_proxy/output/ts/generator.py | 102 +++++++++---------- apps/proxy/live_proxy/server.py | 7 +- core/utils.py | 52 +++++++++- tests/test_log_system_event.py | 55 ++++++++++ 7 files changed, 194 insertions(+), 101 deletions(-) create mode 100644 tests/test_log_system_event.py diff --git a/CHANGELOG.md b/CHANGELOG.md index 01ab218f..e8cacfda 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -47,7 +47,8 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - **Client reconnect during channel teardown could wedge the channel across uWSGI workers.** The disconnect path called `proxy_server.stop_channel()` directly, so other workers were not notified and reconnecting clients could attach while ownership was released on the owner worker. The cleanup thread then re-acquired expired ownership and looped on orphaned clients while the upstream connection stayed open. All lifecycle stops now go through coordinated Redis teardown (`channel_stopping` flag, metadata `stopping` state, and `CHANNEL_STOP` pubsub). New stream requests are rejected with `503 Retry-After` during pending shutdown or active teardown; `initialize_channel()` and ownership re-acquisition refuse to proceed in those states; non-owner workers clean local resources only on pubsub; and orphaned-client sweeps force cleanup when teardown is already active. (Fixes #1342) - **Orphaned upstream threads kept writing Redis after teardown.** Partial cleanup could remove a channel from `stream_managers` while the `stream-{uuid}` OS thread kept running, so orphan metadata sweeps only deleted Redis keys and chunks/metadata were immediately recreated (bare `total_bytes` hash with TTL -1). Stream managers now stop upstream when ownership is lost, orphan cleanup stops local ffmpeg/stream threads even when registry entries are gone (`_live_stream_managers` tracks managers until the thread exits), and forced recovery stops processes before Redis deletion instead of dropping dict entries without calling `stop()`. - **Rapid channel switching could leave bare `buffer:index` keys in Redis.** `buffer.stop()` flushed a final partial chunk via `INCR` during teardown, creating a persistent index key (TTL -1) after chunk keys expired; under load overlapping disconnect and cleanup-thread stops could race on `_stop_local_stream_activity`, blocking on ffmpeg stderr join before `_clean_redis_keys` ever ran. Teardown no longer writes to Redis from `buffer.stop()`, disconnect uses coordinated stop only (no duplicate upstream stop), model `release_stream()` runs before Redis keys are scanned/deleted (so `profile_connections` counters are not left stuck), ownership is released after Redis cleanup but before the blocking local ffmpeg stop, and a `finally` block guarantees Redis cleanup if local teardown raises. -- **Live proxy could leak geventpool DB checkouts outside HTTP requests.** With `django-db-geventpool`, `connection.close()` returns handles to the per-worker pool (`MAX_CONNS=8`); without it, greenlets and OS threads keep connections checked out until the pool blocks on `pool.get()`. Proxy paths that touch the ORM outside Django's request cycle now call `close_old_connections()` after work completes: `log_system_event()` (all system events), `_clean_redis_keys()`, channel init/start logging, client disconnect cleanup (TS and fMP4 generators), and profile lookup in `_establish_transcode_connection()` before spawning ffmpeg. +- **Live proxy could leak geventpool DB checkouts outside HTTP requests.** With `django-db-geventpool`, `connection.close()` returns handles to the per-worker pool (`MAX_CONNS=8`); without it, greenlets and OS threads keep connections checked out until the pool blocks on `pool.get()`. Proxy paths that touch the ORM outside Django's request cycle now call `close_old_connections()` after work completes: `_clean_redis_keys()`, profile lookup in `_establish_transcode_connection()` before spawning ffmpeg, and fMP4 client disconnect cleanup when releasing streams (TS disconnect relies on `log_system_event()`). +- **System events could block callers on Connect and plugin handlers.** `log_system_event()` ran Connect subscriptions and plugin `"events"` hooks synchronously after the DB write, so slow integrations could stall live-proxy and streaming paths even when inserting the event row was fast. Connect/plugin dispatch now runs on a separate gevent when the hub is available (synchronously in Celery workers without a hub). `log_system_event()` and `dispatch_event_system()` also call `close_old_connections()` in `finally` blocks so integration work does not leave pool slots checked out on the caller or dispatch greenlet. - **Plugins could leak geventpool DB checkouts after UI or Connect event runs.** Third-party plugins run inline on uWSGI greenlets (manual actions and Connect `"events"` hooks) with no guaranteed connection cleanup at the plugin boundary. `PluginManager.run_action()` and `stop_plugin()` now call `close_old_connections()` in a `finally` block so each action returns its pool slot whether the plugin succeeds or raises. - **Zombie ffmpeg could survive owner-lock expiry and orphan Redis sweeps.** When the 30s owner lock lapsed under single-worker load, disconnect handling treated the worker as non-owner so coordinated stop never ran, while ffmpeg kept writing and the orphan sweeper only deleted Redis keys (recreating them immediately). Disconnect now re-acquires ownership when local upstream is still active, stops locally when the last client leaves without a lock, orphan cleanup stops local ffmpeg before Redis deletion via `_has_local_upstream_activity`, re-init stops lingering upstream before starting a duplicate thread, and `is_channel_teardown_active` includes channels mid-`stop_channel` on this worker so rapid reconnect gets 503 during teardown. - **Stale `channel_stream` Redis keys after a channel stopped could skip connection accounting on retune.** On `dev`, `get_stream()` reused any existing `channel_stream` / `stream_profile` assignment without reserving a new slot. If those keys were left behind after a stop, the next tune-in could reach the provider without incrementing Redis counters. `get_stream()` now releases stale assignments when proxy metadata shows the channel is inactive, then reserves fresh slots. diff --git a/Plugins.md b/Plugins.md index 97e95ed2..4dc15a55 100644 --- a/Plugins.md +++ b/Plugins.md @@ -317,7 +317,7 @@ Still follow these rules: - **Heavy or long work:** dispatch a Celery task (`.delay()`) and return quickly from `run()`. Celery workers close connections after each task; blocking the uWSGI gevent hub with `time.sleep`, sync HTTP, or large CPU work can freeze the whole worker regardless of DB cleanup. - **Background threads or greenlets you spawn:** each thread/greenlet that uses the ORM must call `close_old_connections()` (or `connection.close()`) in its own `finally` block when done. The wrapper only covers the thread/greenlet that called `run_action()`. -- **Connect event hooks:** actions with an `"events"` list run synchronously inside whatever caller triggered the event (for example a live-proxy system event). Keep event handlers short or defer to Celery. +- **Connect event hooks:** actions with an `"events"` list are dispatched from `log_system_event()` on a separate gevent when uWSGI has an active hub (otherwise synchronously, e.g. Celery). Keep handlers short or defer heavy work to Celery. ### Important: Don’t Ask Users for URL/User/Password Dispatcharr plugins run **inside** the Dispatcharr backend process. That means they already have direct access to the app’s models, tasks, and internal utilities. diff --git a/apps/proxy/live_proxy/input/manager.py b/apps/proxy/live_proxy/input/manager.py index e8315006..7d01a88f 100644 --- a/apps/proxy/live_proxy/input/manager.py +++ b/apps/proxy/live_proxy/input/manager.py @@ -650,48 +650,48 @@ class StreamManager: logger.debug(f"Closing existing HTTP connections before establishing transcode connection for channel {self.channel_id}") self._close_connection() - close_old_connections() - channel = get_stream_object(self.channel_id) + try: + channel = get_stream_object(self.channel_id) - # Use FFmpeg specifically for HLS streams - if hasattr(self, 'force_ffmpeg') and self.force_ffmpeg: - from core.models import StreamProfile - try: - stream_profile = StreamProfile.objects.get(name='ffmpeg', locked=True) - logger.info("Using FFmpeg stream profile for unsupported proxy content (HLS/RTSP/UDP)") - except StreamProfile.DoesNotExist: - # Fall back to channel's profile if FFmpeg not found + # Use FFmpeg specifically for HLS streams + if hasattr(self, 'force_ffmpeg') and self.force_ffmpeg: + from core.models import StreamProfile + try: + stream_profile = StreamProfile.objects.get(name='ffmpeg', locked=True) + logger.info("Using FFmpeg stream profile for unsupported proxy content (HLS/RTSP/UDP)") + except StreamProfile.DoesNotExist: + # Fall back to channel's profile if FFmpeg not found + stream_profile = channel.get_stream_profile() + logger.warning(f"FFmpeg profile not found, using channel default profile for channel: {self.channel_id}") + else: stream_profile = channel.get_stream_profile() - logger.warning(f"FFmpeg profile not found, using channel default profile for channel: {self.channel_id}") - else: - stream_profile = channel.get_stream_profile() - # Build and start transcode command - self.transcode_cmd = stream_profile.build_command(self.url, self.user_agent) + # Build and start transcode command + self.transcode_cmd = stream_profile.build_command(self.url, self.user_agent) - # Store stream command for efficient log parser routing - self.stream_command = stream_profile.command - # Map actual commands to parser types for direct routing - command_to_parser = { - 'ffmpeg': 'ffmpeg', - 'cvlc': 'vlc', - 'vlc': 'vlc', - 'streamlink': 'streamlink' - } - self.parser_type = command_to_parser.get(self.stream_command.lower()) - if self.parser_type: - logger.debug(f"Using {self.parser_type} parser for log parsing (command: {self.stream_command})") - else: - logger.debug(f"Unknown stream command '{self.stream_command}', will use auto-detection for log parsing") + # Store stream command for efficient log parser routing + self.stream_command = stream_profile.command + # Map actual commands to parser types for direct routing + command_to_parser = { + 'ffmpeg': 'ffmpeg', + 'cvlc': 'vlc', + 'vlc': 'vlc', + 'streamlink': 'streamlink' + } + self.parser_type = command_to_parser.get(self.stream_command.lower()) + if self.parser_type: + logger.debug(f"Using {self.parser_type} parser for log parsing (command: {self.stream_command})") + else: + logger.debug(f"Unknown stream command '{self.stream_command}', will use auto-detection for log parsing") - # For UDP streams, remove any user_agent parameters from the command - if hasattr(self, 'stream_type') and self.stream_type == StreamType.UDP: - # Filter out any arguments that contain the user_agent value or related headers - self.transcode_cmd = [arg for arg in self.transcode_cmd if self.user_agent not in arg and 'user-agent' not in arg.lower() and 'user_agent' not in arg.lower()] - logger.debug(f"Removed user_agent parameters from UDP stream command for channel: {self.channel_id}") - - # Profile lookup is done; release the pool slot before a long-lived ffmpeg process. - close_old_connections() + # For UDP streams, remove any user_agent parameters from the command + if hasattr(self, 'stream_type') and self.stream_type == StreamType.UDP: + # Filter out any arguments that contain the user_agent value or related headers + self.transcode_cmd = [arg for arg in self.transcode_cmd if self.user_agent not in arg and 'user-agent' not in arg.lower() and 'user_agent' not in arg.lower()] + logger.debug(f"Removed user_agent parameters from UDP stream command for channel: {self.channel_id}") + finally: + # Release the pool slot before posix_spawn or before returning on profile errors. + close_old_connections() logger.debug(f"Starting transcode process: {self.transcode_cmd} for channel: {self.channel_id}") diff --git a/apps/proxy/live_proxy/output/ts/generator.py b/apps/proxy/live_proxy/output/ts/generator.py index 69dc341f..efde02ad 100644 --- a/apps/proxy/live_proxy/output/ts/generator.py +++ b/apps/proxy/live_proxy/output/ts/generator.py @@ -8,7 +8,6 @@ import gevent from apps.proxy.config import TSConfig as Config from apps.channels.models import Channel, Stream from core.utils import log_system_event -from django.db import close_old_connections from ...server import ProxyServer from ...utils import create_ts_packet, get_logger from ...redis_keys import RedisKeys @@ -591,62 +590,59 @@ class StreamGenerator: def _cleanup(self): """Clean up resources and report final statistics.""" - try: - # Client cleanup - elapsed = time.time() - self.stream_start_time - local_clients = 0 - total_clients = 0 - proxy_server = ProxyServer.get_instance() + # Client cleanup + elapsed = time.time() - self.stream_start_time + local_clients = 0 + total_clients = 0 + proxy_server = ProxyServer.get_instance() - # Release M3U profile stream allocation if this is the last client - stream_released = False - if proxy_server.redis_client: - try: - if self.channel_id in proxy_server.client_managers: - client_count = proxy_server.client_managers[self.channel_id].get_total_client_count() - # Pool slots are global; the last client on any worker must release. - if client_count <= 1: + # Release M3U profile stream allocation if this is the last client + stream_released = False + if proxy_server.redis_client: + try: + if self.channel_id in proxy_server.client_managers: + client_count = proxy_server.client_managers[self.channel_id].get_total_client_count() + # Pool slots are global; the last client on any worker must release. + if client_count <= 1: + try: try: - try: - obj = Channel.objects.get(uuid=self.channel_id) - except (Channel.DoesNotExist, Exception): - obj = Stream.objects.get(stream_hash=self.channel_id) - stream_released = obj.release_stream() - if stream_released: - logger.debug(f"[{self.client_id}] Released stream for channel {self.channel_id}") - else: - logger.warning(f"[{self.client_id}] release_stream found no keys for channel {self.channel_id}") - except Exception as e: - logger.error(f"[{self.client_id}] Error releasing stream for channel {self.channel_id}: {e}") - except Exception as e: - logger.error(f"[{self.client_id}] Error checking stream data for release: {e}") + obj = Channel.objects.get(uuid=self.channel_id) + except (Channel.DoesNotExist, Exception): + obj = Stream.objects.get(stream_hash=self.channel_id) + stream_released = obj.release_stream() + if stream_released: + logger.debug(f"[{self.client_id}] Released stream for channel {self.channel_id}") + else: + logger.warning(f"[{self.client_id}] release_stream found no keys for channel {self.channel_id}") + except Exception as e: + logger.error(f"[{self.client_id}] Error releasing stream for channel {self.channel_id}: {e}") + except Exception as e: + logger.error(f"[{self.client_id}] Error checking stream data for release: {e}") - if self.channel_id in proxy_server.client_managers: - client_manager = proxy_server.client_managers[self.channel_id] - if self.client_id in client_manager.clients: - local_clients = client_manager.remove_client(self.client_id) - else: - local_clients = client_manager.get_client_count() - total_clients = client_manager.get_total_client_count() - logger.info(f"[{self.client_id}] Disconnected after {elapsed:.2f}s (local: {local_clients}, total: {total_clients})") + if self.channel_id in proxy_server.client_managers: + client_manager = proxy_server.client_managers[self.channel_id] + if self.client_id in client_manager.clients: + local_clients = client_manager.remove_client(self.client_id) + else: + local_clients = client_manager.get_client_count() + total_clients = client_manager.get_total_client_count() + logger.info(f"[{self.client_id}] Disconnected after {elapsed:.2f}s (local: {local_clients}, total: {total_clients})") - # Log client disconnect event - try: - log_system_event( - 'client_disconnect', - channel_id=self.channel_id, - channel_name=self.channel_name, - client_ip=self.client_ip, - client_id=self.client_id, - user_agent=self.client_user_agent[:100] if self.client_user_agent else None, - duration=round(elapsed, 2), - bytes_sent=self.bytes_sent, - username=self.user.username if self.user else None - ) - except Exception as e: - logger.error(f"Could not log client disconnect event: {e}") - finally: - close_old_connections() + # Log client disconnect event + try: + log_system_event( + 'client_disconnect', + channel_id=self.channel_id, + channel_name=self.channel_name, + client_ip=self.client_ip, + client_id=self.client_id, + user_agent=self.client_user_agent[:100] if self.client_user_agent else None, + duration=round(elapsed, 2), + bytes_sent=self.bytes_sent, + username=self.user.username if self.user else None + ) + except Exception as e: + logger.error(f"Could not log client disconnect event: {e}") def create_stream_generator(channel_id, client_id, client_ip, client_user_agent, channel_initializing=False, user=None, buffer=None): diff --git a/apps/proxy/live_proxy/server.py b/apps/proxy/live_proxy/server.py index 98346676..3cb1fdae 100644 --- a/apps/proxy/live_proxy/server.py +++ b/apps/proxy/live_proxy/server.py @@ -760,7 +760,6 @@ class ProxyServer: ) except Exception as e: logger.error(f"Could not log channel start event: {e}") - finally: close_old_connections() # Create client manager with channel_id, redis_client AND worker_id (only if not already exists) @@ -1367,11 +1366,7 @@ class ProxyServer: return def _log_stop(): - try: - close_old_connections() - log_system_event('channel_stop', **stop_event_data) - except Exception as e: - logger.error(f"Could not log channel stop event: {e}") + log_system_event('channel_stop', **stop_event_data) gevent.spawn(_log_stop) diff --git a/core/utils.py b/core/utils.py index 5931d985..188d9cb2 100644 --- a/core/utils.py +++ b/core/utils.py @@ -623,6 +623,8 @@ def validate_flexible_url(value): raise ValidationError("Enter a valid URL.") def dispatch_event_system(event_type, channel_id=None, channel_name=None, **details): + from django.db import close_old_connections + try: from apps.connect.utils import trigger_event from apps.channels.models import Channel, Stream @@ -696,9 +698,48 @@ def dispatch_event_system(event_type, channel_id=None, channel_name=None, **deta trigger_event(event_type, payload) - except Exception as e: + except Exception: # Don't fail main path if connect dispatch fails pass + finally: + close_old_connections() + + +def _dispatch_system_event_integrations( + event_type, channel_id=None, channel_name=None, **details +): + """ + Run Connect subscriptions and plugin event hooks without blocking the caller. + + On gevent uWSGI workers, dispatch runs in a spawned greenlet so slow webhooks, + scripts, or plugin handlers cannot stall live-proxy teardown or streaming paths. + Celery prefork workers (gevent patched but no hub) run synchronously instead. + """ + + def _run(): + try: + dispatch_event_system( + event_type, + channel_id=channel_id, + channel_name=channel_name, + **details, + ) + except Exception as e: + logger.error( + "Failed to dispatch Connect/plugin handlers for event %s: %s", + event_type, + e, + ) + + if _should_use_sync_websocket_send(): + _run() + elif _is_gevent_monkey_patched(): + import gevent + + gevent.spawn(_run) + else: + _run() + def log_system_event(event_type, channel_id=None, channel_name=None, **details): """ @@ -726,8 +767,13 @@ def log_system_event(event_type, channel_id=None, channel_name=None, **details): details=details ) - # Trigger connect integrations for specific events - dispatch_event_system(event_type, channel_id=channel_id, channel_name=channel_name, **details) + # Connect integrations and plugin event hooks (non-blocking on gevent uWSGI) + _dispatch_system_event_integrations( + event_type, + channel_id=channel_id, + channel_name=channel_name, + **details, + ) # Get max events from settings (default 100) try: diff --git a/tests/test_log_system_event.py b/tests/test_log_system_event.py new file mode 100644 index 00000000..6ff92ff4 --- /dev/null +++ b/tests/test_log_system_event.py @@ -0,0 +1,55 @@ +"""Tests for log_system_event Connect/plugin dispatch and DB cleanup.""" + +from unittest.mock import patch + +from django.test import SimpleTestCase + + +class LogSystemEventDispatchTests(SimpleTestCase): + @patch("django.db.close_old_connections") + @patch("core.utils._dispatch_system_event_integrations") + @patch("core.models.SystemEvent.objects") + @patch("core.models.CoreSettings.objects") + def test_log_system_event_dispatches_integrations_and_closes_db( + self, mock_core_settings, mock_system_event, mock_dispatch, mock_close + ): + mock_system_event.count.return_value = 1 + mock_core_settings.filter.return_value.first.return_value = None + + from core.utils import log_system_event + + log_system_event("channel_start", channel_id="abc", channel_name="Test") + + mock_dispatch.assert_called_once_with( + "channel_start", + channel_id="abc", + channel_name="Test", + ) + mock_close.assert_called_once() + + @patch("django.db.close_old_connections") + @patch("apps.connect.utils.trigger_event") + def test_integration_dispatch_closes_db_on_sync_path( + self, mock_trigger, mock_close + ): + from core.utils import _dispatch_system_event_integrations + + with patch("core.utils._should_use_sync_websocket_send", return_value=True): + _dispatch_system_event_integrations("client_connect", channel_id="abc") + + mock_trigger.assert_called_once() + mock_close.assert_called_once() + + @patch("core.utils.dispatch_event_system") + def test_integration_dispatch_spawns_on_gevent_uwsgi( + self, mock_dispatch + ): + from core.utils import _dispatch_system_event_integrations + + with patch("core.utils._should_use_sync_websocket_send", return_value=False), patch( + "core.utils._is_gevent_monkey_patched", return_value=True + ), patch("gevent.spawn") as mock_spawn: + _dispatch_system_event_integrations("channel_stop", channel_id="abc") + + mock_spawn.assert_called_once() + mock_dispatch.assert_not_called() From 7989fa3673a58888befa9977d451626fac7d48a4 Mon Sep 17 00:00:00 2001 From: SergeantPanda Date: Mon, 15 Jun 2026 17:32:38 -0500 Subject: [PATCH 7/9] fix(proxy): enhance database connection management during VOD playback and stats updates - Added calls to `close_old_connections()` in `stream_vod()` and `build_vod_stats_data()` to prevent connection leaks during long-lived streaming responses and background stats refreshes. - Improved connection handling in various components to ensure proper resource cleanup and prevent blocking issues. --- CHANGELOG.md | 1 + .../tests/test_ts_proxy_ghost_clients.py | 8 + .../channels/tests/test_ts_proxy_keepalive.py | 12 +- apps/channels/tests/test_ts_proxy_teardown.py | 12 +- apps/proxy/live_proxy/input/manager.py | 15 +- apps/proxy/live_proxy/server.py | 17 +- .../vod_proxy/tests/test_vod_db_cleanup.py | 146 ++++++++++++++++++ apps/proxy/vod_proxy/views.py | 6 + 8 files changed, 198 insertions(+), 19 deletions(-) create mode 100644 apps/proxy/vod_proxy/tests/test_vod_db_cleanup.py diff --git a/CHANGELOG.md b/CHANGELOG.md index e8cacfda..acce9b4e 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -50,6 +50,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - **Live proxy could leak geventpool DB checkouts outside HTTP requests.** With `django-db-geventpool`, `connection.close()` returns handles to the per-worker pool (`MAX_CONNS=8`); without it, greenlets and OS threads keep connections checked out until the pool blocks on `pool.get()`. Proxy paths that touch the ORM outside Django's request cycle now call `close_old_connections()` after work completes: `_clean_redis_keys()`, profile lookup in `_establish_transcode_connection()` before spawning ffmpeg, and fMP4 client disconnect cleanup when releasing streams (TS disconnect relies on `log_system_event()`). - **System events could block callers on Connect and plugin handlers.** `log_system_event()` ran Connect subscriptions and plugin `"events"` hooks synchronously after the DB write, so slow integrations could stall live-proxy and streaming paths even when inserting the event row was fast. Connect/plugin dispatch now runs on a separate gevent when the hub is available (synchronously in Celery workers without a hub). `log_system_event()` and `dispatch_event_system()` also call `close_old_connections()` in `finally` blocks so integration work does not leave pool slots checked out on the caller or dispatch greenlet. - **Plugins could leak geventpool DB checkouts after UI or Connect event runs.** Third-party plugins run inline on uWSGI greenlets (manual actions and Connect `"events"` hooks) with no guaranteed connection cleanup at the plugin boundary. `PluginManager.run_action()` and `stop_plugin()` now call `close_old_connections()` in a `finally` block so each action returns its pool slot whether the plugin succeeds or raises. +- **VOD proxy could leak geventpool DB checkouts during playback and stats updates.** `stream_vod()` ran ORM lookups for content and M3U profiles, then returned a long-lived `StreamingHttpResponse` without releasing the checkout, so each movie/episode stream could hold a pool slot for its full duration. Background VOD stats refresh (`build_vod_stats_data()`, triggered on start/stop and by the admin stats API) also queried movie, episode, and profile rows from daemon threads with no cleanup. `stream_vod()` now calls `close_old_connections()` before handing off to the streaming generator, and `build_vod_stats_data()` releases its checkout in a `finally` block. - **Zombie ffmpeg could survive owner-lock expiry and orphan Redis sweeps.** When the 30s owner lock lapsed under single-worker load, disconnect handling treated the worker as non-owner so coordinated stop never ran, while ffmpeg kept writing and the orphan sweeper only deleted Redis keys (recreating them immediately). Disconnect now re-acquires ownership when local upstream is still active, stops locally when the last client leaves without a lock, orphan cleanup stops local ffmpeg before Redis deletion via `_has_local_upstream_activity`, re-init stops lingering upstream before starting a duplicate thread, and `is_channel_teardown_active` includes channels mid-`stop_channel` on this worker so rapid reconnect gets 503 during teardown. - **Stale `channel_stream` Redis keys after a channel stopped could skip connection accounting on retune.** On `dev`, `get_stream()` reused any existing `channel_stream` / `stream_profile` assignment without reserving a new slot. If those keys were left behind after a stop, the next tune-in could reach the provider without incrementing Redis counters. `get_stream()` now releases stale assignments when proxy metadata shows the channel is inactive, then reserves fresh slots. - **EPG auto-match reliability fixes.** diff --git a/apps/channels/tests/test_ts_proxy_ghost_clients.py b/apps/channels/tests/test_ts_proxy_ghost_clients.py index 6742cf4b..3cc7aa9e 100644 --- a/apps/channels/tests/test_ts_proxy_ghost_clients.py +++ b/apps/channels/tests/test_ts_proxy_ghost_clients.py @@ -247,6 +247,14 @@ class BasicStatsGhostClientTests(TestCase): redis.scard.return_value = len(client_ids) redis.smembers.return_value = client_ids redis.hget.return_value = None # individual field lookups + redis.hmget.return_value = [ + b'VLC/3.0', + b'127.0.0.1', + b'1773500000.0', + None, + b'mpegts', + None, + ] # Pipeline for remove_ghost_clients pipe = MagicMock() diff --git a/apps/channels/tests/test_ts_proxy_keepalive.py b/apps/channels/tests/test_ts_proxy_keepalive.py index b8fb524a..8645a158 100644 --- a/apps/channels/tests/test_ts_proxy_keepalive.py +++ b/apps/channels/tests/test_ts_proxy_keepalive.py @@ -218,7 +218,7 @@ class DoStatsUpdateTests(TestCase): mock_redis.scan.return_value = (0, []) with patch("apps.proxy.live_proxy.client_manager.send_websocket_update") as mock_ws, \ - patch("redis.Redis.from_url", return_value=mock_redis): + patch("core.utils.RedisClient.get_client", return_value=mock_redis): cm._do_stats_update() mock_ws.assert_called_once() @@ -231,25 +231,25 @@ class DoStatsUpdateTests(TestCase): """Redis failure must be swallowed (logged), not propagated.""" cm = self._make_client_manager() - with patch("redis.Redis.from_url", side_effect=Exception("Redis down")): + with patch("core.utils.RedisClient.get_client", side_effect=Exception("Redis down")): try: cm._do_stats_update() except Exception as e: self.fail(f"_do_stats_update raised an exception: {e}") - def test_do_stats_update_scans_channel_client_keys(self): - """Must scan for live:channel:*:clients pattern.""" + def test_do_stats_update_scans_channel_metadata_keys(self): + """Must scan for live:channel:*:metadata pattern.""" cm = self._make_client_manager() mock_redis = MagicMock() mock_redis.scan.return_value = (0, []) with patch("apps.proxy.live_proxy.client_manager.send_websocket_update"), \ - patch("redis.Redis.from_url", return_value=mock_redis): + patch("core.utils.RedisClient.get_client", return_value=mock_redis): cm._do_stats_update() scan_call = mock_redis.scan.call_args - self.assertIn("live:channel:*:clients", str(scan_call)) + self.assertIn("live:channel:*:metadata", str(scan_call)) # --------------------------------------------------------------------------- diff --git a/apps/channels/tests/test_ts_proxy_teardown.py b/apps/channels/tests/test_ts_proxy_teardown.py index 3bc92f18..593df034 100644 --- a/apps/channels/tests/test_ts_proxy_teardown.py +++ b/apps/channels/tests/test_ts_proxy_teardown.py @@ -390,17 +390,21 @@ class CleanRedisKeysOrderTests(TestCase): mock_channel_get.side_effect = channel_get mock_stream_get.side_effect = Stream.DoesNotExist - def scan(*args, **kwargs): + channel_key = f"live:channel:{CHANNEL_ID}:input:buffer:index".encode() + + def scan(cursor, match=None, count=100): call_order.append("redis") - return (0, [b"live:channel:foo:buffer:index"]) + if match == f"live:channel:{CHANNEL_ID}:*": + return (0, [channel_key]) + return (0, []) server.redis_client.scan.side_effect = scan server._clean_redis_keys(CHANNEL_ID) - self.assertEqual(call_order, ["release", "redis"]) + self.assertEqual(call_order, ["release", "redis", "redis"]) channel.release_stream.assert_called_once() - server.redis_client.delete.assert_called_once() + server.redis_client.delete.assert_called_once_with(channel_key) class LocalUpstreamActivityTests(TestCase): diff --git a/apps/proxy/live_proxy/input/manager.py b/apps/proxy/live_proxy/input/manager.py index 7d01a88f..3c7c147d 100644 --- a/apps/proxy/live_proxy/input/manager.py +++ b/apps/proxy/live_proxy/input/manager.py @@ -67,6 +67,7 @@ class StreamManager: # Add to your __init__ method self._buffer_check_timers = [] self.stopping = False + self.stop_requested = False # Add tracking for tried streams and current stream self.current_stream_id = stream_id @@ -572,7 +573,9 @@ class StreamManager: try: metadata_key = RedisKeys.channel_metadata(self.channel_id) owner_key = RedisKeys.channel_owner(self.channel_id) - current_owner = self.buffer.redis_client.get(owner_key) + current_owner = self._decode_redis_value( + self.buffer.redis_client.get(owner_key) + ) is_owner = ( current_owner @@ -583,12 +586,10 @@ class StreamManager: should_update = is_owner if not should_update and no_owner: - current_state_bytes = self.buffer.redis_client.hget( - metadata_key, ChannelMetadataField.STATE - ) - current_state = ( - current_state_bytes - if current_state_bytes else None + current_state = self._decode_redis_value( + self.buffer.redis_client.hget( + metadata_key, ChannelMetadataField.STATE + ) ) should_update = current_state in ChannelState.PRE_ACTIVE if not should_update and current_state: diff --git a/apps/proxy/live_proxy/server.py b/apps/proxy/live_proxy/server.py index 3cb1fdae..ddec2d02 100644 --- a/apps/proxy/live_proxy/server.py +++ b/apps/proxy/live_proxy/server.py @@ -1402,6 +1402,15 @@ class ProxyServer: f"Error broadcasting upstream stop for channel {channel_id}: {e}" ) + @staticmethod + def _channel_id_from_metadata_key(key): + if isinstance(key, bytes): + key = key.decode('utf-8', errors='replace') + parts = key.split(':') + if len(parts) >= 3: + return parts[2] + return None + def _stop_upstream_before_redis_cleanup(self, channel_id): """Stop local ffmpeg before deleting Redis keys (prevents delete/recreate loops).""" if self._has_local_upstream_activity(channel_id): @@ -1955,7 +1964,9 @@ class ProxyServer: for key in channel_keys: try: - channel_id = key.split(':')[2] + channel_id = self._channel_id_from_metadata_key(key) + if not channel_id: + continue # Check if this channel has an owner owner = self.get_channel_owner(channel_id) @@ -1995,7 +2006,9 @@ class ProxyServer: for key in channel_keys: try: - channel_id = key.split(':')[2] + channel_id = self._channel_id_from_metadata_key(key) + if not channel_id: + continue # Get metadata first metadata = self.redis_client.hgetall(key) diff --git a/apps/proxy/vod_proxy/tests/test_vod_db_cleanup.py b/apps/proxy/vod_proxy/tests/test_vod_db_cleanup.py new file mode 100644 index 00000000..5d009803 --- /dev/null +++ b/apps/proxy/vod_proxy/tests/test_vod_db_cleanup.py @@ -0,0 +1,146 @@ +"""VOD proxy must release geventpool checkouts after ORM on stream and stats paths.""" + +from unittest.mock import MagicMock, patch + +from django.http import StreamingHttpResponse +from django.test import RequestFactory, SimpleTestCase + + +class StreamVodDbCleanupTests(SimpleTestCase): + def setUp(self): + self.factory = RequestFactory() + + @patch("apps.proxy.vod_proxy.views.close_old_connections") + @patch("apps.proxy.vod_proxy.views.MultiWorkerVODConnectionManager") + @patch("apps.proxy.vod_proxy.views._transform_url", return_value="http://example.com/movie.mp4") + @patch("apps.proxy.vod_proxy.views._get_m3u_profile") + @patch("apps.proxy.vod_proxy.views._get_stream_url_from_relation", return_value="http://upstream/movie.mp4") + @patch("apps.proxy.vod_proxy.views._get_content_and_relation") + @patch("apps.proxy.vod_proxy.views.network_access_allowed", return_value=True) + def test_stream_vod_closes_db_before_streaming_response( + self, + _network_ok, + mock_content, + _stream_url, + mock_profile, + _transform, + mock_manager_cls, + mock_close, + ): + movie = MagicMock() + movie.name = "Test Movie" + relation = MagicMock() + relation.m3u_account.name = "Provider" + mock_content.return_value = (movie, relation) + + profile = MagicMock() + profile.id = 1 + profile.max_streams = 5 + mock_profile.return_value = (profile, 0) + + mock_manager = MagicMock() + mock_manager.stream_content_with_session.return_value = StreamingHttpResponse( + streaming_content=iter([b"data"]), + content_type="video/mp4", + ) + mock_manager_cls.get_instance.return_value = mock_manager + + request = self.factory.get( + "/proxy/vod/movie/uuid/session123/", + HTTP_USER_AGENT="test-agent", + ) + request.user = MagicMock(is_authenticated=False) + + from apps.proxy.vod_proxy.views import stream_vod + + response = stream_vod( + request, + content_type="movie", + content_id="uuid", + session_id="session123", + ) + + self.assertIsInstance(response, StreamingHttpResponse) + mock_close.assert_called_once() + mock_manager.stream_content_with_session.assert_called_once() + + +class BuildVodStatsDbCleanupTests(SimpleTestCase): + @patch("apps.proxy.vod_proxy.views.close_old_connections") + @patch("apps.proxy.vod_proxy.views.Movie") + def test_build_vod_stats_data_closes_db(self, mock_movie, mock_close): + redis_client = MagicMock() + redis_client.scan.side_effect = [ + (0, ["vod_persistent_connection:s1"]), + ] + redis_client.hgetall.return_value = { + "content_obj_type": "movie", + "content_uuid": "movie-uuid", + "content_name": "Test Movie", + "m3u_profile_id": "1", + "client_ip": "127.0.0.1", + "client_user_agent": "agent", + "connected_at": "1000.0", + "last_activity": "1001.0", + "active_streams": "1", + } + + movie_obj = MagicMock( + name="Test Movie", + logo=None, + year=2020, + rating=7.5, + genre="Action", + description="Desc", + tmdb_id="1", + imdb_id="tt1", + ) + mock_movie.objects.select_related.return_value.get.return_value = movie_obj + + with patch("apps.m3u.models.M3UAccountProfile") as mock_profile_model: + mock_profile_model.objects.select_related.return_value.get.return_value = MagicMock( + name="Profile 1", + m3u_account=MagicMock(name="Account", id=1), + ) + + from apps.proxy.vod_proxy.views import build_vod_stats_data + + stats = build_vod_stats_data(redis_client) + + self.assertEqual(stats["total_connections"], 1) + mock_close.assert_called_once() + + @patch("apps.proxy.vod_proxy.views.close_old_connections") + def test_build_vod_stats_data_closes_db_on_error(self, mock_close): + redis_client = MagicMock() + redis_client.scan.side_effect = RuntimeError("redis down") + + from apps.proxy.vod_proxy.views import build_vod_stats_data + + stats = build_vod_stats_data(redis_client) + + self.assertEqual(stats["total_connections"], 0) + mock_close.assert_called_once() + + +class VodStatsUpdateDbCleanupTests(SimpleTestCase): + @patch("core.utils.send_websocket_update") + @patch("apps.proxy.vod_proxy.views.build_vod_stats_data") + def test_do_vod_stats_update_uses_build_vod_stats_data(self, mock_build, mock_ws): + mock_build.return_value = { + "vod_connections": [], + "total_connections": 0, + "timestamp": 0, + } + + from apps.proxy.vod_proxy.multi_worker_connection_manager import ( + MultiWorkerVODConnectionManager, + ) + + manager = MultiWorkerVODConnectionManager.__new__(MultiWorkerVODConnectionManager) + manager.redis_client = MagicMock() + + manager._do_vod_stats_update() + + mock_build.assert_called_once_with(manager.redis_client) + mock_ws.assert_called_once() diff --git a/apps/proxy/vod_proxy/views.py b/apps/proxy/vod_proxy/views.py index f9740aa1..fef8fed0 100644 --- a/apps/proxy/vod_proxy/views.py +++ b/apps/proxy/vod_proxy/views.py @@ -8,6 +8,7 @@ import random import logging import requests from urllib.parse import urlencode +from django.db import close_old_connections from django.http import JsonResponse, Http404, HttpResponse from django.shortcuts import get_object_or_404 from django.views.decorators.csrf import csrf_exempt @@ -601,6 +602,9 @@ def stream_vod(request, content_type, content_id, session_id=None, profile_id=No # Get connection manager (Redis-backed for multi-worker support) connection_manager = MultiWorkerVODConnectionManager.get_instance() + # Release ORM checkout before returning a long-lived StreamingHttpResponse. + close_old_connections() + # Stream the content with session-based connection reuse logger.info("[VOD-STREAM] Calling connection manager to stream content") response = connection_manager.stream_content_with_session( @@ -1063,6 +1067,8 @@ def build_vod_stats_data(redis_client): except Exception as e: logger.error(f"Error building VOD stats: {e}") return {'vod_connections': [], 'total_connections': 0, 'timestamp': time.time()} + finally: + close_old_connections() @api_view(["GET"]) From 32442e0b6401662ce3cf0452fa1ce34fad90b2f3 Mon Sep 17 00:00:00 2001 From: SergeantPanda Date: Mon, 15 Jun 2026 18:53:49 -0500 Subject: [PATCH 8/9] fix(proxy): enhance channel shutdown management and client reconnection handling - Improved the handling of channel shutdown delays to ensure they reset correctly upon client reconnections, preventing premature shutdowns. - Implemented logic to cancel pending shutdowns when clients reconnect, ensuring proper resource management and preventing client disconnect issues across uWSGI workers. - Enhanced logging for shutdown processes and client management to provide clearer insights during channel operations. --- CHANGELOG.md | 3 +- apps/channels/tests/test_ts_proxy_teardown.py | 163 +++++++++++++++++- apps/proxy/live_proxy/client_manager.py | 16 +- .../proxy/live_proxy/output/fmp4/generator.py | 6 +- apps/proxy/live_proxy/output/ts/generator.py | 3 +- apps/proxy/live_proxy/server.py | 109 ++++++++++-- .../live_proxy/services/channel_service.py | 101 ++++++++++- 7 files changed, 378 insertions(+), 23 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index acce9b4e..fd70a28e 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -44,13 +44,14 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Fixed - **Live proxy channels could remain running with no clients after disconnect.** `stop_channel` called `log_system_event('channel_stop')` synchronously before local cleanup and Redis key deletion; Connect integrations or DB event writes on that path could block teardown indefinitely while the cleanup thread kept refreshing metadata TTL for a stale `stream_buffers` entry. Teardown now signals shutdown (`buffer.stopping`), runs model `release_stream()` and Redis key deletion, releases ownership, stops ffmpeg/output managers and local buffers, and only then logs the stop event asynchronously. Metadata TTL refresh skips channels mid-shutdown and non-owned channels; a stuck-stop watchdog forces cleanup if `stop_channel` does not return within ~10s (or 2× `channel_shutdown_delay`, whichever is greater). Stream buffers ignore late `add_chunk()` writes once shutdown begins (`buffer.stopping` set at teardown start). -- **Client reconnect during channel teardown could wedge the channel across uWSGI workers.** The disconnect path called `proxy_server.stop_channel()` directly, so other workers were not notified and reconnecting clients could attach while ownership was released on the owner worker. The cleanup thread then re-acquired expired ownership and looped on orphaned clients while the upstream connection stayed open. All lifecycle stops now go through coordinated Redis teardown (`channel_stopping` flag, metadata `stopping` state, and `CHANNEL_STOP` pubsub). New stream requests are rejected with `503 Retry-After` during pending shutdown or active teardown; `initialize_channel()` and ownership re-acquisition refuse to proceed in those states; non-owner workers clean local resources only on pubsub; and orphaned-client sweeps force cleanup when teardown is already active. (Fixes #1342) +- **Client reconnect during channel teardown could wedge the channel across uWSGI workers.** The disconnect path called `proxy_server.stop_channel()` directly, so other workers were not notified and reconnecting clients could attach while ownership was released on the owner worker. The cleanup thread then re-acquired expired ownership and looped on orphaned clients while the upstream connection stayed open. All lifecycle stops now go through coordinated Redis teardown (`channel_stopping` flag, metadata `stopping` state, and `CHANNEL_STOP` pubsub). New stream requests are rejected with `503 Retry-After` only during active teardown (not during the post-disconnect shutdown delay grace period); `initialize_channel()` and ownership re-acquisition refuse to proceed in those states; non-owner workers clean local resources only on pubsub; and orphaned-client sweeps force cleanup when teardown is already active. (Fixes #1342) - **Orphaned upstream threads kept writing Redis after teardown.** Partial cleanup could remove a channel from `stream_managers` while the `stream-{uuid}` OS thread kept running, so orphan metadata sweeps only deleted Redis keys and chunks/metadata were immediately recreated (bare `total_bytes` hash with TTL -1). Stream managers now stop upstream when ownership is lost, orphan cleanup stops local ffmpeg/stream threads even when registry entries are gone (`_live_stream_managers` tracks managers until the thread exits), and forced recovery stops processes before Redis deletion instead of dropping dict entries without calling `stop()`. - **Rapid channel switching could leave bare `buffer:index` keys in Redis.** `buffer.stop()` flushed a final partial chunk via `INCR` during teardown, creating a persistent index key (TTL -1) after chunk keys expired; under load overlapping disconnect and cleanup-thread stops could race on `_stop_local_stream_activity`, blocking on ffmpeg stderr join before `_clean_redis_keys` ever ran. Teardown no longer writes to Redis from `buffer.stop()`, disconnect uses coordinated stop only (no duplicate upstream stop), model `release_stream()` runs before Redis keys are scanned/deleted (so `profile_connections` counters are not left stuck), ownership is released after Redis cleanup but before the blocking local ffmpeg stop, and a `finally` block guarantees Redis cleanup if local teardown raises. - **Live proxy could leak geventpool DB checkouts outside HTTP requests.** With `django-db-geventpool`, `connection.close()` returns handles to the per-worker pool (`MAX_CONNS=8`); without it, greenlets and OS threads keep connections checked out until the pool blocks on `pool.get()`. Proxy paths that touch the ORM outside Django's request cycle now call `close_old_connections()` after work completes: `_clean_redis_keys()`, profile lookup in `_establish_transcode_connection()` before spawning ffmpeg, and fMP4 client disconnect cleanup when releasing streams (TS disconnect relies on `log_system_event()`). - **System events could block callers on Connect and plugin handlers.** `log_system_event()` ran Connect subscriptions and plugin `"events"` hooks synchronously after the DB write, so slow integrations could stall live-proxy and streaming paths even when inserting the event row was fast. Connect/plugin dispatch now runs on a separate gevent when the hub is available (synchronously in Celery workers without a hub). `log_system_event()` and `dispatch_event_system()` also call `close_old_connections()` in `finally` blocks so integration work does not leave pool slots checked out on the caller or dispatch greenlet. - **Plugins could leak geventpool DB checkouts after UI or Connect event runs.** Third-party plugins run inline on uWSGI greenlets (manual actions and Connect `"events"` hooks) with no guaranteed connection cleanup at the plugin boundary. `PluginManager.run_action()` and `stop_plugin()` now call `close_old_connections()` in a `finally` block so each action returns its pool slot whether the plugin succeeds or raises. - **VOD proxy could leak geventpool DB checkouts during playback and stats updates.** `stream_vod()` ran ORM lookups for content and M3U profiles, then returned a long-lived `StreamingHttpResponse` without releasing the checkout, so each movie/episode stream could hold a pool slot for its full duration. Background VOD stats refresh (`build_vod_stats_data()`, triggered on start/stop and by the admin stats API) also queried movie, episode, and profile rows from daemon threads with no cleanup. `stream_vod()` now calls `close_old_connections()` before handing off to the streaming generator, and `build_vod_stats_data()` releases its checkout in a `finally` block. +- **Channel shutdown delay did not reset after a reconnect within the grace period.** `handle_client_disconnect()` used a fixed `gevent.sleep(shutdown_delay)` from the first last-client disconnect. If a client reconnected and disconnected again during the delay, an earlier disconnect handler could still stop the channel on the original timer instead of waiting the full delay from the latest disconnect. Shutdown now polls Redis (`last_client_disconnect` timestamp and client count) so concurrent disconnect handlers and multi-worker reconnects always honour the latest disconnect time. - **Zombie ffmpeg could survive owner-lock expiry and orphan Redis sweeps.** When the 30s owner lock lapsed under single-worker load, disconnect handling treated the worker as non-owner so coordinated stop never ran, while ffmpeg kept writing and the orphan sweeper only deleted Redis keys (recreating them immediately). Disconnect now re-acquires ownership when local upstream is still active, stops locally when the last client leaves without a lock, orphan cleanup stops local ffmpeg before Redis deletion via `_has_local_upstream_activity`, re-init stops lingering upstream before starting a duplicate thread, and `is_channel_teardown_active` includes channels mid-`stop_channel` on this worker so rapid reconnect gets 503 during teardown. - **Stale `channel_stream` Redis keys after a channel stopped could skip connection accounting on retune.** On `dev`, `get_stream()` reused any existing `channel_stream` / `stream_profile` assignment without reserving a new slot. If those keys were left behind after a stop, the next tune-in could reach the provider without incrementing Redis counters. `get_stream()` now releases stale assignments when proxy metadata shows the channel is inactive, then reserves fresh slots. - **EPG auto-match reliability fixes.** diff --git a/apps/channels/tests/test_ts_proxy_teardown.py b/apps/channels/tests/test_ts_proxy_teardown.py index 593df034..20fd92ea 100644 --- a/apps/channels/tests/test_ts_proxy_teardown.py +++ b/apps/channels/tests/test_ts_proxy_teardown.py @@ -41,6 +41,7 @@ def _configure_ownership_pipeline( def _mock_proxy_server(redis_client=None): server = MagicMock() server.redis_client = redis_client or MagicMock() + server._stopping_channels = set() return server @@ -72,7 +73,47 @@ class ChannelTeardownAvailabilityTests(TestCase): mock_get_instance.return_value = _mock_proxy_server(redis) self.assertTrue(ChannelService.is_shutdown_pending(CHANNEL_ID)) - self.assertTrue(ChannelService.is_channel_unavailable_for_new_clients(CHANNEL_ID)) + self.assertFalse(ChannelService.is_channel_unavailable_for_new_clients(CHANNEL_ID)) + + @patch("apps.proxy.live_proxy.services.channel_service.ConfigHelper.channel_shutdown_delay") + @patch("apps.proxy.live_proxy.services.channel_service.ProxyServer.get_instance") + def test_cancel_pending_shutdown_clears_disconnect_key(self, mock_get_instance, mock_delay): + mock_delay.return_value = 30 + redis = MagicMock() + redis.exists.side_effect = lambda key: "last_client_disconnect" in key + redis.get.return_value = None + redis.hget.return_value = ChannelState.ACTIVE.encode() + mock_get_instance.return_value = _mock_proxy_server(redis) + + self.assertTrue(ChannelService.cancel_pending_shutdown(CHANNEL_ID)) + redis.delete.assert_any_call(RedisKeys.last_client_disconnect(CHANNEL_ID)) + + @patch("apps.proxy.live_proxy.services.channel_service.ConfigHelper.channel_shutdown_delay") + @patch("apps.proxy.live_proxy.services.channel_service.ProxyServer.get_instance") + def test_cancel_pending_shutdown_skips_during_active_stop(self, mock_get_instance, mock_delay): + mock_delay.return_value = 30 + redis = MagicMock() + redis.exists.return_value = True + server = _mock_proxy_server(redis) + server._stopping_channels = {CHANNEL_ID} + mock_get_instance.return_value = server + + self.assertFalse(ChannelService.cancel_pending_shutdown(CHANNEL_ID)) + redis.delete.assert_not_called() + + @patch("apps.proxy.live_proxy.services.channel_service.ConfigHelper.channel_shutdown_delay") + @patch("apps.proxy.live_proxy.services.channel_service.ProxyServer.get_instance") + def test_cancel_pending_shutdown_skips_real_teardown_without_grace(self, mock_get_instance, mock_delay): + mock_delay.return_value = 30 + redis = MagicMock() + redis.exists.side_effect = lambda key: "stopping" in key + redis.get.return_value = None + redis.hget.return_value = ChannelState.STOPPING.encode() + mock_get_instance.return_value = _mock_proxy_server(redis) + + self.assertFalse(ChannelService.cancel_pending_shutdown(CHANNEL_ID)) + redis.hset.assert_not_called() + redis.delete.assert_not_called() @patch("apps.proxy.live_proxy.services.channel_service.ConfigHelper.channel_shutdown_delay") @patch("apps.proxy.live_proxy.services.channel_service.ProxyServer.get_instance") @@ -86,6 +127,28 @@ class ChannelTeardownAvailabilityTests(TestCase): self.assertFalse(ChannelService.is_shutdown_pending(CHANNEL_ID)) +class ClientManagerAddClientTests(TestCase): + @patch("apps.proxy.live_proxy.services.channel_service.ChannelService.cancel_pending_shutdown", return_value=False) + @patch("apps.proxy.live_proxy.client_manager.send_websocket_update") + def test_add_client_stores_ip_and_user_agent_in_redis(self, _mock_ws, _mock_cancel): + from apps.proxy.live_proxy.client_manager import ClientManager + + redis = MagicMock() + cm = ClientManager(CHANNEL_ID, redis_client=redis, worker_id="worker-1") + cm.proxy_server = MagicMock() + + result = cm.add_client( + "client-1", + "10.0.2.163", + user_agent="VLC/3.0.21", + ) + + self.assertEqual(result, 1) + mapping = redis.hset.call_args[1]["mapping"] + self.assertEqual(mapping["ip_address"], "10.0.2.163") + self.assertEqual(mapping["user_agent"], "VLC/3.0.21") + + class LocalStreamActivityTests(TestCase): def _make_server(self): with patch("apps.proxy.live_proxy.server.RedisClient.get_client", return_value=MagicMock()): @@ -509,6 +572,104 @@ class HandleClientDisconnectUpstreamFirstTests(TestCase): mock_coordinated.assert_called_once_with(CHANNEL_ID) +class ShutdownDelayWaitTests(TestCase): + def _make_server(self): + with patch("apps.proxy.live_proxy.server.RedisClient.get_client", return_value=MagicMock()): + with patch.object(ProxyServer, "_start_cleanup_thread"): + server = ProxyServer() + server.redis_client = MagicMock() + server.redis_client.scard.return_value = 0 + return server + + @patch("apps.proxy.live_proxy.server.gevent.sleep") + @patch("apps.proxy.live_proxy.server.time.time", return_value=1000.0) + @patch("apps.proxy.live_proxy.server.ConfigHelper.channel_shutdown_delay", return_value=30) + def test_aborts_when_disconnect_key_deleted(self, _mock_delay, _mock_time, mock_sleep): + server = self._make_server() + server.redis_client.get.side_effect = [b"1000.0", None] + + result = server._wait_for_shutdown_delay(CHANNEL_ID) + + self.assertFalse(result) + self.assertGreaterEqual(mock_sleep.call_count, 1) + + @patch("apps.proxy.live_proxy.server.gevent.sleep") + @patch("apps.proxy.live_proxy.server.time.time", return_value=1000.0) + @patch("apps.proxy.live_proxy.server.ConfigHelper.channel_shutdown_delay", return_value=30) + def test_aborts_when_clients_reconnect(self, _mock_delay, _mock_time, _mock_sleep): + server = self._make_server() + server.redis_client.get.return_value = b"1000.0" + server.redis_client.scard.side_effect = [0, 1] + + result = server._wait_for_shutdown_delay(CHANNEL_ID) + + self.assertFalse(result) + server.redis_client.delete.assert_called_with( + RedisKeys.last_client_disconnect(CHANNEL_ID) + ) + + @patch("apps.proxy.live_proxy.server.gevent.sleep") + @patch("apps.proxy.live_proxy.server.time.time") + @patch("apps.proxy.live_proxy.server.ConfigHelper.channel_shutdown_delay", return_value=30) + def test_timer_resets_when_disconnect_timestamp_updated( + self, _mock_delay, mock_time, mock_sleep + ): + server = self._make_server() + disconnect_key = RedisKeys.last_client_disconnect(CHANNEL_ID) + current_time = [1000.0] + disconnect_timestamp = [1000.0] + poll_count = [0] + + mock_time.side_effect = lambda: current_time[0] + + def get_side_effect(key): + poll_count[0] += 1 + if poll_count[0] >= 3: + disconnect_timestamp[0] = 1020.0 + if key == disconnect_key: + return str(disconnect_timestamp[0]).encode() + return None + + server.redis_client.get.side_effect = get_side_effect + + def advance_sleep(duration): + current_time[0] += duration + + mock_sleep.side_effect = advance_sleep + + result = server._wait_for_shutdown_delay(CHANNEL_ID) + + self.assertTrue(result) + self.assertGreaterEqual(current_time[0], 1050.0) + + @patch.object(ProxyServer, "_coordinated_stop_channel") + @patch.object(ProxyServer, "_wait_for_shutdown_delay", return_value=True) + @patch("apps.proxy.live_proxy.server.ConfigHelper.channel_shutdown_delay", return_value=30) + def test_handle_client_disconnect_uses_polling_wait( + self, _mock_delay, mock_wait, mock_coordinated + ): + server = HandleClientDisconnectUpstreamFirstTests()._make_server() + server.redis_client.get.return_value = b"1700000000.0" + + server.handle_client_disconnect(CHANNEL_ID) + + mock_wait.assert_called_once_with(CHANNEL_ID) + mock_coordinated.assert_called_once_with(CHANNEL_ID) + + @patch.object(ProxyServer, "_coordinated_stop_channel") + @patch.object(ProxyServer, "_wait_for_shutdown_delay", return_value=False) + @patch("apps.proxy.live_proxy.server.ConfigHelper.channel_shutdown_delay", return_value=30) + def test_handle_client_disconnect_skips_stop_when_wait_aborted( + self, _mock_delay, _mock_wait, mock_coordinated + ): + server = HandleClientDisconnectUpstreamFirstTests()._make_server() + server.redis_client.get.return_value = b"1700000000.0" + + server.handle_client_disconnect(CHANNEL_ID) + + mock_coordinated.assert_not_called() + + class InitWaitAbortTests(TestCase): def _make_generator(self): from apps.proxy.live_proxy.output.ts.generator import StreamGenerator diff --git a/apps/proxy/live_proxy/client_manager.py b/apps/proxy/live_proxy/client_manager.py index 3767a25a..ff031e5b 100644 --- a/apps/proxy/live_proxy/client_manager.py +++ b/apps/proxy/live_proxy/client_manager.py @@ -256,6 +256,14 @@ class ClientManager: # Store in Redis if self.redis_client: + from .services.channel_service import ChannelService + + if ChannelService.cancel_pending_shutdown(self.channel_id): + logger.info( + f"Cancelled pending shutdown for channel {self.channel_id} " + f"(client {client_id} reconnected)" + ) + self.redis_client.hset(client_key, mapping=client_data) self.redis_client.expire(client_key, self.client_ttl) @@ -302,7 +310,10 @@ class ClientManager: return len(self.clients) except Exception as e: - logger.error(f"Error adding client {client_id}: {e}") + logger.error(f"Error adding client {client_id}: {e}", exc_info=True) + with self.lock: + self.clients.discard(client_id) + self._registered_clients.discard(client_id) return False def remove_client(self, client_id): @@ -337,7 +348,8 @@ class ClientManager: if remaining == 0: logger.warning(f"Last client removed: {client_id} - channel may shut down soon") disconnect_key = RedisKeys.last_client_disconnect(self.channel_id) - self.redis_client.setex(disconnect_key, 60, str(time.time())) + ttl = max(int(ConfigHelper.channel_shutdown_delay() * 2), 60) + self.redis_client.setex(disconnect_key, ttl, str(time.time())) self._notify_owner_of_activity() diff --git a/apps/proxy/live_proxy/output/fmp4/generator.py b/apps/proxy/live_proxy/output/fmp4/generator.py index e979008c..d967b5f9 100644 --- a/apps/proxy/live_proxy/output/fmp4/generator.py +++ b/apps/proxy/live_proxy/output/fmp4/generator.py @@ -348,7 +348,11 @@ class FMP4StreamGenerator: client_count = proxy_server.client_managers[ self.channel_id ].get_total_client_count() - if client_count <= 1 and proxy_server.am_i_owner(self.channel_id): + if ( + client_count <= 1 + and proxy_server.am_i_owner(self.channel_id) + and ConfigHelper.channel_shutdown_delay() <= 0 + ): try: try: obj = Channel.objects.get(uuid=self.channel_id) diff --git a/apps/proxy/live_proxy/output/ts/generator.py b/apps/proxy/live_proxy/output/ts/generator.py index efde02ad..2bd88725 100644 --- a/apps/proxy/live_proxy/output/ts/generator.py +++ b/apps/proxy/live_proxy/output/ts/generator.py @@ -603,7 +603,8 @@ class StreamGenerator: if self.channel_id in proxy_server.client_managers: client_count = proxy_server.client_managers[self.channel_id].get_total_client_count() # Pool slots are global; the last client on any worker must release. - if client_count <= 1: + # During shutdown_delay, keep the slot until coordinated stop runs. + if client_count <= 1 and ConfigHelper.channel_shutdown_delay() <= 0: try: try: obj = Channel.objects.get(uuid=self.channel_id) diff --git a/apps/proxy/live_proxy/server.py b/apps/proxy/live_proxy/server.py index ddec2d02..8eca8572 100644 --- a/apps/proxy/live_proxy/server.py +++ b/apps/proxy/live_proxy/server.py @@ -905,6 +905,81 @@ class ProxyServer: logger.error(f"Error cleaning zombie channel {channel_id}: {e}", exc_info=True) return False + @staticmethod + def _shutdown_disconnect_ttl(): + delay = ConfigHelper.channel_shutdown_delay() + return max(int(delay * 2), 60) + + def _wait_for_shutdown_delay(self, channel_id): + """ + Wait until shutdown_delay has elapsed since the Redis disconnect + timestamp. Returns False if clients reconnect or the timer is cancelled. + Uses Redis state so concurrent disconnect handlers and multi-worker + reconnects always honour the latest last-client disconnect time. + """ + if not self.redis_client: + return True + + shutdown_delay = ConfigHelper.channel_shutdown_delay() + if shutdown_delay <= 0: + return True + + disconnect_key = RedisKeys.last_client_disconnect(channel_id) + client_set_key = RedisKeys.clients(channel_id) + poll_interval = 1.0 + + logger.info( + f"Waiting up to {shutdown_delay}s before stopping channel {channel_id}..." + ) + + while True: + total = self.redis_client.scard(client_set_key) or 0 + if total > 0: + logger.info( + f"New clients connected during shutdown delay for " + f"{channel_id} - aborting shutdown" + ) + self.redis_client.delete(disconnect_key) + return False + + disconnect_value = self.redis_client.get(disconnect_key) + if not disconnect_value: + logger.info( + f"Shutdown delay cancelled for {channel_id} - aborting shutdown" + ) + return False + + try: + if isinstance(disconnect_value, bytes): + disconnect_value = disconnect_value.decode() + disconnect_time = float(disconnect_value) + except (ValueError, TypeError): + logger.warning( + f"Invalid disconnect timestamp for {channel_id}, aborting wait" + ) + return False + + elapsed = time.time() - disconnect_time + if elapsed >= shutdown_delay: + total = self.redis_client.scard(client_set_key) or 0 + if total > 0: + logger.info( + f"Clients connected at end of shutdown delay for " + f"{channel_id} - aborting shutdown" + ) + self.redis_client.delete(disconnect_key) + return False + return True + + elapsed_display = max(0.0, elapsed) + remaining = max(0.0, shutdown_delay - elapsed) + logger.debug( + f"Channel {channel_id[:8]} shutdown timer: " + f"{elapsed_display:.1f}s of {shutdown_delay}s elapsed " + f"({remaining:.1f}s remaining)" + ) + gevent.sleep(min(poll_interval, remaining)) + def handle_client_disconnect(self, channel_id): """ Handle client disconnect event - check if channel should shut down and @@ -995,18 +1070,20 @@ class ProxyServer: disconnect_key = RedisKeys.last_client_disconnect(channel_id) if shutdown_delay > 0: - self.redis_client.setex(disconnect_key, 60, str(time.time())) - logger.info(f"Waiting {shutdown_delay}s before stopping channel...") - gevent.sleep(shutdown_delay) - - total = self.redis_client.scard(client_set_key) or 0 - if total > 0: - logger.info(f"New clients connected during shutdown delay - aborting shutdown") - self.redis_client.delete(disconnect_key) + if not self.redis_client.get(disconnect_key): + self.redis_client.setex( + disconnect_key, + self._shutdown_disconnect_ttl(), + str(time.time()), + ) + if not self._wait_for_shutdown_delay(channel_id): return - - if shutdown_delay <= 0: - self.redis_client.setex(disconnect_key, 60, str(time.time())) + else: + self.redis_client.setex( + disconnect_key, + self._shutdown_disconnect_ttl(), + str(time.time()), + ) # Coordinated stop runs local teardown + Redis cleanup once. # Do not call _stop_upstream_before_redis_cleanup here — it races @@ -1794,7 +1871,11 @@ class ProxyServer: if not disconnect_time: # First time seeing zero clients, set timestamp if self.redis_client: - self.redis_client.setex(disconnect_key, 60, str(current_time)) + self.redis_client.setex( + disconnect_key, + self._shutdown_disconnect_ttl(), + str(current_time), + ) logger.warning(f"No clients detected for channel {channel_id}, starting shutdown timer") elif current_time - disconnect_time > ConfigHelper.channel_shutdown_delay(): # We've had no clients for the shutdown delay period @@ -1808,7 +1889,9 @@ class ProxyServer: else: # There are clients or we're still connecting - clear any disconnect timestamp if self.redis_client: - self.redis_client.delete(f"live:channel:{channel_id}:last_client_disconnect_time") + self.redis_client.delete( + RedisKeys.last_client_disconnect(channel_id) + ) else: # === NON-OWNER CHANNEL HANDLING === diff --git a/apps/proxy/live_proxy/services/channel_service.py b/apps/proxy/live_proxy/services/channel_service.py index dcd0b5e1..400f55f4 100644 --- a/apps/proxy/live_proxy/services/channel_service.py +++ b/apps/proxy/live_proxy/services/channel_service.py @@ -93,10 +93,103 @@ class ChannelService: @staticmethod def is_channel_unavailable_for_new_clients(channel_id): - """Reject new stream requests while teardown is active or shutdown is pending.""" - return ( - ChannelService.is_channel_teardown_active(channel_id) - or ChannelService.is_shutdown_pending(channel_id) + """Reject new stream requests only while coordinated teardown is active.""" + return ChannelService.is_channel_teardown_active(channel_id) + + @staticmethod + def cancel_pending_shutdown(channel_id): + """ + Abort the post-disconnect grace timer when a client reconnects. + + Clears the disconnect timestamp and any leaked stopping markers. When + upstream is still active but the last client released its profile slot + during the grace window, re-reserve the slot from Redis metadata. + + Does not run during coordinated stop_channel() — clearing teardown + markers mid-stop would leave clients attached to upstream that is + about to be torn down. + """ + from django.db import close_old_connections + + proxy_server = ProxyServer.get_instance() + if not proxy_server.redis_client: + return False + + if channel_id in proxy_server._stopping_channels: + return False + + disconnect_key = RedisKeys.last_client_disconnect(channel_id) + had_pending = bool(proxy_server.redis_client.exists(disconnect_key)) + in_grace = had_pending or ChannelService.is_shutdown_pending(channel_id) + + if not in_grace: + return False + + try: + proxy_server.redis_client.delete(disconnect_key) + + metadata_key = RedisKeys.channel_metadata(channel_id) + state = proxy_server.redis_client.hget( + metadata_key, ChannelMetadataField.STATE + ) + if state: + state_str = state.decode() if isinstance(state, bytes) else state + if state_str == ChannelState.STOPPING: + proxy_server.redis_client.hset(metadata_key, mapping={ + ChannelMetadataField.STATE: ChannelState.ACTIVE, + ChannelMetadataField.STATE_CHANGED_AT: str(time.time()), + }) + + stop_key = RedisKeys.channel_stopping(channel_id) + if proxy_server.redis_client.exists(stop_key): + proxy_server.redis_client.delete(stop_key) + + if ChannelService._channel_proxy_is_active( + proxy_server.redis_client, channel_id + ): + from apps.channels.models import Channel + + channel = Channel.objects.filter(uuid=channel_id).first() + if channel and not proxy_server.redis_client.get( + f"channel_stream:{channel.id}" + ): + sid, pid, error, slot_reserved = channel.get_stream() + if error: + logger.warning( + f"Could not re-reserve stream for {channel_id} " + f"after shutdown cancel: {error}" + ) + elif slot_reserved and sid and pid: + proxy_server.redis_client.hset(metadata_key, mapping={ + ChannelMetadataField.STREAM_ID: str(sid), + ChannelMetadataField.M3U_PROFILE: str(pid), + }) + logger.info( + f"Re-reserved profile slot for {channel_id} " + f"(stream={sid}, profile={pid})" + ) + finally: + close_old_connections() + + return True + + @staticmethod + def _channel_proxy_is_active(redis_client, channel_id): + """True when live proxy metadata shows this channel is still running.""" + metadata_key = RedisKeys.channel_metadata(channel_id) + if not redis_client.exists(metadata_key): + return False + state = redis_client.hget(metadata_key, ChannelMetadataField.STATE) + if state is None: + return False + if isinstance(state, bytes): + state = state.decode() + return state in ( + ChannelState.ACTIVE, + ChannelState.WAITING_FOR_CLIENTS, + ChannelState.BUFFERING, + ChannelState.INITIALIZING, + ChannelState.CONNECTING, ) @staticmethod From 34c938b1cefff099616345a722c939d09eeaf1ce Mon Sep 17 00:00:00 2001 From: SergeantPanda Date: Mon, 15 Jun 2026 19:50:50 -0500 Subject: [PATCH 9/9] feat(epg): implement staging and batch processing for EPG program updates - Introduced a temporary staging table for efficient batch processing of EPG program inserts, reducing memory and I/O contention during updates. - Enhanced the `parse_programs_for_source` function to stream parsed rows into the staging table before swapping them atomically into the main program data. - Added unit tests to validate the new staging and swapping logic, ensuring existing programs are preserved during failures and that batch processing works as intended. --- apps/epg/tasks.py | 451 ++++++++++++------ .../tests/test_parse_programs_for_source.py | 238 +++++++++ dispatcharr/celery.py | 1 + 3 files changed, 553 insertions(+), 137 deletions(-) create mode 100644 apps/epg/tests/test_parse_programs_for_source.py diff --git a/apps/epg/tasks.py b/apps/epg/tasks.py index 248e9a5f..0e8eda42 100644 --- a/apps/epg/tasks.py +++ b/apps/epg/tasks.py @@ -561,9 +561,10 @@ def refresh_epg_data(source_id, force=False): gc.collect() return - # Build byte-offset index for preview lookups in the background so refresh isn't blocked by it - build_programme_index_task.delay(source.id) + # Build byte-offset index after programme data is committed so refresh + # does not compete for memory/IO during the programme swap. parse_programs_for_source(source) + build_programme_index_task.delay(source.id) elif source.source_type == 'schedules_direct': fetch_schedules_direct(source, force=force) @@ -590,6 +591,7 @@ def refresh_epg_data(source_id, force=False): source = None # Force garbage collection before releasing the lock gc.collect() + connection.close() lock_renewer.stop() release_task_lock('refresh_epg_data', source_id) @@ -1804,6 +1806,163 @@ def parse_programs_for_tvg_id(epg_id, force=False): release_task_lock('parse_epg_programs', epg_id) +_EPG_PROGRAM_STAGING_TABLE = 'epg_program_staging' +# Parse batches bound Python memory during XML iterparse; swap batches bound each +# DELETE/INSERT statement inside the single atomic swap transaction. +_EPG_PARSE_BATCH_SIZE = 2500 +_EPG_SWAP_BATCH_SIZE = 5000 + + +def _epg_program_staging_supported(): + return connection.vendor == 'postgresql' + + +def _prepare_epg_program_staging_table(): + """Create/truncate a session-scoped temp table for streaming EPG programme inserts.""" + if not _epg_program_staging_supported(): + return False + + with connection.cursor() as cursor: + cursor.execute( + f""" + CREATE TEMP TABLE IF NOT EXISTS {_EPG_PROGRAM_STAGING_TABLE} ( + epg_id bigint NOT NULL, + start_time timestamptz NOT NULL, + end_time timestamptz NOT NULL, + title varchar(255) NOT NULL, + sub_title text, + description text, + tvg_id varchar(255), + custom_properties jsonb + ) ON COMMIT PRESERVE ROWS + """ + ) + cursor.execute(f"TRUNCATE {_EPG_PROGRAM_STAGING_TABLE}") + return True + + +def _clear_epg_program_staging_table(): + if not _epg_program_staging_supported(): + return + with connection.cursor() as cursor: + cursor.execute(f"TRUNCATE {_EPG_PROGRAM_STAGING_TABLE}") + + +def _flush_epg_program_staging_batch(programs_batch): + """Insert a batch of unsaved ProgramData rows into the session staging table.""" + if not programs_batch or not _epg_program_staging_supported(): + return + + values_sql = [] + params = [] + for program in programs_batch: + values_sql.append("(%s, %s, %s, %s, %s, %s, %s, %s)") + custom_properties = program.custom_properties + if custom_properties is not None and not isinstance(custom_properties, str): + custom_properties = json.dumps(custom_properties) + params.extend([ + program.epg_id, + program.start_time, + program.end_time, + program.title, + program.sub_title, + program.description, + program.tvg_id, + custom_properties, + ]) + + with connection.cursor() as cursor: + cursor.execute( + f""" + INSERT INTO {_EPG_PROGRAM_STAGING_TABLE} ( + epg_id, start_time, end_time, title, sub_title, description, tvg_id, custom_properties + ) VALUES {', '.join(values_sql)} + """, + params, + ) + + +def _swap_staged_epg_programs(mapped_epg_ids, epg_source, batch_size=_EPG_SWAP_BATCH_SIZE): + """ + Atomically replace mapped programme rows with staged data. + Must be called inside transaction.atomic(). + + Staged rows are moved in batches (DELETE ... RETURNING + INSERT) so Postgres + does not need to materialize the entire catalogue in one statement. + """ + with connection.cursor() as cursor: + cursor.execute("SET LOCAL statement_timeout = '10min'") + + deleted_count = ProgramData.objects.filter(epg_id__in=mapped_epg_ids).delete()[0] + logger.debug(f"Deleted {deleted_count} existing programs") + + unmapped_epg_ids = list( + EPGData.objects.filter(epg_source=epg_source) + .exclude(id__in=mapped_epg_ids) + .values_list('id', flat=True) + ) + if unmapped_epg_ids: + orphaned_count = ProgramData.objects.filter(epg_id__in=unmapped_epg_ids).delete()[0] + if orphaned_count > 0: + logger.info( + f"Cleaned up {orphaned_count} orphaned programs for " + f"{len(unmapped_epg_ids)} unmapped EPG entries" + ) + + if not _epg_program_staging_supported(): + raise RuntimeError('_swap_staged_epg_programs requires PostgreSQL staging support') + + program_table = ProgramData._meta.db_table + total_inserted = 0 + while True: + with connection.cursor() as cursor: + cursor.execute( + f""" + WITH moved AS ( + DELETE FROM {_EPG_PROGRAM_STAGING_TABLE} + WHERE ctid IN ( + SELECT ctid FROM {_EPG_PROGRAM_STAGING_TABLE} LIMIT %s + ) + RETURNING + epg_id, start_time, end_time, title, sub_title, + description, tvg_id, custom_properties + ) + INSERT INTO {program_table} ( + epg_id, start_time, end_time, title, sub_title, + description, tvg_id, custom_properties + ) + SELECT + epg_id, start_time, end_time, title, sub_title, + description, tvg_id, custom_properties + FROM moved + """, + [batch_size], + ) + moved_count = cursor.rowcount + if moved_count == 0: + break + total_inserted += moved_count + + logger.debug(f"Inserted {total_inserted} staged programs in batches of {batch_size}") + + return deleted_count + + +def _swap_parsed_epg_programs(mapped_epg_ids, epg_source, programs_to_create, batch_size=_EPG_SWAP_BATCH_SIZE): + """SQLite/dev fallback: atomic delete + bulk insert from an in-memory batch list.""" + with transaction.atomic(): + deleted_count = ProgramData.objects.filter(epg_id__in=mapped_epg_ids).delete()[0] + unmapped_epg_ids = list( + EPGData.objects.filter(epg_source=epg_source) + .exclude(id__in=mapped_epg_ids) + .values_list('id', flat=True) + ) + if unmapped_epg_ids: + ProgramData.objects.filter(epg_id__in=unmapped_epg_ids).delete() + for i in range(0, len(programs_to_create), batch_size): + ProgramData.objects.bulk_create(programs_to_create[i:i + batch_size]) + return deleted_count + def parse_programs_for_source(epg_source, tvg_id=None): """ @@ -1910,106 +2069,164 @@ def parse_programs_for_source(epg_source, tvg_id=None): send_epg_update(epg_source.id, "parsing_programs", 100, status="error", error="No URL provided") return False - # SINGLE PASS PARSING: Parse the XML file once and collect all programs in memory - # We parse FIRST, then do an atomic delete+insert to avoid race conditions - # where clients might see empty/partial EPG data during the transition - all_programs_to_create = [] - programs_by_channel = {tvg_id: 0 for tvg_id in mapped_tvg_ids} # Track count per channel + # Stream parsed rows into a session temp table, then swap in a short transaction. + # This bounds Python memory (batched staging inserts) and Postgres memory (no + # long-lived transaction spanning the entire XML parse). + programs_by_channel = {tvg_id: 0 for tvg_id in mapped_tvg_ids} total_programs = 0 skipped_programs = 0 last_progress_update = 0 + parse_batch_size = _EPG_PARSE_BATCH_SIZE + swap_batch_size = _EPG_SWAP_BATCH_SIZE + programs_batch = [] + deleted_count = 0 + staging_prepared = False + use_staging = False + programs_accumulator = [] + + send_epg_update(epg_source.id, "parsing_programs", 10, message="Parsing programs...") try: - logger.debug(f"Opening file for single-pass parsing: {file_path}") + staging_prepared = _prepare_epg_program_staging_table() + use_staging = staging_prepared + + logger.debug(f"Opening file for streaming parse: {file_path}") source_file = _open_xmltv_file(file_path) + try: + program_parser = etree.iterparse( + source_file, + events=('end',), + tag='programme', + remove_blank_text=True, + recover=True, + ) - # Stream parse the file using lxml's iterparse - program_parser = etree.iterparse(source_file, events=('end',), tag='programme', remove_blank_text=True, recover=True) + for _, elem in program_parser: + channel_id = elem.get('channel') - for _, elem in program_parser: - channel_id = elem.get('channel') + if channel_id not in mapped_tvg_ids: + skipped_programs += 1 + clear_element(elem) + continue - # Skip programmes for unmapped channels immediately - if channel_id not in mapped_tvg_ids: - skipped_programs += 1 - # Clear element to free memory - clear_element(elem) - continue + try: + start_time = parse_xmltv_time(elem.get('start')) + end_time = parse_xmltv_time(elem.get('stop')) + title = None + desc = None + sub_title = None - # This programme is for a mapped channel - process it - try: - start_time = parse_xmltv_time(elem.get('start')) - end_time = parse_xmltv_time(elem.get('stop')) - title = None - desc = None - sub_title = None + for child in elem: + if child.tag == 'title': + title = child.text or 'No Title' + elif child.tag == 'desc': + desc = child.text or '' + elif child.tag == 'sub-title': + sub_title = child.text or '' - # Efficiently process child elements - for child in elem: - if child.tag == 'title': - title = child.text or 'No Title' - elif child.tag == 'desc': - desc = child.text or '' - elif child.tag == 'sub-title': - sub_title = child.text or '' + if not title: + title = 'No Title' - if not title: - title = 'No Title' + custom_props = extract_custom_properties(elem) + custom_properties_json = custom_props if custom_props else None - # Extract custom properties - custom_props = extract_custom_properties(elem) - custom_properties_json = custom_props if custom_props else None + if desc: + has_season = (custom_properties_json or {}).get('season') is not None + has_episode = (custom_properties_json or {}).get('episode') is not None + if not has_season or not has_episode: + d_season, d_episode, cleaned_desc = extract_season_episode_from_description(desc) + if d_season is not None and d_episode is not None: + if custom_properties_json is None: + custom_properties_json = {} + if not has_season: + custom_properties_json['season'] = d_season + if not has_episode: + custom_properties_json['episode'] = d_episode + custom_properties_json['season_episode_source'] = 'description' + desc = cleaned_desc - # Fallback: extract S/E from description when episode-num - # elements didn't provide them - if desc: - has_season = (custom_properties_json or {}).get('season') is not None - has_episode = (custom_properties_json or {}).get('episode') is not None - if not has_season or not has_episode: - d_season, d_episode, cleaned_desc = extract_season_episode_from_description(desc) - if d_season is not None and d_episode is not None: - if custom_properties_json is None: - custom_properties_json = {} - if not has_season: - custom_properties_json['season'] = d_season - if not has_episode: - custom_properties_json['episode'] = d_episode - custom_properties_json['season_episode_source'] = 'description' - desc = cleaned_desc + epg_id = tvg_id_to_epg_id[channel_id] + programs_batch.append(ProgramData( + epg_id=epg_id, + start_time=start_time, + end_time=end_time, + title=title[:255], + description=desc, + sub_title=sub_title, + tvg_id=channel_id, + custom_properties=custom_properties_json, + )) + total_programs += 1 + programs_by_channel[channel_id] += 1 + clear_element(elem) - epg_id = tvg_id_to_epg_id[channel_id] - all_programs_to_create.append(ProgramData( - epg_id=epg_id, - start_time=start_time, - end_time=end_time, - title=title[:255], - description=desc, - sub_title=sub_title, - tvg_id=channel_id, - custom_properties=custom_properties_json - )) - total_programs += 1 - programs_by_channel[channel_id] += 1 + if len(programs_batch) >= parse_batch_size: + if use_staging: + _flush_epg_program_staging_batch(programs_batch) + programs_batch = [] + else: + programs_accumulator.extend(programs_batch) + programs_batch = [] - # Clear the element to free memory - clear_element(elem) + if total_programs - last_progress_update >= 5000: + last_progress_update = total_programs + progress = min( + 85, + 10 + int((total_programs / max(total_programs + 10000, 1)) * 75), + ) + send_epg_update( + epg_source.id, + "parsing_programs", + progress, + processed=total_programs, + channels=mapped_count, + message=f"Staging programs... {total_programs:,}", + ) - # Send progress update (estimate based on programs processed) - if total_programs - last_progress_update >= 5000: - last_progress_update = total_programs - # Cap at 70% during parsing phase (save 30% for DB operations) - progress = min(70, 10 + int((total_programs / max(total_programs + 10000, 1)) * 60)) - send_epg_update(epg_source.id, "parsing_programs", progress, - processed=total_programs, channels=mapped_count) + if total_programs % 5000 == 0: + gc.collect() - # Periodic garbage collection during parsing - if total_programs % 5000 == 0: - gc.collect() + except Exception as e: + logger.error(f"Error processing program for {channel_id}: {e}", exc_info=True) + clear_element(elem) + continue - except Exception as e: - logger.error(f"Error processing program for {channel_id}: {e}", exc_info=True) - clear_element(elem) - continue + if programs_batch: + if use_staging: + _flush_epg_program_staging_batch(programs_batch) + else: + programs_accumulator.extend(programs_batch) + programs_batch = [] + finally: + if source_file: + source_file.close() + source_file = None + + try: + send_epg_update(epg_source.id, "parsing_programs", 90, message="Updating database...") + if use_staging: + with transaction.atomic(): + deleted_count = _swap_staged_epg_programs( + mapped_epg_ids, epg_source, batch_size=swap_batch_size + ) + else: + deleted_count = _swap_parsed_epg_programs( + mapped_epg_ids, epg_source, programs_accumulator, batch_size=swap_batch_size + ) + programs_accumulator = [] + + logger.info( + f"Atomic update complete: deleted {deleted_count}, inserted {total_programs} programs" + ) + except Exception as db_error: + logger.error(f"Database error during atomic update: {db_error}", exc_info=True) + epg_source.status = EPGSource.STATUS_ERROR + epg_source.last_message = f"Database error: {str(db_error)}" + epg_source.save(update_fields=['status', 'last_message']) + send_epg_update( + epg_source.id, "parsing_programs", 100, status="error", message=str(db_error) + ) + return False except etree.XMLSyntaxError as xml_error: logger.error(f"XML syntax error parsing program data: {xml_error}") @@ -2018,63 +2235,23 @@ def parse_programs_for_source(epg_source, tvg_id=None): epg_source.save(update_fields=['status', 'last_message']) send_epg_update(epg_source.id, "parsing_programs", 100, status="error", message=str(xml_error)) return False - except Exception as e: - logger.error(f"Error parsing XML for programs: {e}", exc_info=True) - raise - finally: - if source_file: - source_file.close() - source_file = None - - # Now perform atomic delete + bulk insert - # This ensures clients never see empty/partial EPG data - logger.info(f"Parsed {total_programs} programs, performing atomic database update...") - send_epg_update(epg_source.id, "parsing_programs", 75, message="Updating database...") - - batch_size = 1000 - try: - with transaction.atomic(): - # Kill any individual statement that hangs longer than 10 minutes. - # SET LOCAL automatically resets when this transaction ends (commit or rollback). - with connection.cursor() as cursor: - cursor.execute("SET LOCAL statement_timeout = '10min'") - # Delete existing programs for mapped EPGs - deleted_count = ProgramData.objects.filter(epg_id__in=mapped_epg_ids).delete()[0] - logger.debug(f"Deleted {deleted_count} existing programs") - - # Clean up orphaned programs for unmapped EPG entries - unmapped_epg_ids = list(EPGData.objects.filter( - epg_source=epg_source - ).exclude(id__in=mapped_epg_ids).values_list('id', flat=True)) - - if unmapped_epg_ids: - orphaned_count = ProgramData.objects.filter(epg_id__in=unmapped_epg_ids).delete()[0] - if orphaned_count > 0: - logger.info(f"Cleaned up {orphaned_count} orphaned programs for {len(unmapped_epg_ids)} unmapped EPG entries") - - # Bulk insert all new programs in batches within the same transaction - for i in range(0, len(all_programs_to_create), batch_size): - batch = all_programs_to_create[i:i + batch_size] - ProgramData.objects.bulk_create(batch) - - # Update progress during insertion - progress = 75 + int((i / len(all_programs_to_create)) * 20) if all_programs_to_create else 95 - if i % (batch_size * 5) == 0: - send_epg_update(epg_source.id, "parsing_programs", min(95, progress), - message=f"Inserting programs... {i}/{len(all_programs_to_create)}") - - logger.info(f"Atomic update complete: deleted {deleted_count}, inserted {total_programs} programs") - - except Exception as db_error: - logger.error(f"Database error during atomic update: {db_error}", exc_info=True) + except Exception as parse_error: + logger.error(f"Error parsing programs from XML: {parse_error}", exc_info=True) epg_source.status = EPGSource.STATUS_ERROR - epg_source.last_message = f"Database error: {str(db_error)}" + epg_source.last_message = f"Error parsing programs: {str(parse_error)}" epg_source.save(update_fields=['status', 'last_message']) - send_epg_update(epg_source.id, "parsing_programs", 100, status="error", message=str(db_error)) + send_epg_update( + epg_source.id, "parsing_programs", 100, status="error", message=str(parse_error) + ) return False finally: - # Clear the large list to free memory - all_programs_to_create = None + programs_batch = None + programs_accumulator = None + if staging_prepared: + try: + _clear_epg_program_staging_table() + except Exception: + pass gc.collect() # Count channels that actually got programs @@ -2130,7 +2307,7 @@ def parse_programs_for_source(epg_source, tvg_id=None): source_file = None # Explicitly release any remaining large data structures - programs_to_create = None + programs_batch = None programs_by_channel = None mapped_epg_ids = None mapped_tvg_ids = None diff --git a/apps/epg/tests/test_parse_programs_for_source.py b/apps/epg/tests/test_parse_programs_for_source.py new file mode 100644 index 00000000..f49a5d70 --- /dev/null +++ b/apps/epg/tests/test_parse_programs_for_source.py @@ -0,0 +1,238 @@ +import os +import tempfile +from datetime import timedelta +from unittest.mock import patch + +from django.db import connection, transaction +from django.test import TestCase +from django.utils import timezone + +from apps.channels.models import Channel +from apps.epg.models import EPGSource, EPGData, ProgramData +from apps.epg.tasks import ( + parse_programs_for_source, + _flush_epg_program_staging_batch, + _swap_staged_epg_programs, + _EPG_PARSE_BATCH_SIZE, +) + + +def _programme_xml(channel_id, title, start, stop): + return ( + f' \n' + f' {title}\n' + f' \n' + ) + + +def _xmltv_file(programmes): + body = ( + '\n' + '\n' + f'{programmes}' + '\n' + ) + handle = tempfile.NamedTemporaryFile( + mode='w', + suffix='.xml', + delete=False, + encoding='utf-8', + ) + handle.write(body) + handle.close() + return handle.name + + +class ParseProgramsForSourceTests(TestCase): + def setUp(self): + self.source = EPGSource.objects.create( + name='XMLTV Parse Test', + source_type='xmltv', + ) + self.mapped_epg = EPGData.objects.create( + epg_source=self.source, + tvg_id='mapped.channel', + name='Mapped Channel', + ) + self.unmapped_epg = EPGData.objects.create( + epg_source=self.source, + tvg_id='unmapped.channel', + name='Unmapped Channel', + ) + Channel.objects.create( + channel_number=1, + name='Mapped Channel', + epg_data=self.mapped_epg, + ) + self.base_time = timezone.now().replace(minute=0, second=0, microsecond=0) + self.start = self.base_time.strftime('%Y%m%d%H%M%S +0000') + self.stop = (self.base_time + timedelta(hours=1)).strftime('%Y%m%d%H%M%S +0000') + + def tearDown(self): + if getattr(self, 'xml_path', None) and os.path.exists(self.xml_path): + os.unlink(self.xml_path) + + def _configure_source_file(self, programmes): + self.xml_path = _xmltv_file(programmes) + self.source.file_path = self.xml_path + self.source.save(update_fields=['file_path']) + + @patch('apps.epg.tasks.log_system_event') + @patch('apps.epg.tasks.send_epg_update') + def test_replaces_programs_for_mapped_channels(self, _send_update, _log_event): + old_start = self.base_time - timedelta(days=1) + ProgramData.objects.create( + epg=self.mapped_epg, + start_time=old_start, + end_time=old_start + timedelta(hours=1), + title='Old Programme', + tvg_id=self.mapped_epg.tvg_id, + ) + orphan_start = self.base_time - timedelta(days=1) + ProgramData.objects.create( + epg=self.unmapped_epg, + start_time=orphan_start, + end_time=orphan_start + timedelta(hours=1), + title='Orphan Programme', + tvg_id=self.unmapped_epg.tvg_id, + ) + + programmes = ( + _programme_xml('mapped.channel', 'New Show', self.start, self.stop) + + _programme_xml('unmapped.channel', 'Skipped Show', self.start, self.stop) + ) + self._configure_source_file(programmes) + + result = parse_programs_for_source(self.source) + + self.assertTrue(result) + mapped_programs = ProgramData.objects.filter(epg=self.mapped_epg) + self.assertEqual(mapped_programs.count(), 1) + self.assertEqual(mapped_programs.get().title, 'New Show') + self.assertFalse(ProgramData.objects.filter(epg=self.unmapped_epg).exists()) + + @patch('apps.epg.tasks.log_system_event') + @patch('apps.epg.tasks.send_epg_update') + def test_atomic_failure_rolls_back_and_preserves_existing_programs(self, _send_update, _log_event): + old_start = self.base_time - timedelta(days=1) + ProgramData.objects.create( + epg=self.mapped_epg, + start_time=old_start, + end_time=old_start + timedelta(hours=1), + title='Keep Me', + tvg_id=self.mapped_epg.tvg_id, + ) + + self._configure_source_file( + _programme_xml('mapped.channel', 'Replacement', self.start, self.stop) + ) + + swap_path = ( + 'apps.epg.tasks._swap_staged_epg_programs' + if connection.vendor == 'postgresql' + else 'apps.epg.tasks._swap_parsed_epg_programs' + ) + with patch(swap_path, side_effect=RuntimeError('simulated insert failure')): + result = parse_programs_for_source(self.source) + + self.assertFalse(result) + self.assertEqual(ProgramData.objects.filter(epg=self.mapped_epg).count(), 1) + self.assertEqual( + ProgramData.objects.get(epg=self.mapped_epg).title, + 'Keep Me', + ) + + @patch('apps.epg.tasks.log_system_event') + @patch('apps.epg.tasks.send_epg_update') + def test_streams_batches_without_holding_full_program_list(self, _send_update, _log_event): + if connection.vendor != 'postgresql': + self.skipTest('PostgreSQL staging batches are required for this assertion') + + programme_count = _EPG_PARSE_BATCH_SIZE * 2 + programmes = ''.join( + _programme_xml( + 'mapped.channel', + f'Show {idx}', + self.start, + self.stop, + ) + for idx in range(programme_count) + ) + self._configure_source_file(programmes) + flush_sizes = [] + original_flush = _flush_epg_program_staging_batch + + def tracking_flush(batch): + flush_sizes.append(len(batch)) + return original_flush(batch) + + with patch('apps.epg.tasks._flush_epg_program_staging_batch', side_effect=tracking_flush): + result = parse_programs_for_source(self.source) + + self.assertTrue(result) + self.assertEqual(ProgramData.objects.filter(epg=self.mapped_epg).count(), programme_count) + self.assertEqual(sum(flush_sizes), programme_count) + self.assertTrue(all(size <= _EPG_PARSE_BATCH_SIZE for size in flush_sizes)) + self.assertGreater(len(flush_sizes), 1) + + @patch('apps.epg.tasks.log_system_event') + @patch('apps.epg.tasks.send_epg_update') + def test_live_programs_remain_until_swap_commits(self, _send_update, _log_event): + if connection.vendor != 'postgresql': + self.skipTest('PostgreSQL staging swap is required for this assertion') + + old_start = self.base_time - timedelta(days=1) + ProgramData.objects.create( + epg=self.mapped_epg, + start_time=old_start, + end_time=old_start + timedelta(hours=1), + title='Old Programme', + tvg_id=self.mapped_epg.tvg_id, + ) + self._configure_source_file( + _programme_xml('mapped.channel', 'New Show', self.start, self.stop) + ) + + observed_titles_at_swap = [] + + def swap_with_visibility_check(mapped_epg_ids, epg_source, *args, **kwargs): + observed_titles_at_swap.append( + ProgramData.objects.get(epg=self.mapped_epg).title + ) + return _swap_staged_epg_programs(mapped_epg_ids, epg_source, *args, **kwargs) + + with patch('apps.epg.tasks._swap_staged_epg_programs', side_effect=swap_with_visibility_check): + result = parse_programs_for_source(self.source) + + self.assertTrue(result) + self.assertEqual(observed_titles_at_swap, ['Old Programme']) + self.assertEqual(ProgramData.objects.get(epg=self.mapped_epg).title, 'New Show') + + @patch('apps.epg.tasks.log_system_event') + @patch('apps.epg.tasks.send_epg_update') + def test_swap_delete_is_rolled_back_when_insert_fails(self, _send_update, _log_event): + if connection.vendor != 'postgresql': + self.skipTest('PostgreSQL staging swap is required for this assertion') + + old_start = self.base_time - timedelta(days=1) + ProgramData.objects.create( + epg=self.mapped_epg, + start_time=old_start, + end_time=old_start + timedelta(hours=1), + title='Keep Me', + tvg_id=self.mapped_epg.tvg_id, + ) + self._configure_source_file( + _programme_xml('mapped.channel', 'Replacement', self.start, self.stop) + ) + + def failing_swap(mapped_epg_ids, epg_source, *args, **kwargs): + with transaction.atomic(): + ProgramData.objects.filter(epg_id__in=mapped_epg_ids).delete() + raise RuntimeError('simulated insert failure') + + with patch('apps.epg.tasks._swap_staged_epg_programs', side_effect=failing_swap): + result = parse_programs_for_source(self.source) + + self.assertFalse(result) + self.assertEqual(ProgramData.objects.get(epg=self.mapped_epg).title, 'Keep Me') diff --git a/dispatcharr/celery.py b/dispatcharr/celery.py index 7ce0ab29..bdb5e48d 100644 --- a/dispatcharr/celery.py +++ b/dispatcharr/celery.py @@ -94,6 +94,7 @@ def cleanup_task_memory(**kwargs): 'apps.epg.tasks.refresh_all_epg_data', 'apps.epg.tasks.parse_programs_for_source', 'apps.epg.tasks.parse_programs_for_tvg_id', + 'apps.epg.tasks.build_programme_index_task', 'apps.channels.tasks.match_epg_channels', 'apps.channels.tasks.match_selected_channels_epg', 'apps.channels.tasks.match_single_channel_epg',