From 38a306b4123fb7f2e00ad8c7d1cbefddc55c297f Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=EA=B9=80=EA=B8=B0=EB=AF=BC?= Date: Sun, 4 Oct 2026 01:28:17 +0900 Subject: [PATCH 1/9] test: prepare reusable observability drill controls --- monitoring/drills/run_drill.py | 45 ++++++++++++++++++++++++++++------ 1 file changed, 38 insertions(+), 7 deletions(-) diff --git a/monitoring/drills/run_drill.py b/monitoring/drills/run_drill.py index a64c73cc..48f6ad47 100755 --- a/monitoring/drills/run_drill.py +++ b/monitoring/drills/run_drill.py @@ -106,6 +106,20 @@ def wait_for(description, predicate, timeout_seconds, interval_seconds=1): raise TimeoutError(f"Timed out after {timeout_seconds}s waiting for {description}{detail}") +def assert_absent_for(description, predicate, duration_seconds, interval_seconds=1): + """Fail if an observable event appears during a bounded negative-check window.""" + deadline = time.monotonic() + duration_seconds + next_progress = time.monotonic() + 30 + while time.monotonic() < deadline: + if predicate(): + raise AssertionError(f"Unexpected event while checking {description}") + now = time.monotonic() + if now >= next_progress: + print(f"Still verifying absence of {description}...", flush=True) + next_progress = now + 30 + time.sleep(interval_seconds) + + def nearest_rank(values, percentile): """Calculate an explicit nearest-rank percentile without external benchmark libraries.""" ordered = sorted(values) @@ -184,8 +198,16 @@ def psql(self, sql): ) return result.stdout.strip() - def start_backend(self, jar_path, name, *, worker_enabled, snapshot_interval): - """Launch a real Backend process against this scenario's database and shared local files.""" + def start_backend( + self, + jar_path, + name, + *, + worker_enabled, + snapshot_interval, + environment_overrides=None, + ): + """Launch a real Backend process with optional scenario-specific non-secret settings.""" api_port = free_port() management_port = free_port() log_path = self.log_dir / f"backend-{name}.log" @@ -228,6 +250,8 @@ def start_backend(self, jar_path, name, *, worker_enabled, snapshot_interval): "SERVER_PORT": str(api_port), "MANAGEMENT_PORT": str(management_port), }) + # Scenario overrides are applied last so timing tests can remove randomness without changing defaults. + environment.update(environment_overrides or {}) process = subprocess.Popen( ["java", "-jar", str(jar_path)], cwd=ROOT_DIR, @@ -403,7 +427,14 @@ def fetch_metrics(backend): return body.decode("utf-8") -def login_and_upload(backend, temp_dir): +def login_and_upload( + backend, + temp_dir, + *, + filename="queue-stall.txt", + title="Observability Queue Recovery Drill", + description="Actual queue alert and worker recovery", +): """Create a real pending Embedding Job through authentication and multipart upload APIs.""" _, login_response = request_json( f"http://127.0.0.1:{backend['apiPort']}/auth/login", @@ -411,7 +442,7 @@ def login_and_upload(backend, temp_dir): payload={"email": "kcw130502@gmail.com", "password": "admin1234"}, ) access_token = login_response["data"]["accessToken"] - document_path = temp_dir / "queue-stall.txt" + document_path = temp_dir / filename document_path.write_text( "A recovered indexing worker must claim this queued document and complete its embedding.", encoding="utf-8", @@ -429,13 +460,13 @@ def append_field(name, value): parts.extend([ f"--{boundary}\r\n".encode(), - b'Content-Disposition: form-data; name="file"; filename="queue-stall.txt"\r\n', + f'Content-Disposition: form-data; name="file"; filename="{filename}"\r\n'.encode(), b"Content-Type: text/plain\r\n\r\n", document_path.read_bytes(), b"\r\n", ]) - append_field("title", "Observability Queue Recovery Drill") - append_field("description", "Actual queue alert and worker recovery") + append_field("title", title) + append_field("description", description) append_field("visibility", "PRIVATE") parts.append(f"--{boundary}--\r\n".encode()) upload_request = urllib.request.Request( From d12ba611453e63159525f11354fc50259c303bce Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=EA=B9=80=EA=B8=B0=EB=AF=BC?= Date: Sun, 4 Oct 2026 01:30:06 +0900 Subject: [PATCH 2/9] test: add embedding circuit recovery drill --- monitoring/drills/run_drill.py | 385 ++++++++++++++++++++++++++++++++- 1 file changed, 382 insertions(+), 3 deletions(-) diff --git a/monitoring/drills/run_drill.py b/monitoring/drills/run_drill.py index 48f6ad47..a9693638 100755 --- a/monitoring/drills/run_drill.py +++ b/monitoring/drills/run_drill.py @@ -427,6 +427,43 @@ def fetch_metrics(backend): return body.decode("utf-8") +def circuit_metric_snapshot(backend): + """Read one exposition snapshot of the Circuit, Probe, and delayed Retry metrics.""" + metrics = fetch_metrics(backend) + return { + "open": metric_value(metrics, "docgrid_embedding_provider_circuit_open"), + "probeFailed": metric_value( + metrics, "docgrid_embedding_provider_circuit_probe_failed" + ), + "openTransitions": metric_value( + metrics, + "docgrid_embedding_provider_circuit_transitions_total", + {"state": "open"}, + ), + "halfOpenTransitions": metric_value( + metrics, + "docgrid_embedding_provider_circuit_transitions_total", + {"state": "half_open"}, + ), + "closedTransitions": metric_value( + metrics, + "docgrid_embedding_provider_circuit_transitions_total", + {"state": "closed"}, + ), + "failedProbes": metric_value( + metrics, + "docgrid_embedding_provider_circuit_probe_total", + {"outcome": "failed"}, + ), + "successfulProbes": metric_value( + metrics, + "docgrid_embedding_provider_circuit_probe_total", + {"outcome": "success"}, + ), + "delayedRetryJobs": metric_value(metrics, "docgrid_embedding_delayed_retry_jobs"), + } + + def login_and_upload( backend, temp_dir, @@ -726,6 +763,339 @@ def run_provider_outage(output_dir): environment.close() +def run_circuit_recovery(output_dir, jar_path): + """Drive one real Job through Circuit protection, failed Probe, and successful recovery.""" + environment = DrillEnvironment("circuit-recovery", output_dir) + provider_paused = False + try: + # 1. Create a real Job while the Provider is healthy, but keep all Workers disabled. + environment.start_core(include_provider=True) + wait_for( + "initial Embedding Provider readiness", + lambda: request( + f"http://127.0.0.1:{environment.embedding_port}/health/ready", + timeout=5, + )[0] == 200, + 900, + 5, + ) + observer = environment.start_backend( + jar_path, "circuit-observer", worker_enabled=False, snapshot_interval="2s" + ) + upload = login_and_upload( + observer, + environment.temp_dir, + filename="circuit-recovery.txt", + title="Embedding Circuit Recovery Drill", + description="Actual Circuit alert, Probe failure, and recovery", + ) + job_id = int(upload["embeddingJobId"]) + document_version_id = int(upload["documentVersionId"]) + environment.psql( + "UPDATE sync_outbox_events SET status='PROCESSED', processed_at=CURRENT_TIMESTAMP, " + "updated_at=CURRENT_TIMESTAMP WHERE event_id=(SELECT source_event_id FROM embedding_jobs " + f"WHERE id={job_id})" + ) + # The default three retries would terminate at the first failed Probe; preserve recovery headroom. + environment.psql( + "UPDATE embedding_jobs SET max_retry_count=10, updated_at=CURRENT_TIMESTAMP " + f"WHERE id={job_id}" + ) + + # 2. Pause the existing container so Backend and Prometheus see an outage without changing its port. + print("Pausing the real Embedding Provider container...", flush=True) + provider_paused_at = utc_now() + environment.compose("pause", "embedding-server", capture=False) + provider_paused = True + worker = environment.start_backend( + jar_path, + "circuit-worker", + worker_enabled=True, + snapshot_interval="2s", + environment_overrides={"INDEXING_WORKER_RETRY_JITTER_RATIO": "0"}, + ) + environment.write_prometheus_config(worker["managementPort"]) + environment.start_prometheus() + wait_for( + "Prometheus to scrape the Circuit Worker", + lambda: environment.prometheus_value('up{job="docgrid-backend"}') == 1, + 60, + ) + provider_down_condition_at = wait_for( + "Prometheus up=0 provider condition", + lambda: utc_now() if environment.prometheus_value( + 'up{job="embedding-provider"}' + ) == 0 else None, + 60, + ) + + # 3. Observe the first OPEN and a real future Retry before the Half-open failure. + circuit_open_snapshot = wait_for( + "the Worker Circuit to open", + lambda: ( + snapshot if ( + (snapshot := circuit_metric_snapshot(worker))["open"] == 1 + and snapshot["openTransitions"] >= 1 + ) else None + ), + 120, + ) + circuit_opened_at = utc_now() + delayed_retry_snapshot = wait_for( + "a delayed Retry Job after Circuit OPEN", + lambda: ( + snapshot if ( + (snapshot := circuit_metric_snapshot(worker))["delayedRetryJobs"] >= 1 + and environment.psql( + f"SELECT status FROM embedding_jobs WHERE id={job_id}" + ) == "PENDING" + ) else None + ), + 60, + ) + delayed_retry_observed_at = utc_now() + + # 4. Wait for the real failed Probe and freeze only this Job while the production for-clause matures. + failed_probe_snapshot = wait_for( + "a failed Half-open Probe and Retry persistence", + lambda: ( + snapshot if ( + (snapshot := circuit_metric_snapshot(worker))["failedProbes"] >= 1 + and snapshot["probeFailed"] == 1 + and snapshot["openTransitions"] >= 2 + and environment.psql( + f"SELECT status FROM embedding_jobs WHERE id={job_id}" + ) == "PENDING" + ) else None + ), + 120, + ) + failed_probe_at = utc_now() + environment.psql( + "UPDATE embedding_jobs SET next_retry_at=CURRENT_TIMESTAMP + INTERVAL '10 minutes', " + f"updated_at=CURRENT_TIMESTAMP WHERE id={job_id} AND status='PENDING'" + ) + wait_for( + "the frozen Job to remain visible as delayed Retry", + lambda: circuit_metric_snapshot(worker)["delayedRetryJobs"] >= 1, + 30, + ) + + # 5. Verify the real root-cause alert, Circuit alert, and Alertmanager inhibition boundary. + provider_down_firing_at = wait_for( + "EmbeddingProviderDown firing state", + lambda: utc_now() if environment.prometheus_alert( + "EmbeddingProviderDown", "firing" + ) else None, + 150, + 2, + ) + provider_down_delivery = wait_for( + "EmbeddingProviderDown firing webhook", + lambda: environment.webhook_delivery("EmbeddingProviderDown", "firing"), + 60, + ) + circuit_alert_pending_at = wait_for( + "DocGridEmbeddingProviderCircuitOpen pending state", + lambda: utc_now() if environment.prometheus_alert( + "DocGridEmbeddingProviderCircuitOpen", "pending" + ) else None, + 60, + 2, + ) + circuit_alert_firing_at = wait_for( + "DocGridEmbeddingProviderCircuitOpen firing state", + lambda: utc_now() if environment.prometheus_alert( + "DocGridEmbeddingProviderCircuitOpen", "firing" + ) else None, + 120, + 2, + ) + inhibited_circuit_alert = wait_for( + "Circuit warning inhibition by the Provider root cause", + lambda: ( + alert if ( + (alert := environment.alertmanager_alert( + "DocGridEmbeddingProviderCircuitOpen" + )) and alert.get("status", {}).get("state") == "suppressed" + ) else None + ), + 60, + ) + circuit_suppressed_at = utc_now() + assert_absent_for( + "Circuit warning firing webhook while inhibited", + lambda: environment.webhook_delivery( + "DocGridEmbeddingProviderCircuitOpen", "firing" + ), + 35, + ) + + # 6. Resume the same Provider, release the frozen Retry, and require a successful Probe closure. + print("Unpausing the real Embedding Provider container...", flush=True) + recovery_started_at = utc_now() + environment.compose("unpause", "embedding-server", capture=False) + provider_paused = False + wait_for( + "Embedding Provider readiness after unpause", + lambda: request( + f"http://127.0.0.1:{environment.embedding_port}/health/ready", + timeout=5, + )[0] == 200, + 120, + 2, + ) + provider_ready_at = utc_now() + wait_for( + "Prometheus to observe Provider recovery", + lambda: environment.prometheus_value('up{job="embedding-provider"}') == 1, + 60, + ) + environment.psql( + "UPDATE embedding_jobs SET next_retry_at=CURRENT_TIMESTAMP, updated_at=CURRENT_TIMESTAMP " + f"WHERE id={job_id} AND status='PENDING'" + ) + successful_probe_snapshot = wait_for( + "the successful Probe to close the Circuit", + lambda: ( + snapshot if ( + (snapshot := circuit_metric_snapshot(worker))["successfulProbes"] >= 1 + and snapshot["closedTransitions"] >= 1 + and snapshot["open"] == 0 + and snapshot["probeFailed"] == 0 + ) else None + ), + 120, + ) + successful_probe_at = utc_now() + job_indexed_at = wait_for( + "the recovered Job to reach INDEXED", + lambda: utc_now() if environment.psql( + f"SELECT status FROM embedding_jobs WHERE id={job_id}" + ) == "INDEXED" else None, + 120, + 2, + ) + embedding_count = int(environment.psql( + "SELECT COUNT(*) FROM embeddings WHERE document_version_id=" + f"{document_version_id}" + )) + if embedding_count <= 0: + raise AssertionError("Recovered Job reached INDEXED without stored embeddings") + + # 7. Require both Prometheus alerts to clear and only the root-cause lifecycle to be delivered. + alerts_resolved_at = wait_for( + "Provider and Circuit alerts to resolve in Prometheus", + lambda: utc_now() if ( + not environment.prometheus_alert("EmbeddingProviderDown") + and not environment.prometheus_alert("DocGridEmbeddingProviderCircuitOpen") + ) else None, + 90, + 2, + ) + provider_down_resolved = wait_for( + "EmbeddingProviderDown resolved webhook", + lambda: environment.webhook_delivery("EmbeddingProviderDown", "resolved"), + 90, + ) + circuit_firing_deliveries = sum( + 1 for event in environment.webhook_events() + for alert in event["payload"].get("alerts", []) + if alert.get("labels", {}).get("alertname") + == "DocGridEmbeddingProviderCircuitOpen" + and alert.get("status") == "firing" + ) + if circuit_firing_deliveries != 0: + raise AssertionError("The inhibited Circuit warning reached the webhook receiver") + + final_job = environment.psql( + "SELECT status || '|' || retry_count || '|' || max_retry_count " + f"FROM embedding_jobs WHERE id={job_id}" + ).split("|") + firing_received_at = datetime.fromisoformat(provider_down_delivery["receivedAt"]) + resolved_received_at = datetime.fromisoformat(provider_down_resolved["receivedAt"]) + result = base_result("circuit-recovery") + result["conditions"] = { + "providerFailureMode": "docker-pause", + "circuitFailureThreshold": 3, + "circuitOpenDuration": "30s", + "retryJitterRatio": 0, + "jobMaxRetryCount": 10, + "failedProbeRetryFreeze": "10m", + "scrapeInterval": "15s", + "evaluationInterval": "15s", + "circuitRuleFor": "1m", + "criticalGroupWait": "10s", + "warningGroupWait": "30s", + "testGroupInterval": "30s", + "productionGroupInterval": "5m", + } + result["timestamps"] = { + "providerPausedAt": iso(provider_paused_at), + "providerDownConditionAt": iso(provider_down_condition_at), + "circuitOpenedAt": iso(circuit_opened_at), + "delayedRetryObservedAt": iso(delayed_retry_observed_at), + "failedProbeAt": iso(failed_probe_at), + "providerDownFiringAt": iso(provider_down_firing_at), + "providerDownWebhookAt": iso(firing_received_at), + "circuitAlertPendingAt": iso(circuit_alert_pending_at), + "circuitAlertFiringAt": iso(circuit_alert_firing_at), + "circuitSuppressedAt": iso(circuit_suppressed_at), + "recoveryStartedAt": iso(recovery_started_at), + "providerReadyAt": iso(provider_ready_at), + "successfulProbeAt": iso(successful_probe_at), + "jobIndexedAt": iso(job_indexed_at), + "alertsResolvedAt": iso(alerts_resolved_at), + "providerDownResolvedWebhookAt": iso(resolved_received_at), + } + result["measurements"] = { + "pauseToProviderDownConditionSeconds": round( + (provider_down_condition_at - provider_paused_at).total_seconds(), 3 + ), + "pauseToCircuitOpenSeconds": round( + (circuit_opened_at - provider_paused_at).total_seconds(), 3 + ), + "pauseToFailedProbeSeconds": round( + (failed_probe_at - provider_paused_at).total_seconds(), 3 + ), + "failedProbeToCircuitFiringSeconds": round( + (circuit_alert_firing_at - failed_probe_at).total_seconds(), 3 + ), + "recoveryToProviderReadySeconds": round( + (provider_ready_at - recovery_started_at).total_seconds(), 3 + ), + "providerReadyToSuccessfulProbeSeconds": round( + (successful_probe_at - provider_ready_at).total_seconds(), 3 + ), + "recoveryToIndexedSeconds": round( + (job_indexed_at - recovery_started_at).total_seconds(), 3 + ), + "recoveryToAllPrometheusAlertsResolvedSeconds": round( + (alerts_resolved_at - recovery_started_at).total_seconds(), 3 + ), + "recoveryToProviderResolvedWebhookSeconds": round( + (resolved_received_at - recovery_started_at).total_seconds(), 3 + ), + "circuitWarningSuppressed": bool(inhibited_circuit_alert), + "circuitWarningFiringWebhookDeliveries": circuit_firing_deliveries, + "storedEmbeddings": embedding_count, + "finalJobStatus": final_job[0], + "finalRetryCount": int(final_job[1]), + "maxRetryCount": int(final_job[2]), + } + result["metricSnapshots"] = { + "circuitOpen": circuit_open_snapshot, + "delayedRetry": delayed_retry_snapshot, + "failedProbe": failed_probe_snapshot, + "successfulProbe": successful_probe_snapshot, + } + return result + finally: + if provider_paused: + environment.compose("unpause", "embedding-server", check=False) + environment.close() + + def run_queue_recovery(output_dir, jar_path): """Create a real queued document, observe production alerts, then recover it with a Worker.""" environment = DrillEnvironment("queue-recovery", output_dir) @@ -926,7 +1296,13 @@ def parse_arguments(): parser = argparse.ArgumentParser(description=__doc__) parser.add_argument( "scenario", - choices=["scrape-load", "queue-recovery", "provider-outage", "all"], + choices=[ + "scrape-load", + "queue-recovery", + "provider-outage", + "circuit-recovery", + "all", + ], ) parser.add_argument( "--output-dir", @@ -943,11 +1319,12 @@ def main(): output_dir = arguments.output_dir.resolve() output_dir.mkdir(parents=True, exist_ok=True) scenarios = ( - ["scrape-load", "queue-recovery", "provider-outage"] + ["scrape-load", "queue-recovery", "provider-outage", "circuit-recovery"] if arguments.scenario == "all" else [arguments.scenario] ) jar_path = build_backend() if any( - scenario in {"scrape-load", "queue-recovery"} for scenario in scenarios + scenario in {"scrape-load", "queue-recovery", "circuit-recovery"} + for scenario in scenarios ) else None results = [] try: @@ -956,6 +1333,8 @@ def main(): result = run_scrape_load(output_dir, jar_path) elif scenario == "queue-recovery": result = run_queue_recovery(output_dir, jar_path) + elif scenario == "circuit-recovery": + result = run_circuit_recovery(output_dir, jar_path) else: result = run_provider_outage(output_dir) write_result(output_dir, result) From 8149ee2c6555a900783170a2238480c5c01b9afc Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=EA=B9=80=EA=B8=B0=EB=AF=BC?= Date: Sun, 4 Oct 2026 01:30:28 +0900 Subject: [PATCH 3/9] test: verify circuit drill metric evidence --- monitoring/drills/test_run_drill.py | 63 +++++++++++++++++++++++++++++ 1 file changed, 63 insertions(+) create mode 100644 monitoring/drills/test_run_drill.py diff --git a/monitoring/drills/test_run_drill.py b/monitoring/drills/test_run_drill.py new file mode 100644 index 00000000..1c641aa9 --- /dev/null +++ b/monitoring/drills/test_run_drill.py @@ -0,0 +1,63 @@ +"""Unit tests for deterministic observability drill parsing and negative assertions.""" + +import importlib.util +import unittest +from pathlib import Path +from unittest.mock import patch + + +MODULE_PATH = Path(__file__).with_name("run_drill.py") +SPEC = importlib.util.spec_from_file_location("docgrid_run_drill", MODULE_PATH) +run_drill = importlib.util.module_from_spec(SPEC) +SPEC.loader.exec_module(run_drill) + + +class CircuitDrillHelpersTest(unittest.TestCase): + """Verify the Circuit scenario reads exact labels and enforces absent-event windows.""" + + def test_circuit_metric_snapshot_reads_all_required_series(self): + metrics = """ +docgrid_embedding_provider_circuit_open 1.0 +docgrid_embedding_provider_circuit_probe_failed 1.0 +docgrid_embedding_provider_circuit_transitions_total{state="open"} 2.0 +docgrid_embedding_provider_circuit_transitions_total{state="half_open"} 1.0 +docgrid_embedding_provider_circuit_transitions_total{state="closed"} 0.0 +docgrid_embedding_provider_circuit_probe_total{outcome="failed"} 1.0 +docgrid_embedding_provider_circuit_probe_total{outcome="success"} 0.0 +docgrid_embedding_delayed_retry_jobs 1.0 +""".strip() + + with patch.object(run_drill, "fetch_metrics", return_value=metrics): + snapshot = run_drill.circuit_metric_snapshot({"metricsUrl": "unused"}) + + self.assertEqual({ + "open": 1.0, + "probeFailed": 1.0, + "openTransitions": 2.0, + "halfOpenTransitions": 1.0, + "closedTransitions": 0.0, + "failedProbes": 1.0, + "successfulProbes": 0.0, + "delayedRetryJobs": 1.0, + }, snapshot) + + def test_assert_absent_for_returns_after_clean_window(self): + run_drill.assert_absent_for( + "clean webhook window", + lambda: False, + duration_seconds=0.005, + interval_seconds=0.001, + ) + + def test_assert_absent_for_fails_when_event_appears(self): + with self.assertRaisesRegex(AssertionError, "Unexpected event"): + run_drill.assert_absent_for( + "unexpected webhook", + lambda: True, + duration_seconds=1, + interval_seconds=0.001, + ) + + +if __name__ == "__main__": + unittest.main() From 4e0cb92763210d784a0a3c9eee4d1aeab58bf7c1 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=EA=B9=80=EA=B8=B0=EB=AF=BC?= Date: Sun, 4 Oct 2026 01:42:53 +0900 Subject: [PATCH 4/9] test: isolate circuit outage with stable provider port --- monitoring/drills/docker-compose.yml | 2 +- monitoring/drills/run_drill.py | 76 +++++++++++++++------------- 2 files changed, 41 insertions(+), 37 deletions(-) diff --git a/monitoring/drills/docker-compose.yml b/monitoring/drills/docker-compose.yml index 84dbfc0d..8d3b2f96 100644 --- a/monitoring/drills/docker-compose.yml +++ b/monitoring/drills/docker-compose.yml @@ -42,7 +42,7 @@ services: EMBEDDING_PROVIDER_MAX_QUEUE_SIZE: 1 EMBEDDING_PROVIDER_QUEUE_WAIT_TIMEOUT_SECONDS: 15 ports: - - "127.0.0.1::8000" + - "127.0.0.1:${DRILL_EMBEDDING_PORT:-0}:8000" volumes: - huggingface-cache:/root/.cache/huggingface healthcheck: diff --git a/monitoring/drills/run_drill.py b/monitoring/drills/run_drill.py index a9693638..7bb2c9dd 100755 --- a/monitoring/drills/run_drill.py +++ b/monitoring/drills/run_drill.py @@ -153,6 +153,8 @@ def __init__(self, scenario, output_dir): self.project_name = f"docgrid-drill-{scenario.replace('_', '-')}-{os.getpid()}" self.compose_env = os.environ.copy() self.compose_env["DRILL_TMP_DIR"] = str(self.temp_dir) + # Keep the Provider address stable across stop/start so the real Backend can recover in place. + self.compose_env["DRILL_EMBEDDING_PORT"] = str(free_port()) self.backend_processes = [] self.backend_logs = [] self.postgres_port = None @@ -766,7 +768,6 @@ def run_provider_outage(output_dir): def run_circuit_recovery(output_dir, jar_path): """Drive one real Job through Circuit protection, failed Probe, and successful recovery.""" environment = DrillEnvironment("circuit-recovery", output_dir) - provider_paused = False try: # 1. Create a real Job while the Provider is healthy, but keep all Workers disabled. environment.start_core(include_provider=True) @@ -802,11 +803,10 @@ def run_circuit_recovery(output_dir, jar_path): f"WHERE id={job_id}" ) - # 2. Pause the existing container so Backend and Prometheus see an outage without changing its port. - print("Pausing the real Embedding Provider container...", flush=True) - provider_paused_at = utc_now() - environment.compose("pause", "embedding-server", capture=False) - provider_paused = True + # 2. Stop the existing container so clients fail cleanly while its configured port stays stable. + print("Stopping the real Embedding Provider container...", flush=True) + provider_stopped_at = utc_now() + environment.compose("stop", "embedding-server", capture=False) worker = environment.start_backend( jar_path, "circuit-worker", @@ -856,25 +856,30 @@ def run_circuit_recovery(output_dir, jar_path): delayed_retry_observed_at = utc_now() # 4. Wait for the real failed Probe and freeze only this Job while the production for-clause matures. + def freeze_after_failed_probe(): + """Atomically move the target Retry beyond the alert window after its failed Probe.""" + snapshot = circuit_metric_snapshot(worker) + if not ( + snapshot["failedProbes"] >= 1 + and snapshot["probeFailed"] == 1 + and snapshot["openTransitions"] >= 2 + ): + return None + updated = environment.psql( + "UPDATE embedding_jobs " + "SET next_retry_at=CURRENT_TIMESTAMP + INTERVAL '10 minutes', " + "updated_at=CURRENT_TIMESTAMP " + f"WHERE id={job_id} AND status='PENDING' RETURNING id" + ) + return snapshot if str(job_id) in updated.splitlines() else None + failed_probe_snapshot = wait_for( - "a failed Half-open Probe and Retry persistence", - lambda: ( - snapshot if ( - (snapshot := circuit_metric_snapshot(worker))["failedProbes"] >= 1 - and snapshot["probeFailed"] == 1 - and snapshot["openTransitions"] >= 2 - and environment.psql( - f"SELECT status FROM embedding_jobs WHERE id={job_id}" - ) == "PENDING" - ) else None - ), + "a failed Half-open Probe and atomic Retry freeze", + freeze_after_failed_probe, 120, + 0.2, ) failed_probe_at = utc_now() - environment.psql( - "UPDATE embedding_jobs SET next_retry_at=CURRENT_TIMESTAMP + INTERVAL '10 minutes', " - f"updated_at=CURRENT_TIMESTAMP WHERE id={job_id} AND status='PENDING'" - ) wait_for( "the frozen Job to remain visible as delayed Retry", lambda: circuit_metric_snapshot(worker)["delayedRetryJobs"] >= 1, @@ -931,13 +936,14 @@ def run_circuit_recovery(output_dir, jar_path): 35, ) - # 6. Resume the same Provider, release the frozen Retry, and require a successful Probe closure. - print("Unpausing the real Embedding Provider container...", flush=True) + # 6. Restart the same Provider, release the frozen Retry, and require a successful Probe closure. + print("Restarting the real Embedding Provider container...", flush=True) recovery_started_at = utc_now() - environment.compose("unpause", "embedding-server", capture=False) - provider_paused = False + environment.compose("start", "embedding-server", capture=False) + if environment.service_port("embedding-server", 8000) != environment.embedding_port: + raise AssertionError("Embedding Provider host port changed across stop/start") wait_for( - "Embedding Provider readiness after unpause", + "Embedding Provider readiness after restart", lambda: request( f"http://127.0.0.1:{environment.embedding_port}/health/ready", timeout=5, @@ -1016,7 +1022,7 @@ def run_circuit_recovery(output_dir, jar_path): resolved_received_at = datetime.fromisoformat(provider_down_resolved["receivedAt"]) result = base_result("circuit-recovery") result["conditions"] = { - "providerFailureMode": "docker-pause", + "providerFailureMode": "docker-stop", "circuitFailureThreshold": 3, "circuitOpenDuration": "30s", "retryJitterRatio": 0, @@ -1031,7 +1037,7 @@ def run_circuit_recovery(output_dir, jar_path): "productionGroupInterval": "5m", } result["timestamps"] = { - "providerPausedAt": iso(provider_paused_at), + "providerStoppedAt": iso(provider_stopped_at), "providerDownConditionAt": iso(provider_down_condition_at), "circuitOpenedAt": iso(circuit_opened_at), "delayedRetryObservedAt": iso(delayed_retry_observed_at), @@ -1049,14 +1055,14 @@ def run_circuit_recovery(output_dir, jar_path): "providerDownResolvedWebhookAt": iso(resolved_received_at), } result["measurements"] = { - "pauseToProviderDownConditionSeconds": round( - (provider_down_condition_at - provider_paused_at).total_seconds(), 3 + "stopToProviderDownConditionSeconds": round( + (provider_down_condition_at - provider_stopped_at).total_seconds(), 3 ), - "pauseToCircuitOpenSeconds": round( - (circuit_opened_at - provider_paused_at).total_seconds(), 3 + "stopToCircuitOpenSeconds": round( + (circuit_opened_at - provider_stopped_at).total_seconds(), 3 ), - "pauseToFailedProbeSeconds": round( - (failed_probe_at - provider_paused_at).total_seconds(), 3 + "stopToFailedProbeSeconds": round( + (failed_probe_at - provider_stopped_at).total_seconds(), 3 ), "failedProbeToCircuitFiringSeconds": round( (circuit_alert_firing_at - failed_probe_at).total_seconds(), 3 @@ -1091,8 +1097,6 @@ def run_circuit_recovery(output_dir, jar_path): } return result finally: - if provider_paused: - environment.compose("unpause", "embedding-server", check=False) environment.close() From 32ccc58434e24b5b041fbad67119355ab82f7a3b Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=EA=B9=80=EA=B8=B0=EB=AF=BC?= Date: Sun, 4 Oct 2026 01:53:27 +0900 Subject: [PATCH 5/9] fix: send embedding requests as json --- .../docgrid/domain/embedding/client/EmbeddingClient.java | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/backend/src/main/java/com/opensource/docgrid/domain/embedding/client/EmbeddingClient.java b/backend/src/main/java/com/opensource/docgrid/domain/embedding/client/EmbeddingClient.java index e9bf4d2e..c8a5fa14 100644 --- a/backend/src/main/java/com/opensource/docgrid/domain/embedding/client/EmbeddingClient.java +++ b/backend/src/main/java/com/opensource/docgrid/domain/embedding/client/EmbeddingClient.java @@ -8,6 +8,7 @@ import org.springframework.beans.factory.annotation.Qualifier; import org.springframework.http.HttpHeaders; +import org.springframework.http.MediaType; import org.springframework.stereotype.Component; import org.springframework.util.StringUtils; import org.springframework.web.client.ResourceAccessException; @@ -68,6 +69,8 @@ public float[] embed(String text) { try { response = queryRestClient.post() .uri("/embed") + // JSON을 명시해 XML Converter가 Provider 요청 DTO를 먼저 선택하지 못하게 한다. + .contentType(MediaType.APPLICATION_JSON) .body(new EmbedRequest(text)) .retrieve() .body(EmbedServerResponse.class); @@ -107,6 +110,8 @@ public EmbedBatchServerResponse embedBatch(List texts, int batchSize) { try { response = documentRestClient.post() .uri("/embed/batch") + // FastAPI Batch 계약은 JSON 객체이므로 classpath의 XML 지원 여부와 무관하게 고정한다. + .contentType(MediaType.APPLICATION_JSON) .body(new EmbedBatchRequest(texts, batchSize)) .retrieve() .body(EmbedBatchServerResponse.class); From 3176c466b098e0192cec153205e1b21427a0ab16 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=EA=B9=80=EA=B8=B0=EB=AF=BC?= Date: Sun, 4 Oct 2026 01:53:27 +0900 Subject: [PATCH 6/9] test: verify embedding request content type --- .../docgrid/domain/embedding/client/EmbeddingClientTest.java | 3 +++ 1 file changed, 3 insertions(+) diff --git a/backend/src/test/java/com/opensource/docgrid/domain/embedding/client/EmbeddingClientTest.java b/backend/src/test/java/com/opensource/docgrid/domain/embedding/client/EmbeddingClientTest.java index e2ad44b9..78e68b00 100644 --- a/backend/src/test/java/com/opensource/docgrid/domain/embedding/client/EmbeddingClientTest.java +++ b/backend/src/test/java/com/opensource/docgrid/domain/embedding/client/EmbeddingClientTest.java @@ -13,6 +13,7 @@ import java.util.List; import org.springframework.http.HttpHeaders; +import org.springframework.http.MediaType; import org.junit.jupiter.api.BeforeEach; import org.junit.jupiter.api.DisplayName; import org.junit.jupiter.api.Test; @@ -78,6 +79,7 @@ void embed_success() { assertThat(result).containsExactly(vector); verify(queryRestClient).post(); + verify(requestBodyUriSpec).contentType(MediaType.APPLICATION_JSON); verify(documentRestClient, never()).post(); verify(circuitBreaker).recordSuccess(permission); } @@ -247,6 +249,7 @@ void embedBatch_returnsValidatedResponse() { .extracting(EmbedBatchItemResponse::index) .containsExactly(0, 1); verify(documentRestClient).post(); + verify(requestBodyUriSpec).contentType(MediaType.APPLICATION_JSON); verify(queryRestClient, never()).post(); } From 00c1a8b82fa0a4fcc682c1d5562e2575d390d91b Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=EA=B9=80=EA=B8=B0=EB=AF=BC?= Date: Sun, 4 Oct 2026 01:58:32 +0900 Subject: [PATCH 7/9] test: redact internal webhook evidence urls --- monitoring/drills/test_webhook_receiver.py | 46 ++++++++++++++++++++++ monitoring/drills/webhook_receiver.py | 20 +++++++++- 2 files changed, 65 insertions(+), 1 deletion(-) create mode 100644 monitoring/drills/test_webhook_receiver.py diff --git a/monitoring/drills/test_webhook_receiver.py b/monitoring/drills/test_webhook_receiver.py new file mode 100644 index 00000000..0eb9b14e --- /dev/null +++ b/monitoring/drills/test_webhook_receiver.py @@ -0,0 +1,46 @@ +"""Unit tests for pre-recording sanitization of local Alertmanager webhook evidence.""" + +import importlib.util +import os +import unittest +from pathlib import Path +from unittest.mock import patch + + +MODULE_PATH = Path(__file__).with_name("webhook_receiver.py") +SPEC = importlib.util.spec_from_file_location("docgrid_webhook_receiver", MODULE_PATH) +with patch.dict(os.environ, {"EVENT_LOG": "/tmp/docgrid-webhook-test.jsonl"}): + webhook_receiver = importlib.util.module_from_spec(SPEC) + SPEC.loader.exec_module(webhook_receiver) + + +class WebhookEvidenceSanitizationTest(unittest.TestCase): + """Verify internal callback addresses never reach the persisted evidence payload.""" + + def test_sanitize_payload_replaces_internal_urls_at_every_depth(self): + payload = { + "externalURL": "http://alertmanager-container:9093", + "alerts": [{ + "generatorURL": "http://prometheus-container:9090/graph", + "labels": {"alertname": "EmbeddingProviderDown"}, + }], + } + + sanitized = webhook_receiver.sanitize_payload(payload) + + self.assertEqual( + webhook_receiver.INTERNAL_URL_OMITTED, + sanitized["externalURL"], + ) + self.assertEqual( + webhook_receiver.INTERNAL_URL_OMITTED, + sanitized["alerts"][0]["generatorURL"], + ) + self.assertEqual( + "EmbeddingProviderDown", + sanitized["alerts"][0]["labels"]["alertname"], + ) + + +if __name__ == "__main__": + unittest.main() diff --git a/monitoring/drills/webhook_receiver.py b/monitoring/drills/webhook_receiver.py index 48693360..2bda860a 100644 --- a/monitoring/drills/webhook_receiver.py +++ b/monitoring/drills/webhook_receiver.py @@ -8,6 +8,23 @@ EVENT_LOG = Path(os.environ["EVENT_LOG"]) +INTERNAL_URL_OMITTED = "[internal URL omitted]" + + +def sanitize_payload(value): + """Remove drill-internal Prometheus and Alertmanager addresses before evidence is recorded.""" + if isinstance(value, dict): + return { + key: ( + INTERNAL_URL_OMITTED + if key in {"generatorURL", "externalURL"} + else sanitize_payload(item) + ) + for key, item in value.items() + } + if isinstance(value, list): + return [sanitize_payload(item) for item in value] + return value class WebhookHandler(BaseHTTPRequestHandler): @@ -26,7 +43,8 @@ def do_POST(self): return content_length = int(self.headers.get("Content-Length", "0")) - payload = json.loads(self.rfile.read(content_length)) + # Internal container identifiers are not needed for lifecycle assertions or public evidence. + payload = sanitize_payload(json.loads(self.rfile.read(content_length))) event = { "receivedAt": datetime.now(timezone.utc).isoformat(), "payload": payload, From 310965b929cff4e682d029ff1bb836379c1fe3ae Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=EA=B9=80=EA=B8=B0=EB=AF=BC?= Date: Sun, 4 Oct 2026 02:03:41 +0900 Subject: [PATCH 8/9] test: capture fully recovered circuit metrics --- monitoring/drills/run_drill.py | 14 ++++++++++++++ 1 file changed, 14 insertions(+) diff --git a/monitoring/drills/run_drill.py b/monitoring/drills/run_drill.py index 7bb2c9dd..ce18a5d3 100755 --- a/monitoring/drills/run_drill.py +++ b/monitoring/drills/run_drill.py @@ -988,6 +988,19 @@ def freeze_after_failed_probe(): )) if embedding_count <= 0: raise AssertionError("Recovered Job reached INDEXED without stored embeddings") + recovered_snapshot = wait_for( + "the recovered metric snapshot to clear delayed Retry state", + lambda: ( + snapshot if ( + (snapshot := circuit_metric_snapshot(worker))["open"] == 0 + and snapshot["probeFailed"] == 0 + and snapshot["successfulProbes"] >= 1 + and snapshot["closedTransitions"] >= 1 + and snapshot["delayedRetryJobs"] == 0 + ) else None + ), + 30, + ) # 7. Require both Prometheus alerts to clear and only the root-cause lifecycle to be delivered. alerts_resolved_at = wait_for( @@ -1094,6 +1107,7 @@ def freeze_after_failed_probe(): "delayedRetry": delayed_retry_snapshot, "failedProbe": failed_probe_snapshot, "successfulProbe": successful_probe_snapshot, + "recovered": recovered_snapshot, } return result finally: From 8f722ea6a99580aa5937294b72db7a36bbff9bf9 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=EA=B9=80=EA=B8=B0=EB=AF=BC?= Date: Sun, 4 Oct 2026 02:14:24 +0900 Subject: [PATCH 9/9] docs: record embedding circuit recovery drill --- .../issue-413/circuit-recovery-webhooks.jsonl | 2 + .../evidence/issue-413/circuit-recovery.json | 117 ++++++ .../gimin-#413-embedding-circuit-recovery.md | 370 ++++++++++++++++++ monitoring/drills/README.md | 28 +- 4 files changed, 515 insertions(+), 2 deletions(-) create mode 100644 docs/test-results/evidence/issue-413/circuit-recovery-webhooks.jsonl create mode 100644 docs/test-results/evidence/issue-413/circuit-recovery.json create mode 100644 docs/test-results/gimin-#413-embedding-circuit-recovery.md diff --git a/docs/test-results/evidence/issue-413/circuit-recovery-webhooks.jsonl b/docs/test-results/evidence/issue-413/circuit-recovery-webhooks.jsonl new file mode 100644 index 00000000..00ced732 --- /dev/null +++ b/docs/test-results/evidence/issue-413/circuit-recovery-webhooks.jsonl @@ -0,0 +1,2 @@ +{"receivedAt":"2026-10-03T17:05:47.781605+00:00","payload":{"receiver":"local-webhook","status":"firing","alerts":[{"status":"firing","labels":{"alertname":"EmbeddingProviderDown","cluster":"docgrid-drill","environment":"local-drill","instance":"embedding-server:8000","job":"embedding-provider","service":"embedding-provider","severity":"critical"},"annotations":{"description":"Prometheus has failed to scrape the Embedding Provider for one minute.","summary":"Embedding Provider metric endpoint is unavailable"},"startsAt":"2026-10-03T17:05:37.76Z","endsAt":"0001-01-01T00:00:00Z","generatorURL":"[internal URL omitted]","fingerprint":"dcc4408eec1a5b0a"}],"notification_reason":"first notification","groupLabels":{"alertname":"EmbeddingProviderDown","cluster":"docgrid-drill","environment":"local-drill","service":"embedding-provider","severity":"critical"},"commonLabels":{"alertname":"EmbeddingProviderDown","cluster":"docgrid-drill","environment":"local-drill","instance":"embedding-server:8000","job":"embedding-provider","service":"embedding-provider","severity":"critical"},"commonAnnotations":{"description":"Prometheus has failed to scrape the Embedding Provider for one minute.","summary":"Embedding Provider metric endpoint is unavailable"},"externalURL":"[internal URL omitted]","version":"4","groupKey":"{}/{severity=\"critical\"}:{alertname=\"EmbeddingProviderDown\", cluster=\"docgrid-drill\", environment=\"local-drill\", service=\"embedding-provider\", severity=\"critical\"}","truncatedAlerts":0}} +{"receivedAt":"2026-10-03T17:08:17.793669+00:00","payload":{"receiver":"local-webhook","status":"resolved","alerts":[{"status":"resolved","labels":{"alertname":"EmbeddingProviderDown","cluster":"docgrid-drill","environment":"local-drill","instance":"embedding-server:8000","job":"embedding-provider","service":"embedding-provider","severity":"critical"},"annotations":{"description":"Prometheus has failed to scrape the Embedding Provider for one minute.","summary":"Embedding Provider metric endpoint is unavailable"},"startsAt":"2026-10-03T17:05:37.76Z","endsAt":"2026-10-03T17:07:52.76Z","generatorURL":"[internal URL omitted]","fingerprint":"dcc4408eec1a5b0a"}],"notification_reason":"all alerts resolved","groupLabels":{"alertname":"EmbeddingProviderDown","cluster":"docgrid-drill","environment":"local-drill","service":"embedding-provider","severity":"critical"},"commonLabels":{"alertname":"EmbeddingProviderDown","cluster":"docgrid-drill","environment":"local-drill","instance":"embedding-server:8000","job":"embedding-provider","service":"embedding-provider","severity":"critical"},"commonAnnotations":{"description":"Prometheus has failed to scrape the Embedding Provider for one minute.","summary":"Embedding Provider metric endpoint is unavailable"},"externalURL":"[internal URL omitted]","version":"4","groupKey":"{}/{severity=\"critical\"}:{alertname=\"EmbeddingProviderDown\", cluster=\"docgrid-drill\", environment=\"local-drill\", service=\"embedding-provider\", severity=\"critical\"}","truncatedAlerts":0}} diff --git a/docs/test-results/evidence/issue-413/circuit-recovery.json b/docs/test-results/evidence/issue-413/circuit-recovery.json new file mode 100644 index 00000000..dae4a1f3 --- /dev/null +++ b/docs/test-results/evidence/issue-413/circuit-recovery.json @@ -0,0 +1,117 @@ +{ + "scenario": "circuit-recovery", + "status": "PASS", + "measuredAt": "2026-10-03T17:08:18.145282+00:00", + "gitCommit": "310965b929cff4e682d029ff1bb836379c1fe3ae", + "host": { + "system": "Darwin", + "machine": "arm64" + }, + "images": { + "postgres": "pgvector/pgvector:0.8.1-pg17", + "prometheus": "prom/prometheus:v3.5.5", + "alertmanager": "quay.io/prometheus/alertmanager:v0.33.1" + }, + "conditions": { + "providerFailureMode": "docker-stop", + "circuitFailureThreshold": 3, + "circuitOpenDuration": "30s", + "retryJitterRatio": 0, + "jobMaxRetryCount": 10, + "failedProbeRetryFreeze": "10m", + "scrapeInterval": "15s", + "evaluationInterval": "15s", + "circuitRuleFor": "1m", + "criticalGroupWait": "10s", + "warningGroupWait": "30s", + "testGroupInterval": "30s", + "productionGroupInterval": "5m" + }, + "timestamps": { + "providerStoppedAt": "2026-10-03T17:04:13.035922+00:00", + "providerDownConditionAt": "2026-10-03T17:04:32.110422+00:00", + "circuitOpenedAt": "2026-10-03T17:04:51.405977+00:00", + "delayedRetryObservedAt": "2026-10-03T17:04:51.628918+00:00", + "failedProbeAt": "2026-10-03T17:05:31.612993+00:00", + "providerDownFiringAt": "2026-10-03T17:05:39.643678+00:00", + "providerDownWebhookAt": "2026-10-03T17:05:47.781605+00:00", + "circuitAlertPendingAt": "2026-10-03T17:05:48.687839+00:00", + "circuitAlertFiringAt": "2026-10-03T17:06:46.911840+00:00", + "circuitSuppressedAt": "2026-10-03T17:06:46.914042+00:00", + "recoveryStartedAt": "2026-10-03T17:07:22.044228+00:00", + "providerReadyAt": "2026-10-03T17:07:26.326082+00:00", + "successfulProbeAt": "2026-10-03T17:07:30.473955+00:00", + "jobIndexedAt": "2026-10-03T17:07:30.553405+00:00", + "alertsResolvedAt": "2026-10-03T17:07:52.763847+00:00", + "providerDownResolvedWebhookAt": "2026-10-03T17:08:17.793669+00:00" + }, + "measurements": { + "stopToProviderDownConditionSeconds": 19.075, + "stopToCircuitOpenSeconds": 38.37, + "stopToFailedProbeSeconds": 78.577, + "failedProbeToCircuitFiringSeconds": 75.299, + "recoveryToProviderReadySeconds": 4.282, + "providerReadyToSuccessfulProbeSeconds": 4.148, + "recoveryToIndexedSeconds": 8.509, + "recoveryToAllPrometheusAlertsResolvedSeconds": 30.72, + "recoveryToProviderResolvedWebhookSeconds": 55.749, + "circuitWarningSuppressed": true, + "circuitWarningFiringWebhookDeliveries": 0, + "storedEmbeddings": 1, + "finalJobStatus": "INDEXED", + "finalRetryCount": 5, + "maxRetryCount": 10 + }, + "metricSnapshots": { + "circuitOpen": { + "open": 1.0, + "probeFailed": 0.0, + "openTransitions": 1.0, + "halfOpenTransitions": 0.0, + "closedTransitions": 0.0, + "failedProbes": 0.0, + "successfulProbes": 0.0, + "delayedRetryJobs": 1.0 + }, + "delayedRetry": { + "open": 1.0, + "probeFailed": 0.0, + "openTransitions": 1.0, + "halfOpenTransitions": 0.0, + "closedTransitions": 0.0, + "failedProbes": 0.0, + "successfulProbes": 0.0, + "delayedRetryJobs": 1.0 + }, + "failedProbe": { + "open": 1.0, + "probeFailed": 1.0, + "openTransitions": 2.0, + "halfOpenTransitions": 1.0, + "closedTransitions": 0.0, + "failedProbes": 1.0, + "successfulProbes": 0.0, + "delayedRetryJobs": 1.0 + }, + "successfulProbe": { + "open": 0.0, + "probeFailed": 0.0, + "openTransitions": 2.0, + "halfOpenTransitions": 2.0, + "closedTransitions": 1.0, + "failedProbes": 1.0, + "successfulProbes": 1.0, + "delayedRetryJobs": 0.0 + }, + "recovered": { + "open": 0.0, + "probeFailed": 0.0, + "openTransitions": 2.0, + "halfOpenTransitions": 2.0, + "closedTransitions": 1.0, + "failedProbes": 1.0, + "successfulProbes": 1.0, + "delayedRetryJobs": 0.0 + } + } +} diff --git a/docs/test-results/gimin-#413-embedding-circuit-recovery.md b/docs/test-results/gimin-#413-embedding-circuit-recovery.md new file mode 100644 index 00000000..2ad8b3f5 --- /dev/null +++ b/docs/test-results/gimin-#413-embedding-circuit-recovery.md @@ -0,0 +1,370 @@ +# Embedding Circuit 장애·Probe 복구 경로 통합 검증 결과 + +## 1. 결론 + +2026-10-04(KST)에 커밋 `310965b929cff4e682d029ff1bb836379c1fe3ae`의 Drill로 실제 +Spring Backend, PostgreSQL, Valkey, BGE-M3, Prometheus, Alertmanager를 연결했다. Provider 중단부터 +Circuit OPEN, 실패 HALF_OPEN Probe, 경보 억제, Provider 재시작, 성공 Probe, Job `INDEXED`까지 +하나의 Job으로 검증했고 최종 결과는 PASS다. + +| 검증 항목 | 실측 결과 | 판정 | +|---|---:|---| +| Provider 중단 → Circuit OPEN | 38.370초 | PASS | +| Provider 중단 → 실패 Probe | 78.577초 | PASS | +| 실패 Probe → Circuit 경보 firing | 75.299초 | PASS | +| Circuit OPEN 전환 | 2회 | 최초 OPEN + 실패 Probe 재OPEN | +| HALF_OPEN 전환 | 2회 | 실패 Probe + 성공 Probe | +| 실패 / 성공 Probe | 1회 / 1회 | PASS | +| Circuit CLOSED 전환 | 1회 | PASS | +| Circuit warning firing webhook | 0건 | Provider critical에 의해 억제 | +| Provider 복구 → ready | 4.282초 | PASS | +| ready → 성공 Probe | 4.148초 | PASS | +| Provider 복구 → Job `INDEXED` | 8.509초 | PASS | +| 저장 Embedding | 1건 | PASS | +| 최종 delayed Retry | 0건 | PASS | +| Backend 전체 테스트 | 1,315개 중 1,313개 성공 | 실패·오류 0, 조건부 skip 2 | +| Monitoring E2E | firing 3초, resolved 2초 | PASS | + +최종 원본 증거는 다음 두 파일이다. + +- [`circuit-recovery.json`](evidence/issue-413/circuit-recovery.json) +- [`circuit-recovery-webhooks.jsonl`](evidence/issue-413/circuit-recovery-webhooks.jsonl) + +## 2. 검증한 전체 구조 + +### 그림 1. 실제 컴포넌트를 연결한 End-to-End 경로 + +```text +[로그인·문서 업로드 API] + │ + │ 실제 multipart TXT 업로드 + ▼ +[Observer Backend: Worker OFF] + │ + ├─ document_versions / document_chunks 저장 + └─ embedding_jobs(PENDING) 생성 + │ + ▼ + [PostgreSQL Queue] + │ claim + ▼ + [Worker Backend] ── acquirePermission() ──> [EmbeddingProviderCircuitBreaker] + │ │ + │ POST /embed/batch │ OPEN / HALF_OPEN / CLOSED + ▼ │ Metric 갱신 + [실제 BGE-M3 Provider] ▼ + │ [/actuator/prometheus] + │ /metrics │ + └───────────────────────────────────────────┤ scrape 15초 + ▼ + [Prometheus] + │ rule 평가 15초 + ▼ + [Alertmanager] + │ inhibition + ▼ + [격리 Webhook Receiver] + firing/resolved 증거 기록 +``` + +Mock Worker나 Mock Provider를 사용하지 않았다. Job은 실제 업로드 API로 만들었고, Worker는 실제 문서 +Chunk를 읽어 BGE-M3 Batch API를 호출했다. Prometheus와 Alertmanager도 운영 규칙 파일을 그대로 읽었다. + +## 3. 장애·복구 절차 + +### 그림 2. 장애 주입부터 최종 복구까지의 실행 순서 + +```text +1. Observer Backend 기동 + └─ Worker OFF + └─ 업로드 API → Job #1 PENDING + +2. Provider 중단(docker stop) + └─ 고정된 loopback host port는 유지 + +3. Worker Backend 기동 + ├─ attempt 1: 연결 실패 → retry_count 1 + ├─ attempt 2: 연결 실패 → retry_count 2 + └─ attempt 3: 연결 실패 → retry_count 3 → Circuit OPEN + +4. OPEN 30초 경과 + └─ attempt 4: HALF_OPEN Probe 권한 획득 + └─ 연결 실패 → failed Probe 1 → Circuit 재OPEN + +5. 경보 검증용 Job 동결 + └─ UPDATE ... WHERE status='PENDING' RETURNING id + └─ next_retry_at = now + 10분 + +6. 운영 경보 대기 + ├─ EmbeddingProviderDown = firing + └─ DocGridEmbeddingProviderCircuitOpen = firing + suppressed + +7. Provider 재시작 + ├─ 같은 host port로 ready + └─ Job next_retry_at = now + +8. 복구 + ├─ HALF_OPEN 성공 Probe 1 + ├─ Circuit CLOSED + ├─ Embedding 1건 저장 + ├─ Job INDEXED + └─ delayed Retry Gauge 0 +``` + +`pause/unpause`는 사용하지 않았다. pause 중 Java HTTP 요청이 timeout되어도 연결 자체는 남을 수 있고, +unpause 뒤 오래된 요청이 Provider에 도달할 수 있기 때문이다. 실행 시작 때 비어 있는 loopback port를 +하나 선택해 Compose에 고정하고, `stop/start`로 연결 거부와 정상 복구를 만들었다. + +## 4. Circuit 내부 상태와 Metric 검증 + +### 그림 3. 상태 전이와 관측값 + +```text + 연속 실패 3회 + [CLOSED] ─────────────────────────> [OPEN #1] + │ │ + │ open=0 │ open=1 + │ probe_failed=0 │ open transitions=1 + │ │ delayed retry=1 + │ │ + │ open-duration 30초 + │ │ + │ ▼ + │ [HALF_OPEN #1] + │ │ failed Probe + │ ▼ + │ [OPEN #2] + │ │ probe_failed=1 + │ │ failed probes=1 + │ │ open transitions=2 + │ │ + │ Provider 재시작 + │ │ + │ ▼ + │ [HALF_OPEN #2] + │ │ successful Probe + └──────────────────────────────────┘ + [CLOSED] + open=0 + probe_failed=0 + successful probes=1 + closed transitions=1 + delayed retry=0 +``` + +| Snapshot | open | probe failed | OPEN 전환 | HALF_OPEN 전환 | CLOSED 전환 | 실패 Probe | 성공 Probe | delayed Retry | +|---|---:|---:|---:|---:|---:|---:|---:|---:| +| 최초 OPEN | 1 | 0 | 1 | 0 | 0 | 0 | 0 | 1 | +| 실패 Probe | 1 | 1 | 2 | 1 | 0 | 1 | 0 | 1 | +| 성공 Probe | 0 | 0 | 2 | 2 | 1 | 1 | 1 | 0 | +| 최종 recovered | 0 | 0 | 2 | 2 | 1 | 1 | 1 | 0 | + +성공 Probe 직후에도 Job 완료 Transaction과 주기적 Gauge 갱신 사이에 짧은 시차가 생길 수 있다. 그래서 +Job `INDEXED`와 Embedding 저장을 확인한 뒤 `delayedRetryJobs=0`인 별도 `recovered` snapshot까지 +기다리도록 했다. + +## 5. Prometheus와 Alertmanager 검증 + +### 그림 4. Root-cause 경보와 파생 경보 억제 + +```text +[Provider stop] + │ + ├─ Prometheus up{job="embedding-provider"}=0 + │ └─ for: 1m + │ └─ EmbeddingProviderDown{severity="critical"}=firing + │ + └─ 실패 Probe + └─ circuit_open=1 AND probe_failed=1 + AND 최근 6분 failed Probe 존재 + └─ for: 1m + └─ DocGridEmbeddingProviderCircuitOpen + {severity="warning", + dependency="embedding-provider"}=firing + +[Alertmanager inhibition] + critical root cause와 warning의 cluster/environment/dependency 일치 + ├─ Provider critical → webhook firing 1건 + └─ Circuit warning → suppressed, firing webhook 0건 + +[Provider recovery] + ├─ up=1 + ├─ 성공 Probe → Circuit CLOSED + ├─ Prometheus 두 경보 해제 + └─ Provider critical → webhook resolved 1건 +``` + +| 경계 | 실측 | 해석 | +|---|---:|---| +| Provider stop → Prometheus `up=0` 관측 | 19.075초 | 15초 scrape 정렬 포함 | +| 실패 Probe → Circuit 경보 firing | 75.299초 | `for: 1m` + 15초 평가 정렬 | +| Circuit 경보 상태 | suppressed | root-cause inhibition 적용 | +| 35초 검증 창의 Circuit firing webhook | 0건 | warning 미전달 | +| Provider critical firing webhook | 1건 | 실제 Alertmanager 전달 | +| Provider critical resolved webhook | 1건 | 실제 Alertmanager 전달 | +| 복구 시작 → Prometheus 경보 모두 해제 | 30.720초 | scrape/evaluation 정렬 포함 | +| 복구 시작 → resolved webhook | 55.749초 | test `group_interval: 30s` 포함 | + +Webhook Receiver는 JSONL을 쓰기 전에 `generatorURL`과 `externalURL`의 Docker 내부 주소를 +`[internal URL omitted]`으로 치환한다. 경보 상태, 라벨, 시각, fingerprint는 유지한다. + +## 6. 통합 검증이 발견한 실제 HTTP 계약 버그 + +### 그림 5. 수정 전 XML 선택과 수정 후 JSON 고정 + +```text +수정 전 + +EmbeddingClient + .post() + .uri("/embed/batch") + .body(EmbedBatchRequest) + │ Content-Type 미지정 + ▼ +Spring MessageConverter 선택 + │ classpath의 XML Converter가 DTO 처리 + ▼ + + ... + 2 + + │ + ▼ +FastAPI EmbedBatchRequest(JSON object 기대) + └─ HTTP 422 model_attributes_type + └─ Job EMBEDDING_REQUEST_INVALID / terminal + +수정 후 + +EmbeddingClient + .contentType(MediaType.APPLICATION_JSON) + .body(EmbedBatchRequest) + │ + ▼ +{"texts":[...],"batch_size":2} + │ + ▼ +FastAPI 200 + └─ 성공 Probe → Circuit CLOSED + └─ Embedding 저장 → Job INDEXED +``` + +Python으로 같은 JSON을 직접 보냈을 때는 HTTP 200이었지만, 운영과 같은 JDK `HttpClient` + Spring +`RestClient` 조합은 422를 재현했다. FastAPI 응답은 요청 body가 XML 문자열이라고 명시했다. 단건 +`/embed`와 Batch `/embed/batch` 모두 JSON Content-Type을 명시했고, 단위 테스트에서 두 요청의 +`contentType(APPLICATION_JSON)` 호출을 검증했다. + +이 결함은 Circuit 상태 전이 자체의 오류는 아니다. Provider가 HTTP 응답을 했으므로 Circuit은 생존한 +Provider로 판단하고 정상적으로 CLOSED가 됐다. 그러나 422는 영구 요청 오류라 Job은 재시도 없이 +종결됐다. 통합 Drill이 성공 Probe 뒤의 실제 작업 완료까지 검사했기 때문에 이 계약 버그가 드러났다. + +## 7. 실행 조건 + +| 항목 | 값 | +|---|---| +| Host | Darwin arm64 로컬 개발 장비 | +| Spring Backend | 실제 `bootJar`, observer/worker 분리 | +| PostgreSQL | `pgvector/pgvector:0.8.1-pg17` | +| Valkey | `valkey/valkey:9.1-alpine` | +| Prometheus | `prom/prometheus:v3.5.5` | +| Alertmanager | `quay.io/prometheus/alertmanager:v0.33.1` | +| BGE-M3 | 저장소 `backend/embedding-server/Dockerfile` build | +| failure threshold | 3회 | +| Circuit open duration | 30초 | +| Retry Jitter | 0, 테스트 재현성용 | +| 대상 Job max retry | 10회, 실패·성공 Probe를 같은 Job으로 검증하기 위한 테스트 값 | +| 실패 Probe 뒤 Job 지연 | 10분, 경보 `for` 검증용 | +| Prometheus scrape / evaluation | 15초 / 15초, 운영값 | +| Circuit rule `for` | 1분, 운영값 | +| Alertmanager group wait | critical 10초 / warning 30초, 운영값 | +| Alertmanager group interval | 30초, 운영 5분 대신 테스트 시간 제한용 | + +실행 명령은 다음과 같다. + +```bash +./monitoring/drills/run.sh circuit-recovery \ + --output-dir <결과 디렉터리> +``` + +## 8. 실행·재시도 기록 + +| Run ID | 목적·실행 위치 | 명령·방법 | 관측 결과 | 판정과 해석 | +|---|---|---|---|---| +| `issue413-circuit-recovery-r1-20261004` | 최초 전체 Drill | 실제 Stack, Provider pause/unpause | 실패 Probe·경보 억제·성공 Probe 확인 뒤 Job 422 종결 | FAIL. 복구 후 실제 작업 완료 실패 발견 | +| `issue413-provider-contract-r1-20261004` | Provider 계약 격리 | Host Python 요청 | 샌드박스 network 권한에서 요청 전 실패 | 환경 준비 실패, 제품 판정 아님 | +| `issue413-provider-contract-r2-20261004` | Provider 자체 JSON 계약 | Provider 컨테이너 내부 Python 요청 | HTTP 200, 입력 2건·Embedding 2건 | PASS. Provider 계약 정상 | +| `issue413-harness-stop-start-check-r1-20261004` | stop/start Harness 정적 검증 | Python test + Compose render | 단위 3건 성공 뒤 검증 문자열 불일치 | 검증 명령 실패, YAML 표기 확인 후 수정 | +| `issue413-harness-stop-start-check-r2-20261004` | 정적 검증 재시도 | Python test + Compose render | 단위 3건, 고정 port render, diff check 통과 | PASS | +| `issue413-circuit-recovery-r2-20261004` | stop/start 전체 Drill | 실제 Stack | pause를 제거해도 Java Batch 요청 422 | FAIL. Harness가 아닌 Java 계약 결함으로 범위 축소 | +| `issue413-java-provider-contract-r1-20261004` | 운영 Java→Provider 계약 | JDK HttpClient + RestClient + 실제 Provider | HTTP 422, FastAPI가 XML body를 확인 | FAIL. Content-Type 누락 원인 확정 | +| `issue413-embedding-client-unit-r1-20261004` | 수정 후 단위 회귀 | Gradle targeted test | Gradle cache lock 권한에서 실행 전 실패 | 환경 준비 실패, 제품 판정 아님 | +| `issue413-embedding-client-unit-r2-20261004` | 단위 회귀 재시도 | `EmbeddingClientTest` | 전체 성공 | PASS | +| `issue413-java-provider-contract-r2-20261004` | 수정 후 실제 계약 | 운영 EmbeddingClient + 실제 Provider | HTTP 200, model·2개 결과 확인 | PASS | +| `issue413-circuit-recovery-r3-20261004` | JSON 수정 후 전체 Drill | 실제 Stack | Job INDEXED, 경보·복구 전부 통과 | PASS | +| `issue413-webhook-redaction-unit-r1-20261004` | 증거 사전 비식별화 | Python unittest | 기존 3건 + 신규 1건 성공 | PASS | +| `issue413-circuit-recovery-r4-20261004` | 비식별 증거 Run | 실제 Stack | 기능 PASS, 내부 URL 생략 확인 | PASS | +| `issue413-recovered-snapshot-unit-r1-20261004` | 최종 Gauge 증거 보완 | Python unittest | 4건 성공 | PASS | +| `issue413-circuit-recovery-r5-20261004` | 최종 증거 Run | 실제 Stack | 모든 성공 조건과 recovered snapshot 확인 | **PASS** | +| `issue413-backend-regression-r1-20261004` | Backend 전체 회귀 | 격리 PostgreSQL·Valkey + Gradle | 1,315개, 실패·오류 0, skip 2 | PASS. skip은 전용 다중 앱 환경 조건부 기존 테스트 | +| `issue413-monitoring-verify-e2e-r1-20261004` | Monitoring 설정·전달 E2E | `monitoring/verify.sh --e2e` | 규칙·설정·Compose 통과, firing 3초·resolved 2초 | PASS | + +각 Run은 목적별 로그를 덮어쓰지 않고 별도로 보존했다. 저장소에는 최종 PASS의 구조화 JSON과 +비식별 webhook만 커밋한다. 실패 Run은 원인을 이 문서에 남기되 로컬 경로, 내부 주소, 원문 noisy +로그는 공개 증거에 포함하지 않는다. + +## 9. 전체 회귀 검증 + +### Backend + +새 PostgreSQL·Valkey Compose project와 volume을 만들고 동적 loopback port를 Backend 테스트에 +주입했다. 캐시 영향을 없애기 위해 `--rerun-tasks`로 실행했다. + +```bash +./backend/gradlew -p backend test --no-daemon --rerun-tasks +``` + +| 항목 | 결과 | +|---|---:| +| JUnit suite | 220개 | +| 테스트 | 1,315개 | +| 성공 | 1,313개 | +| 실패 | 0개 | +| 오류 | 0개 | +| 건너뜀 | 2개 | +| JUnit suite 누적 시간 | 32.570초 | +| Gradle 전체 시간 | 1분 27초 | + +건너뛴 두 테스트는 전용 다중 앱 Redis/PostgreSQL 시험 환경이 없으면 `Assumption`으로 중단하도록 +설계된 `DashboardCrossNodeSignalRedisIntegrationTest`, `DashboardCrossNodeWebSocketIntegrationTest`다. +테스트 종료 뒤 전용 컨테이너, network, PostgreSQL volume이 모두 삭제됐음을 확인했다. + +### Monitoring + +```bash +./monitoring/verify.sh --e2e +``` + +다음을 확인했다. + +- Prometheus 설정과 rule file 3개, rule 20개 검증 +- Prometheus rule test 3개 통과 +- 기본·E2E·Drill·채널 예제를 포함한 Alertmanager 설정 9개 검증 +- Python AST, Shell 문법, Compose 렌더링 검증 +- 실제 Prometheus → Alertmanager → webhook firing 3초, resolved 2초 +- E2E 종료 뒤 컨테이너 0개 + +## 10. 해석 한계 + +- 수치는 단일 Darwin arm64 로컬 장비의 loopback 결과다. 운영 SLA가 아니라 같은 조건의 회귀 기준이다. +- Retry Jitter를 0으로 고정했으므로 운영의 분산 폭을 측정하지 않았다. 이 Drill은 Circuit 상태와 경보 + 시간 경계를 재현하는 데 목적이 있다. +- 대상 Job의 `max_retry_count=10`, 실패 Probe 뒤 10분 지연은 같은 Job으로 실패·성공 Probe와 1분 + 경보를 모두 검증하기 위한 테스트 조작이다. 애플리케이션 기본값을 바꾸지 않는다. +- Alertmanager `group_interval`은 테스트에서 30초다. 운영 5분의 resolved 최악 시간을 이 결과의 + 55.749초로 일반화할 수 없다. +- 실제 Slack·Discord 사업자의 응답은 검증하지 않았다. Alertmanager가 HTTP webhook을 보내고 격리 + Receiver가 firing/resolved를 받은 경계까지 검증했다. +- Provider critical 경보가 존재하는 동안 Circuit warning이 억제되는 경로를 검증했다. root-cause가 + 없는 독립 Circuit warning 전달은 Prometheus rule test와 Alertmanager routing E2E가 담당한다. + +closes #413 diff --git a/monitoring/drills/README.md b/monitoring/drills/README.md index ed33b8c4..5256a6fb 100644 --- a/monitoring/drills/README.md +++ b/monitoring/drills/README.md @@ -28,7 +28,10 @@ Compose project와 PostgreSQL volume을 만들고 종료할 때 삭제한다. # 실제 BGE-M3 중단·재시작과 종속 경보 억제 ./monitoring/drills/run.sh provider-outage -# 세 실험을 순서대로 각각 새 Stack에서 실행 +# 실제 Job으로 Circuit OPEN·실패 Probe·성공 Probe 복구 +./monitoring/drills/run.sh circuit-recovery + +# 네 실험을 순서대로 각각 새 Stack에서 실행 ./monitoring/drills/run.sh all ``` @@ -76,11 +79,28 @@ scrape callback이 DB를 호출하지 않았다는 의미이며, 주기적 갱 2. 실제 Provider 컨테이너를 중단하고 운영 `EmbeddingProviderDown` 규칙의 pending·firing을 기다린다. 3. 실제 root-cause 경보가 Alertmanager에 있는 동안 동일 배포의 종속 warning 하나를 API로 주입한다. 4. 종속 warning의 `suppressed` 상태와 firing webhook 0건을 함께 확인한다. -5. Provider를 재시작하고 새 동적 host 포트, readiness, Prometheus 해제와 resolved webhook을 확인한다. +5. Provider를 재시작하고 실행 시작 때 고정한 동적 host 포트, readiness, Prometheus 해제와 resolved + webhook을 확인한다. 종속 warning만 inhibition 경계를 분리하기 위해 직접 주입한다. Provider 중단·복구와 root-cause 경보는 실제 BGE-M3와 운영 Prometheus 규칙에서 발생한다. +### `circuit-recovery` + +1. Worker를 끈 실제 Backend의 로그인·multipart API로 TXT 문서와 PENDING Job을 만든다. +2. Provider 컨테이너를 중단하고 실제 Worker가 연속 세 번 실패해 Circuit을 여는지 확인한다. +3. 30초 뒤 HALF_OPEN Probe가 실패해 Circuit이 다시 열리고 failed Probe Metric이 증가하는지 확인한다. +4. 해당 Job만 10분 뒤로 원자적으로 미뤄 운영 Circuit 경보의 `for: 1m`을 유지한다. +5. Provider critical 경보와 Circuit warning이 모두 firing인지, Alertmanager가 warning을 suppressed로 + 유지하고 webhook 전송은 0건인지 확인한다. +6. 같은 Provider를 같은 host port로 재시작하고 Job을 즉시 실행 가능하게 만든다. +7. 성공 Probe가 Circuit을 닫고 Job `INDEXED`, Embedding 저장, delayed Retry 0건과 경보 해제를 + 모두 확인한다. + +Provider host port는 실행 시작 때 비어 있는 loopback port 하나로 고정한다. `pause/unpause`는 timeout된 +HTTP 연결이 재개 뒤 Provider로 밀려들 수 있으므로 장애 주입에는 `stop/start`를 사용한다. Webhook +receiver는 증거를 기록하기 전에 Prometheus·Alertmanager 내부 URL을 생략 표시로 치환한다. + ## 운영 설정과 다른 값 Prometheus의 scrape 15초, evaluation 15초와 모든 `for` 시간, Alertmanager의 warning 30초·critical @@ -88,5 +108,9 @@ Prometheus의 scrape 15초, evaluation 15초와 모든 `for` 시간, Alertmanage 운영 5분에서 30초로 줄인다. JSON에는 두 값을 모두 기록하므로 테스트 복구 시간과 운영 최악 시간을 구분할 수 있다. +Circuit 복구 실험은 재현 가능한 시간 경계를 위해 Retry Jitter를 0으로 설정한다. 기본 재시도 한도로는 +첫 실패 Probe에서 Job이 종결되므로 이 Job의 한도만 10회로 높이고, 경보 `for` 구간에는 이 Job만 10분 +뒤로 미룬다. 애플리케이션 기본 설정과 다른 값은 결과 JSON의 `conditions`에 기록한다. + 각 결과 JSON은 조건, UTC 시각, 구간별 초 단위 측정값과 검증된 최종 상태를 기록한다. 실패하면 같은 결과 디렉터리에 traceback과 Backend·Compose·webhook 로그를 남기며 Stack은 동일하게 정리한다.