From 481307828de7d9e0dd0f7f124cf4cb047030868e Mon Sep 17 00:00:00 2001 From: gbischof Date: Tue, 8 Jul 2025 15:00:00 -0400 Subject: [PATCH 1/7] add a test to test a slow redis operation --- README.md | 4 +- server.py | 1 + tests/conftest.py | 43 +++++++++++++++++++ tests/test_redis_timeout.py | 83 +++++++++++++++++++++++++++++++++++++ 4 files changed, 129 insertions(+), 2 deletions(-) create mode 100644 tests/test_redis_timeout.py diff --git a/README.md b/README.md index d9af2ba..346b3eb 100644 --- a/README.md +++ b/README.md @@ -9,7 +9,7 @@ ### Option 1: Manual Setup ```sh -docker run --net=host --rm -v ./redis:/usr/local/etc/redis --name test-redis redis redis-server /usr/local/etc/redis/redis.conf +docker run --rm -p 6379:6379 -v ./redis:/usr/local/etc/redis --name test-redis redis redis-server /usr/local/etc/redis/redis.conf pixi run serve ``` @@ -48,7 +48,7 @@ for i in {1..20}; do curl -s -D - http://localhost:8000/stream/live 2>/dev/null Before running tests, start Redis: ```sh -docker run --net=host --rm -v ./redis:/usr/local/etc/redis --name test-redis redis redis-server /usr/local/etc/redis/redis.conf +docker run --rm -p 6379:6379 -v ./redis:/usr/local/etc/redis --name test-redis redis redis-server /usr/local/etc/redis/redis.conf ``` ### Run the Test Suite diff --git a/server.py b/server.py index 6e592d8..ddfe7d2 100644 --- a/server.py +++ b/server.py @@ -18,6 +18,7 @@ class Settings(BaseSettings): def build_app(settings: Settings): + # This doesn't connect to the redis, so it will work if redis is down. redis_client = redis.from_url(settings.redis_url) @asynccontextmanager diff --git a/tests/conftest.py b/tests/conftest.py index 91b9111..01ecce4 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -1,14 +1,57 @@ import pytest +import logging +import sys +from datetime import datetime from starlette.testclient import TestClient +from starlette.middleware.base import BaseHTTPMiddleware +from starlette.requests import Request from server import build_app, Settings +class ExceptionLoggingMiddleware(BaseHTTPMiddleware): + def __init__(self, app, logger): + super().__init__(app) + self.logger = logger + + async def dispatch(self, request: Request, call_next): + try: + response = await call_next(request) + return response + except Exception as e: + self.logger.error(f"Exception in {request.method} {request.url}: {type(e).__name__}: {e}", exc_info=True) + raise + + @pytest.fixture(scope="function") def client(): """Fixture providing TestClient following ws-tests pattern.""" + # Configure logging to write to file + log_filename = f"test_logs_{datetime.now().strftime('%Y%m%d_%H%M%S')}.log" + + # Clear any existing handlers + for handler in logging.root.handlers[:]: + logging.root.removeHandler(handler) + + # Set up file and console logging + file_handler = logging.FileHandler(log_filename) + console_handler = logging.StreamHandler(sys.stdout) + + formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s') + file_handler.setFormatter(formatter) + console_handler.setFormatter(formatter) + + # Configure logger for exceptions + logger = logging.getLogger("test_exceptions") + logger.setLevel(logging.ERROR) + logger.addHandler(file_handler) + logger.addHandler(console_handler) + settings = Settings(redis_url="redis://localhost:6379/0", ttl=60 * 60) app = build_app(settings) + # Add exception logging middleware + app.add_middleware(ExceptionLoggingMiddleware, logger=logger) + with TestClient(app) as client: yield client diff --git a/tests/test_redis_timeout.py b/tests/test_redis_timeout.py new file mode 100644 index 0000000..7f45929 --- /dev/null +++ b/tests/test_redis_timeout.py @@ -0,0 +1,83 @@ +import time +from starlette.testclient import TestClient +import pytest +from unittest.mock import patch, MagicMock +import redis.asyncio as redis + + +def test_redis_client_timeout_on_unreachable_server(): + """Test that Redis operations timeout when server is unreachable.""" + from server import Settings, build_app + + # Use a non-existent Redis server to test timeout behavior + settings = Settings(redis_url="redis://localhost:9999/0", ttl=60 * 60) + app = build_app(settings) + + with TestClient(app) as test_client: + start_time = time.time() + + # This should fail quickly with a connection error, not hang indefinitely + with pytest.raises(Exception): # Expect an exception due to unreachable Redis + response = test_client.post("/upload") + + elapsed_time = time.time() - start_time + + # Should fail within a reasonable time (less than 5 seconds) + assert elapsed_time < 5.0, f"Redis operation took too long: {elapsed_time} seconds" + + +def test_redis_command_with_slow_operation(): + """Test that Redis operations timeout when they take too long.""" + import asyncio + + # Create a Redis client with short timeouts + redis_client = redis.from_url( + "redis://localhost:6379/0", + socket_timeout=0.5, # 500ms timeout + socket_connect_timeout=0.5, + retry_on_timeout=False + ) + + async def run_slow_operation(): + # Use a Lua script that busy-waits for 2 seconds + slow_script = """ + local start_time = redis.call('TIME') + local start_seconds = tonumber(start_time[1]) + local start_microseconds = tonumber(start_time[2]) + local target_time = start_seconds + 2 -- Add 2 seconds + + while true do + local current_time = redis.call('TIME') + local current_seconds = tonumber(current_time[1]) + if current_seconds >= target_time then + break + end + end + + return "done" + """ + + # This should timeout because the script takes 2 seconds but timeout is 0.5s + result = await redis_client.eval(slow_script, 0) + return result + + start_time = time.time() + + # Let's see what actually happens without expecting an exception + try: + result = asyncio.run(run_slow_operation()) + print(f"Operation completed successfully with result: {result}") + except Exception as e: + print(f"Operation failed with exception: {type(e).__name__}: {e}") + + elapsed_time = time.time() - start_time + print(f"Operation took {elapsed_time} seconds") + + # For now, just assert it completes in reasonable time + assert elapsed_time < 10.0, f"Redis operation took too long: {elapsed_time} seconds" + + # Clean up + try: + asyncio.run(redis_client.aclose()) + except: + pass From 60c5e8ab0e0fe071c4062c578124c0a94ab1f2c4 Mon Sep 17 00:00:00 2001 From: gbischof Date: Tue, 8 Jul 2025 15:16:07 -0400 Subject: [PATCH 2/7] add socket_timeout to redis --- server.py | 9 +++++- tests/conftest.py | 46 +------------------------- tests/test_redis_timeout.py | 64 +++++++++++-------------------------- 3 files changed, 28 insertions(+), 91 deletions(-) diff --git a/server.py b/server.py index ddfe7d2..c993fa4 100644 --- a/server.py +++ b/server.py @@ -15,11 +15,18 @@ class Settings(BaseSettings): redis_url: str = "redis://localhost:6379/0" ttl: int = 60 * 60 # 1 hour + socket_timeout: float = 10.0 # 5 seconds + socket_connect_timeout: float = 10.0 # 10 seconds def build_app(settings: Settings): # This doesn't connect to the redis, so it will work if redis is down. - redis_client = redis.from_url(settings.redis_url) + redis_client = redis.from_url( + settings.redis_url, + socket_timeout=settings.socket_timeout, + socket_connect_timeout=settings.socket_connect_timeout, + retry_on_timeout=False + ) @asynccontextmanager async def lifespan(app: FastAPI): diff --git a/tests/conftest.py b/tests/conftest.py index 01ecce4..9510f32 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -1,57 +1,13 @@ import pytest -import logging -import sys -from datetime import datetime from starlette.testclient import TestClient -from starlette.middleware.base import BaseHTTPMiddleware -from starlette.requests import Request from server import build_app, Settings -class ExceptionLoggingMiddleware(BaseHTTPMiddleware): - def __init__(self, app, logger): - super().__init__(app) - self.logger = logger - - async def dispatch(self, request: Request, call_next): - try: - response = await call_next(request) - return response - except Exception as e: - self.logger.error(f"Exception in {request.method} {request.url}: {type(e).__name__}: {e}", exc_info=True) - raise - - @pytest.fixture(scope="function") def client(): """Fixture providing TestClient following ws-tests pattern.""" - # Configure logging to write to file - log_filename = f"test_logs_{datetime.now().strftime('%Y%m%d_%H%M%S')}.log" - - # Clear any existing handlers - for handler in logging.root.handlers[:]: - logging.root.removeHandler(handler) - - # Set up file and console logging - file_handler = logging.FileHandler(log_filename) - console_handler = logging.StreamHandler(sys.stdout) - - formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s') - file_handler.setFormatter(formatter) - console_handler.setFormatter(formatter) - - # Configure logger for exceptions - logger = logging.getLogger("test_exceptions") - logger.setLevel(logging.ERROR) - logger.addHandler(file_handler) - logger.addHandler(console_handler) - settings = Settings(redis_url="redis://localhost:6379/0", ttl=60 * 60) app = build_app(settings) - # Add exception logging middleware - app.add_middleware(ExceptionLoggingMiddleware, logger=logger) - with TestClient(app) as client: - yield client - + yield client \ No newline at end of file diff --git a/tests/test_redis_timeout.py b/tests/test_redis_timeout.py index 7f45929..d1cfa23 100644 --- a/tests/test_redis_timeout.py +++ b/tests/test_redis_timeout.py @@ -5,76 +5,50 @@ import redis.asyncio as redis -def test_redis_client_timeout_on_unreachable_server(): - """Test that Redis operations timeout when server is unreachable.""" - from server import Settings, build_app - - # Use a non-existent Redis server to test timeout behavior - settings = Settings(redis_url="redis://localhost:9999/0", ttl=60 * 60) - app = build_app(settings) - - with TestClient(app) as test_client: - start_time = time.time() - - # This should fail quickly with a connection error, not hang indefinitely - with pytest.raises(Exception): # Expect an exception due to unreachable Redis - response = test_client.post("/upload") - - elapsed_time = time.time() - start_time - - # Should fail within a reasonable time (less than 5 seconds) - assert elapsed_time < 5.0, f"Redis operation took too long: {elapsed_time} seconds" - - def test_redis_command_with_slow_operation(): """Test that Redis operations timeout when they take too long.""" import asyncio + from server import Settings, build_app # Create a Redis client with short timeouts + settings = Settings(redis_url="redis://localhost:6379/0", ttl=60 * 60) + + # Create Redis client with timeout configuration redis_client = redis.from_url( - "redis://localhost:6379/0", - socket_timeout=0.5, # 500ms timeout - socket_connect_timeout=0.5, + settings.redis_url, + # Operations will hang indefinitely without this timeout. + socket_timeout=1.0, # 1 second timeout + socket_connect_timeout=1.0, retry_on_timeout=False ) async def run_slow_operation(): - # Use a Lua script that busy-waits for 2 seconds + # Use a Lua script that busy-waits for 3 seconds (longer than timeout) slow_script = """ - local start_time = redis.call('TIME') - local start_seconds = tonumber(start_time[1]) - local start_microseconds = tonumber(start_time[2]) - local target_time = start_seconds + 2 -- Add 2 seconds + local start_time = tonumber(redis.call('TIME')[1]) + local end_time = start_time + 3 - while true do - local current_time = redis.call('TIME') - local current_seconds = tonumber(current_time[1]) - if current_seconds >= target_time then - break - end + while tonumber(redis.call('TIME')[1]) < end_time do + -- busy wait end return "done" """ - # This should timeout because the script takes 2 seconds but timeout is 0.5s + # This should timeout because the script takes 3 seconds but timeout is 1s result = await redis_client.eval(slow_script, 0) return result start_time = time.time() - # Let's see what actually happens without expecting an exception - try: - result = asyncio.run(run_slow_operation()) - print(f"Operation completed successfully with result: {result}") - except Exception as e: - print(f"Operation failed with exception: {type(e).__name__}: {e}") + # This should timeout, not complete successfully + with pytest.raises((redis.TimeoutError, redis.ConnectionError, Exception)): + asyncio.run(run_slow_operation()) elapsed_time = time.time() - start_time - print(f"Operation took {elapsed_time} seconds") - # For now, just assert it completes in reasonable time - assert elapsed_time < 10.0, f"Redis operation took too long: {elapsed_time} seconds" + # Should timeout within a reasonable time (much less than 3 seconds) + assert elapsed_time < 2.0, f"Redis operation took too long: {elapsed_time} seconds" # Clean up try: From f1504143a9da38ac61df61cdb110f184dbfb2eff Mon Sep 17 00:00:00 2001 From: gbischof Date: Tue, 8 Jul 2025 15:21:23 -0400 Subject: [PATCH 3/7] touch ups --- server.py | 1 - tests/test_redis_timeout.py | 4 +--- 2 files changed, 1 insertion(+), 4 deletions(-) diff --git a/server.py b/server.py index c993fa4..bd93553 100644 --- a/server.py +++ b/server.py @@ -25,7 +25,6 @@ def build_app(settings: Settings): settings.redis_url, socket_timeout=settings.socket_timeout, socket_connect_timeout=settings.socket_connect_timeout, - retry_on_timeout=False ) @asynccontextmanager diff --git a/tests/test_redis_timeout.py b/tests/test_redis_timeout.py index d1cfa23..08dc928 100644 --- a/tests/test_redis_timeout.py +++ b/tests/test_redis_timeout.py @@ -1,14 +1,12 @@ import time -from starlette.testclient import TestClient import pytest -from unittest.mock import patch, MagicMock import redis.asyncio as redis def test_redis_command_with_slow_operation(): """Test that Redis operations timeout when they take too long.""" import asyncio - from server import Settings, build_app + from server import Settings # Create a Redis client with short timeouts settings = Settings(redis_url="redis://localhost:6379/0", ttl=60 * 60) From f39fea8ec4ab9a7877cc58438db5a72d3bc93987 Mon Sep 17 00:00:00 2001 From: gbischof Date: Tue, 8 Jul 2025 15:23:58 -0400 Subject: [PATCH 4/7] touch ups --- tests/test_redis_timeout.py | 5 +---- 1 file changed, 1 insertion(+), 4 deletions(-) diff --git a/tests/test_redis_timeout.py b/tests/test_redis_timeout.py index 08dc928..c267c29 100644 --- a/tests/test_redis_timeout.py +++ b/tests/test_redis_timeout.py @@ -8,15 +8,12 @@ def test_redis_command_with_slow_operation(): import asyncio from server import Settings - # Create a Redis client with short timeouts - settings = Settings(redis_url="redis://localhost:6379/0", ttl=60 * 60) - # Create Redis client with timeout configuration + settings = Settings(redis_url="redis://localhost:6379/0", ttl=60 * 60) redis_client = redis.from_url( settings.redis_url, # Operations will hang indefinitely without this timeout. socket_timeout=1.0, # 1 second timeout - socket_connect_timeout=1.0, retry_on_timeout=False ) From 2b3936a9597978a9cc5783c4f47c58b6b37fd93c Mon Sep 17 00:00:00 2001 From: gbischof Date: Tue, 8 Jul 2025 15:34:03 -0400 Subject: [PATCH 5/7] touch up --- tests/test_redis_timeout.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/tests/test_redis_timeout.py b/tests/test_redis_timeout.py index c267c29..1b3bb48 100644 --- a/tests/test_redis_timeout.py +++ b/tests/test_redis_timeout.py @@ -37,7 +37,7 @@ async def run_slow_operation(): start_time = time.time() # This should timeout, not complete successfully - with pytest.raises((redis.TimeoutError, redis.ConnectionError, Exception)): + with pytest.raises((redis.TimeoutError)): asyncio.run(run_slow_operation()) elapsed_time = time.time() - start_time @@ -48,5 +48,5 @@ async def run_slow_operation(): # Clean up try: asyncio.run(redis_client.aclose()) - except: + except Exception: pass From 6102aedd1d1a7e22b3c43a96bf0d180f05682ee5 Mon Sep 17 00:00:00 2001 From: gbischof Date: Tue, 8 Jul 2025 15:34:48 -0400 Subject: [PATCH 6/7] whitespace --- tests/conftest.py | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/tests/conftest.py b/tests/conftest.py index 9510f32..91b9111 100644 --- a/tests/conftest.py +++ b/tests/conftest.py @@ -10,4 +10,5 @@ def client(): app = build_app(settings) with TestClient(app) as client: - yield client \ No newline at end of file + yield client + From 54a1389438e9240a2bfefee09b41ca953659b9ea Mon Sep 17 00:00:00 2001 From: gbischof Date: Wed, 9 Jul 2025 13:20:01 -0400 Subject: [PATCH 7/7] clean up --- tests/test_redis_timeout.py | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/tests/test_redis_timeout.py b/tests/test_redis_timeout.py index 1b3bb48..fb5cd52 100644 --- a/tests/test_redis_timeout.py +++ b/tests/test_redis_timeout.py @@ -9,9 +9,8 @@ def test_redis_command_with_slow_operation(): from server import Settings # Create Redis client with timeout configuration - settings = Settings(redis_url="redis://localhost:6379/0", ttl=60 * 60) redis_client = redis.from_url( - settings.redis_url, + "redis://localhost:6379/0", # Operations will hang indefinitely without this timeout. socket_timeout=1.0, # 1 second timeout retry_on_timeout=False