From a51024f01d9cadf74cd5f1750e7d4b3c879e6281 Mon Sep 17 00:00:00 2001 From: Joshua Li Date: Wed, 30 Apr 2025 15:04:04 -0700 Subject: [PATCH 01/10] feat: exponentially backoff retries for pullinh --- devservices/commands/up.py | 4 +- devservices/utils/docker_compose.py | 59 +++++++++++++++++++++++------ 2 files changed, 51 insertions(+), 12 deletions(-) diff --git a/devservices/commands/up.py b/devservices/commands/up.py index 03aa7085..9ae82949 100644 --- a/devservices/commands/up.py +++ b/devservices/commands/up.py @@ -157,7 +157,9 @@ def up(args: Namespace) -> None: def _pull_dependency_images( cmd: DockerComposeCommand, current_env: dict[str, str], status: Status ) -> None: - run_cmd(cmd.full_command, current_env) + run_cmd( + cmd.full_command, current_env, retries=4, retry_initial_wait=5.0, retry_exp=2.0 + ) for dependency in cmd.services: status.info(f"Pulled image for {dependency}") diff --git a/devservices/utils/docker_compose.py b/devservices/utils/docker_compose.py index 8eba334d..3ac05f52 100644 --- a/devservices/utils/docker_compose.py +++ b/devservices/utils/docker_compose.py @@ -5,7 +5,9 @@ import os import platform import re +import shlex import subprocess +import time from typing import cast from typing import NamedTuple @@ -290,15 +292,50 @@ def get_docker_compose_commands_to_run( return docker_compose_commands -def run_cmd(cmd: list[str], env: dict[str, str]) -> subprocess.CompletedProcess[str]: +def run_cmd( + cmd: list[str], + env: dict[str, str], + retries: int = 0, + retry_initial_wait: float = 5.0, + retry_exp: float = 2.0, +) -> subprocess.CompletedProcess[str]: + if retries < 0: + raise ValueError("Retries cannot be negative") + logger = logging.getLogger(LOGGER_NAME) - try: - logger.debug("Running command: %s", " ".join(cmd)) - return subprocess.run(cmd, check=True, capture_output=True, text=True, env=env) - except subprocess.CalledProcessError as e: - raise DockerComposeError( - command=" ".join(cmd), - returncode=e.returncode, - stdout=e.stdout, - stderr=e.stderr, - ) from e + cmd_pretty = shlex.join(cmd) + + while retries >= 0: + try: + logger.debug(f"Running command: {cmd_pretty}") + proc = subprocess.run( + cmd, check=True, capture_output=True, text=True, env=env + ) + return proc + except subprocess.CalledProcessError as e: + if retries == 0: + raise DockerComposeError( + command=cmd_pretty, + returncode=e.returncode, + stdout=e.stdout, + stderr=e.stderr, + ) from e + + err = DockerComposeError( + command=cmd_pretty, + returncode=e.returncode, + stdout=e.stdout, + stderr=e.stderr, + ) + print( + f""" +Error: {err} + +Retrying in {retry_initial_wait}s ({retries} retries left)... +""" + ) + time.sleep(retry_initial_wait) + retries -= 1 + retry_initial_wait *= retry_exp + + return proc From 6576c5d2c54999786b0f495317f370b3b90e8a34 Mon Sep 17 00:00:00 2001 From: Joshua Li Date: Wed, 30 Apr 2025 15:06:19 -0700 Subject: [PATCH 02/10] feat: exponentially backoff retries for pullinh --- devservices/utils/docker_compose.py | 15 ++++----------- 1 file changed, 4 insertions(+), 11 deletions(-) diff --git a/devservices/utils/docker_compose.py b/devservices/utils/docker_compose.py index 3ac05f52..945c981a 100644 --- a/devservices/utils/docker_compose.py +++ b/devservices/utils/docker_compose.py @@ -305,7 +305,7 @@ def run_cmd( logger = logging.getLogger(LOGGER_NAME) cmd_pretty = shlex.join(cmd) - while retries >= 0: + while True: try: logger.debug(f"Running command: {cmd_pretty}") proc = subprocess.run( @@ -313,20 +313,15 @@ def run_cmd( ) return proc except subprocess.CalledProcessError as e: - if retries == 0: - raise DockerComposeError( - command=cmd_pretty, - returncode=e.returncode, - stdout=e.stdout, - stderr=e.stderr, - ) from e - err = DockerComposeError( command=cmd_pretty, returncode=e.returncode, stdout=e.stdout, stderr=e.stderr, ) + if retries == 0: + raise err + print( f""" Error: {err} @@ -337,5 +332,3 @@ def run_cmd( time.sleep(retry_initial_wait) retries -= 1 retry_initial_wait *= retry_exp - - return proc From b99fc48e9501004b2c8d055b6097949dca370a41 Mon Sep 17 00:00:00 2001 From: Joshua Li Date: Tue, 6 May 2025 09:12:53 -0700 Subject: [PATCH 03/10] test --- devservices/commands/up.py | 1 + tests/commands/test_up.py | 101 +++++++++++++++++++++++++++++++++++++ 2 files changed, 102 insertions(+) diff --git a/devservices/commands/up.py b/devservices/commands/up.py index 9ae82949..3bdd6c19 100644 --- a/devservices/commands/up.py +++ b/devservices/commands/up.py @@ -201,6 +201,7 @@ def _up( ) ), ) + # Pull all images in parallel status.info("Pulling images") pull_commands = get_docker_compose_commands_to_run( diff --git a/tests/commands/test_up.py b/tests/commands/test_up.py index 9cb00fdb..f21e426e 100644 --- a/tests/commands/test_up.py +++ b/tests/commands/test_up.py @@ -5,6 +5,7 @@ from argparse import Namespace from pathlib import Path from unittest import mock +from unittest.mock import call import pytest @@ -339,6 +340,106 @@ def test_up_error( assert "Starting redis" not in captured.out.strip() +@mock.patch("time.sleep") +@mock.patch("devservices.utils.state.State.remove_service_entry") +@mock.patch("devservices.utils.state.State.update_service_entry") +@mock.patch("devservices.commands.up._create_devservices_network") +@mock.patch("devservices.commands.up.check_all_containers_healthy") +@mock.patch( + "devservices.utils.docker_compose.get_non_remote_services", + return_value={"clickhouse", "redis"}, +) +def test_up_pull_error_timeout( + mock_get_non_remote_services: mock.Mock, + mock_check_all_containers_healthy: mock.Mock, + mock_create_devservices_network: mock.Mock, + mock_update_service_entry: mock.Mock, + mock_remove_service_entry: mock.Mock, + mock_sleep: mock.Mock, + capsys: pytest.CaptureFixture[str], + tmp_path: Path, +) -> None: + config = { + "x-sentry-service-config": { + "version": 0.1, + "service_name": "example-service", + "dependencies": { + "redis": {"description": "Redis"}, + "clickhouse": {"description": "Clickhouse"}, + }, + "modes": {"default": ["redis", "clickhouse"]}, + }, + "services": { + "redis": {"image": "redis:6.2.14-alpine"}, + "clickhouse": { + "image": "altinity/clickhouse-server:23.8.11.29.altinitystable" + }, + }, + } + + create_config_file(tmp_path, config) + os.chdir(tmp_path) + + args = Namespace(service_name=None, debug=False, mode="default") + + with pytest.raises(SystemExit): + with mock.patch( + "devservices.utils.docker_compose.subprocess.run", + side_effect=[ + subprocess.CalledProcessError( + returncode=1, output="", stderr="TLS handshake timeout", cmd="" + ), + subprocess.CalledProcessError( + returncode=1, output="", stderr="TLS handshake timeout", cmd="" + ), + subprocess.CalledProcessError( + returncode=1, output="", stderr="TLS handshake timeout", cmd="" + ), + subprocess.CalledProcessError( + returncode=1, output="", stderr="TLS handshake timeout", cmd="" + ), + subprocess.CalledProcessError( + returncode=1, output="", stderr="TLS handshake timeout", cmd="" + ), + ], + ) as mock_subprocess_run: + up(args) + + # assert multiple failled calls + assert ( + mock_subprocess_run.mock_calls + == [ + call( + [ + "docker", + "compose", + "-p", + "example-service", + "-f", + f"{tmp_path}/{DEVSERVICES_DIR_NAME}/{CONFIG_FILE_NAME}", + "pull", + "clickhouse", + "redis", + ], + check=True, + capture_output=True, + text=True, + env=mock.ANY, + ) + ] + * 5 + ) + + mock_create_devservices_network.assert_called_once() + mock_check_all_containers_healthy.assert_not_called() + # Capture the printed output + captured = capsys.readouterr() + + assert ( + "Failed to start example-service: TLS handshake timeout" in captured.out.strip() + ) + + @mock.patch("devservices.utils.state.State.remove_service_entry") @mock.patch("devservices.utils.state.State.update_service_entry") @mock.patch("devservices.commands.up._create_devservices_network") From 3639b295999477f9bf2f5f5cb7703e5029c782dc Mon Sep 17 00:00:00 2001 From: Joshua Li Date: Tue, 6 May 2025 09:32:11 -0700 Subject: [PATCH 04/10] add test for eventual success --- tests/commands/test_up.py | 113 ++++++++++++++++++++++++++++++++++++++ 1 file changed, 113 insertions(+) diff --git a/tests/commands/test_up.py b/tests/commands/test_up.py index f21e426e..b3961c28 100644 --- a/tests/commands/test_up.py +++ b/tests/commands/test_up.py @@ -440,6 +440,119 @@ def test_up_pull_error_timeout( ) +@mock.patch("time.sleep") +@mock.patch("devservices.utils.state.State.remove_service_entry") +@mock.patch("devservices.utils.state.State.update_service_entry") +@mock.patch("devservices.commands.up._create_devservices_network") +@mock.patch("devservices.commands.up.check_all_containers_healthy") +@mock.patch( + "devservices.utils.docker_compose.get_non_remote_services", + return_value={"clickhouse", "redis"}, +) +@mock.patch( + "devservices.commands.up.get_container_names_for_project", + return_value=["x", "y"], +) +def test_up_pull_error_eventual_success( + mock_get_container_names_for_project: mock.Mock, + mock_get_non_remote_services: mock.Mock, + mock_check_all_containers_healthy: mock.Mock, + mock_create_devservices_network: mock.Mock, + mock_update_service_entry: mock.Mock, + mock_remove_service_entry: mock.Mock, + mock_sleep: mock.Mock, + capsys: pytest.CaptureFixture[str], + tmp_path: Path, +) -> None: + config = { + "x-sentry-service-config": { + "version": 0.1, + "service_name": "example-service", + "dependencies": { + "redis": {"description": "Redis"}, + "clickhouse": {"description": "Clickhouse"}, + }, + "modes": {"default": ["redis", "clickhouse"]}, + }, + "services": { + "redis": {"image": "redis:6.2.14-alpine"}, + "clickhouse": { + "image": "altinity/clickhouse-server:23.8.11.29.altinitystable" + }, + }, + } + + create_config_file(tmp_path, config) + os.chdir(tmp_path) + + args = Namespace(service_name=None, debug=False, mode="default") + + with mock.patch( + "devservices.utils.docker_compose.subprocess.run", + side_effect=[ + subprocess.CalledProcessError( + returncode=1, output="", stderr="TLS handshake timeout", cmd="" + ), + subprocess.CalledProcessError( + returncode=1, output="", stderr="TLS handshake timeout", cmd="" + ), + subprocess.CompletedProcess( + args=(), + returncode=0, + ), + subprocess.CompletedProcess( + args=(), + returncode=0, + ), + ], + ) as mock_subprocess_run: + up(args) + + assert mock_subprocess_run.mock_calls == [ + call( + [ + "docker", + "compose", + "-p", + "example-service", + "-f", + f"{tmp_path}/{DEVSERVICES_DIR_NAME}/{CONFIG_FILE_NAME}", + "pull", + "clickhouse", + "redis", + ], + check=True, + capture_output=True, + text=True, + env=mock.ANY, + ) + ] * 3 + [ + call( + [ + "docker", + "compose", + "-p", + "example-service", + "-f", + f"{tmp_path}/{DEVSERVICES_DIR_NAME}/{CONFIG_FILE_NAME}", + "up", + "clickhouse", + "redis", + "-d", + ], + check=True, + capture_output=True, + text=True, + env=mock.ANY, + ) + ] + + mock_create_devservices_network.assert_called_once() + captured = capsys.readouterr() + + assert "example-service started" in captured.out.strip() + + @mock.patch("devservices.utils.state.State.remove_service_entry") @mock.patch("devservices.utils.state.State.update_service_entry") @mock.patch("devservices.commands.up._create_devservices_network") From efa144a639fd85919d3cea66188e62bfad73506b Mon Sep 17 00:00:00 2001 From: Joshua Li Date: Tue, 6 May 2025 09:35:06 -0700 Subject: [PATCH 05/10] fedback --- devservices/commands/up.py | 4 +--- devservices/utils/docker_compose.py | 3 ++- 2 files changed, 3 insertions(+), 4 deletions(-) diff --git a/devservices/commands/up.py b/devservices/commands/up.py index 3bdd6c19..615fa95f 100644 --- a/devservices/commands/up.py +++ b/devservices/commands/up.py @@ -157,9 +157,7 @@ def up(args: Namespace) -> None: def _pull_dependency_images( cmd: DockerComposeCommand, current_env: dict[str, str], status: Status ) -> None: - run_cmd( - cmd.full_command, current_env, retries=4, retry_initial_wait=5.0, retry_exp=2.0 - ) + run_cmd(cmd.full_command, current_env, retries=4) for dependency in cmd.services: status.info(f"Pulled image for {dependency}") diff --git a/devservices/utils/docker_compose.py b/devservices/utils/docker_compose.py index 945c981a..afeced21 100644 --- a/devservices/utils/docker_compose.py +++ b/devservices/utils/docker_compose.py @@ -303,6 +303,7 @@ def run_cmd( raise ValueError("Retries cannot be negative") logger = logging.getLogger(LOGGER_NAME) + console = Console() cmd_pretty = shlex.join(cmd) while True: @@ -322,7 +323,7 @@ def run_cmd( if retries == 0: raise err - print( + console.warning( f""" Error: {err} From de776a5f436b9a41b50daae1bd289f5ef7c3ffb5 Mon Sep 17 00:00:00 2001 From: Joshua Li Date: Tue, 6 May 2025 10:25:55 -0700 Subject: [PATCH 06/10] feedback --- devservices/utils/docker_compose.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/devservices/utils/docker_compose.py b/devservices/utils/docker_compose.py index afeced21..a6b280e8 100644 --- a/devservices/utils/docker_compose.py +++ b/devservices/utils/docker_compose.py @@ -306,7 +306,7 @@ def run_cmd( console = Console() cmd_pretty = shlex.join(cmd) - while True: + while retries >= 0: try: logger.debug(f"Running command: {cmd_pretty}") proc = subprocess.run( From 3d05e0705bcdfcdad4b24b0cd9041a33872dec64 Mon Sep 17 00:00:00 2001 From: Joshua Li Date: Thu, 8 May 2025 14:42:52 -0700 Subject: [PATCH 07/10] mypy happy --- devservices/utils/docker_compose.py | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/devservices/utils/docker_compose.py b/devservices/utils/docker_compose.py index a6b280e8..13905f56 100644 --- a/devservices/utils/docker_compose.py +++ b/devservices/utils/docker_compose.py @@ -312,7 +312,6 @@ def run_cmd( proc = subprocess.run( cmd, check=True, capture_output=True, text=True, env=env ) - return proc except subprocess.CalledProcessError as e: err = DockerComposeError( command=cmd_pretty, @@ -333,3 +332,5 @@ def run_cmd( time.sleep(retry_initial_wait) retries -= 1 retry_initial_wait *= retry_exp + + return proc From 45184008fddb6e85dde42644af7d7cc855633341 Mon Sep 17 00:00:00 2001 From: Joshua Li Date: Fri, 9 May 2025 11:26:57 -0700 Subject: [PATCH 08/10] feedback --- devservices/utils/docker_compose.py | 7 ++++--- tests/commands/test_up.py | 3 ++- 2 files changed, 6 insertions(+), 4 deletions(-) diff --git a/devservices/utils/docker_compose.py b/devservices/utils/docker_compose.py index 13905f56..1463c10d 100644 --- a/devservices/utils/docker_compose.py +++ b/devservices/utils/docker_compose.py @@ -306,7 +306,10 @@ def run_cmd( console = Console() cmd_pretty = shlex.join(cmd) - while retries >= 0: + retries += 1 # initial try + + while retries > 0: + retries -= 1 try: logger.debug(f"Running command: {cmd_pretty}") proc = subprocess.run( @@ -330,7 +333,5 @@ def run_cmd( """ ) time.sleep(retry_initial_wait) - retries -= 1 retry_initial_wait *= retry_exp - return proc diff --git a/tests/commands/test_up.py b/tests/commands/test_up.py index b3961c28..5f60d86e 100644 --- a/tests/commands/test_up.py +++ b/tests/commands/test_up.py @@ -405,7 +405,7 @@ def test_up_pull_error_timeout( ) as mock_subprocess_run: up(args) - # assert multiple failled calls + # assert multiple failed calls assert ( mock_subprocess_run.mock_calls == [ @@ -427,6 +427,7 @@ def test_up_pull_error_timeout( env=mock.ANY, ) ] + # default is 4 retries (5 tries total) * 5 ) From ef05f10f81707828a334e35653ec44e867a75ca3 Mon Sep 17 00:00:00 2001 From: Joshua Li Date: Fri, 9 May 2025 11:32:51 -0700 Subject: [PATCH 09/10] happy mypy --- devservices/utils/docker_compose.py | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/devservices/utils/docker_compose.py b/devservices/utils/docker_compose.py index 1463c10d..73ea206e 100644 --- a/devservices/utils/docker_compose.py +++ b/devservices/utils/docker_compose.py @@ -306,6 +306,7 @@ def run_cmd( console = Console() cmd_pretty = shlex.join(cmd) + proc = None retries += 1 # initial try while retries > 0: @@ -335,3 +336,6 @@ def run_cmd( time.sleep(retry_initial_wait) retry_initial_wait *= retry_exp + # make mypy happy + assert proc is not None + return proc From 177f6056fe0b81582be68717e3a46ba7161ecefd Mon Sep 17 00:00:00 2001 From: Joshua Li Date: Fri, 9 May 2025 11:37:46 -0700 Subject: [PATCH 10/10] forgot --- devservices/utils/docker_compose.py | 1 + 1 file changed, 1 insertion(+) diff --git a/devservices/utils/docker_compose.py b/devservices/utils/docker_compose.py index 73ea206e..d8a26cf5 100644 --- a/devservices/utils/docker_compose.py +++ b/devservices/utils/docker_compose.py @@ -316,6 +316,7 @@ def run_cmd( proc = subprocess.run( cmd, check=True, capture_output=True, text=True, env=env ) + return proc except subprocess.CalledProcessError as e: err = DockerComposeError( command=cmd_pretty,