fix: log which layer failed when registering on Solana

certified_builder/certificates_on_solana.py

@@ -1,11 +1,18 @@
 import logging
+import socket
+import ssl
+import time
+from urllib.parse import urlparse
+
 import httpx
 from retry import retry
 from pydantic import BaseModel
 from config import config
 
 logger = logging.getLogger(__name__)
 
+RESPONSE_BODY_LOG_LIMIT = 500
+
 
 class CertificatesOnSolanaException(Exception):
     """Custom exception for CertificatesOnSolana errors."""
@@ -15,10 +22,75 @@ def __init__(
         message: str = "Error registering certificate on Solana",
         details: str = "",
         cause: Exception = None,
+        stage: str = "unexpected",
     ):
-        super().__init__(message)
+        super().__init__(f"{message} [stage={stage}]: {details}")
         self.details = details
         self.cause = cause
+        self.stage = stage
+
+
+def _exception_chain(exc: BaseException) -> list:
+    """Return exc followed by its __cause__/__context__ chain.
+
+    Stops at context hidden with `raise ... from None`, as tracebacks do.
+    """
+    chain = []
+    while exc is not None and exc not in chain:
+        chain.append(exc)
+        if exc.__cause__ is not None:
+            exc = exc.__cause__
+        elif exc.__suppress_context__:
+            exc = None
+        else:
+            exc = exc.__context__
+    return chain
+
+
+def _classify_error(exc: BaseException) -> str:
+    """Name the layer where the registration failed."""
+    chain = _exception_chain(exc)
+    if any(isinstance(e, socket.gaierror) for e in chain):
+        return "dns"
+    if any(isinstance(e, ssl.SSLError) for e in chain):
+        return "tls"
+    if isinstance(exc, httpx.TimeoutException):
+        return "timeout"
+    if isinstance(exc, httpx.ConnectError):
+        return "connect"
+    if isinstance(exc, httpx.HTTPStatusError):
+        if exc.response.status_code in (401, 403):
+            return "auth"
+        return "http_status"
+    if isinstance(exc, httpx.RequestError):
+        return "network"
+    if isinstance(exc, ValueError):
+        return "response_parse"
+    return "unexpected"
+
+
+def _describe_chain(exc: BaseException) -> str:
+    return " <- ".join(
+        f"{type(e).__module__}.{type(e).__name__}(errno={getattr(e, 'errno', None)})"
+        for e in _exception_chain(exc)
+    )
+
+
+def _loggable_body(response) -> str | None:
+    """Response body safe to log.
+
+    Other 4xx responses (400, 422...) may echo the request payload, which
+    carries the participant's name and email, so only their shape is logged.
+    """
+    if response is None:
+        return None
+    status = response.status_code
+    if status >= 500 or status in (401, 403):
+        return response.text[:RESPONSE_BODY_LOG_LIMIT]
+    return (
+        f"<omitted: content-type={response.headers.get('content-type')} "
+        f"length={len(response.content)}>"
+    )
 
 
 class CertificatesOnSolana:
@@ -34,10 +106,6 @@ class CertificatesOnSolana:
         logger=logger,
     )
     def register_certificate_on_solana(certificate_data: dict) -> dict:
-        logger.info(
-            "Registering certificate on Solana blockchain with data: %s",
-            certificate_data,
-        )
         """
         Registers a certificate on the Solana blockchain.
 
@@ -47,6 +115,16 @@ def register_certificate_on_solana(certificate_data: dict) -> dict:
         Returns:
             dict: A dictionary with the registration result.
         """
+        target = urlparse(config.SERVICE_URL_REGISTRATION_API_SOLANA)
+        logger.info(
+            "Registering certificate on Solana: host=%s path=%s certificate_code=%s event=%s",
+            target.netloc,
+            target.path,
+            certificate_data.get("certificate_code"),
+            certificate_data.get("event"),
+        )
+        started = time.monotonic()
+        response = None
         try:
             with httpx.Client(timeout=60.0) as client:
                 response = client.post(
@@ -62,5 +140,18 @@ def register_certificate_on_solana(certificate_data: dict) -> dict:
                 solana_response = response.json()
                 return solana_response
         except Exception as e:
-            logger.error(f"Error registering certificate on Solana: {str(e)}")
-            raise CertificatesOnSolanaException(details=str(e), cause=e)
+            stage = _classify_error(e)
+            status = getattr(response, "status_code", None)
+            body = _loggable_body(response)
+            logger.exception(
+                "Error registering certificate on Solana: stage=%s host=%s elapsed_ms=%d "
+                "status=%s certificate_code=%s chain=%s body=%s",
+                stage,
+                target.netloc,
+                (time.monotonic() - started) * 1000,
+                status,
+                certificate_data.get("certificate_code"),
+                _describe_chain(e),
+                body,
+            )
+            raise CertificatesOnSolanaException(details=str(e), cause=e, stage=stage)

tests/test_certificates_on_solana.py

@@ -64,7 +64,9 @@ def test_register_certificate_success(sample_payload, monkeypatch):
         assert call_kwargs["json"] == sample_payload
 
 
-def test_register_certificate_http_error_raises(sample_payload, monkeypatch):
+def test_register_certificate_http_error_raises(
+    sample_payload, monkeypatch, no_retry_sleep
+):
     monkeypatch.setattr(
         module_under_test.config,
         "SERVICE_URL_REGISTRATION_API_SOLANA",
@@ -99,3 +101,142 @@ def _raise():
             CertificatesOnSolana.register_certificate_on_solana(sample_payload)
 
         assert "boom" in str(exc.value.details)
+
+
+@pytest.fixture
+def no_retry_sleep(monkeypatch):
+    import retry.api
+
+    monkeypatch.setattr(retry.api.time, "sleep", lambda _: None)
+
+
+def _client_raising_on_post(error):
+    mock_client_instance = MagicMock()
+    mock_client_instance.post.side_effect = error
+    mock_client_instance.__enter__.return_value = mock_client_instance
+    mock_client_instance.__exit__.return_value = False
+    return mock_client_instance
+
+
+def test_register_certificate_dns_failure_stage(sample_payload, no_retry_sleep):
+    import socket
+    import httpx
+
+    dns_error = httpx.ConnectError("[Errno -2] Name or service not known")
+    dns_error.__cause__ = socket.gaierror(-2, "Name or service not known")
+
+    with patch(
+        "certified_builder.certificates_on_solana.httpx.Client",
+        return_value=_client_raising_on_post(dns_error),
+    ):
+        with pytest.raises(CertificatesOnSolanaException) as exc:
+            CertificatesOnSolana.register_certificate_on_solana(sample_payload)
+
+    assert exc.value.stage == "dns"
+    assert "[stage=dns]" in str(exc.value)
+
+
+def test_register_certificate_auth_failure_stage(sample_payload, no_retry_sleep):
+    import httpx
+
+    request = httpx.Request("POST", "https://example.test/solana/register")
+    response = httpx.Response(401, request=request, json={"detail": "Invalid API Key"})
+
+    mock_client_instance = MagicMock()
+    mock_client_instance.post.return_value = response
+    mock_client_instance.__enter__.return_value = mock_client_instance
+    mock_client_instance.__exit__.return_value = False
+
+    with patch(
+        "certified_builder.certificates_on_solana.httpx.Client",
+        return_value=mock_client_instance,
+    ):
+        with pytest.raises(CertificatesOnSolanaException) as exc:
+            CertificatesOnSolana.register_certificate_on_solana(sample_payload)
+
+    assert exc.value.stage == "auth"
+
+
+def test_register_certificate_failure_log_has_no_secrets(
+    sample_payload, no_retry_sleep, caplog
+):
+    import httpx
+
+    with patch(
+        "certified_builder.certificates_on_solana.httpx.Client",
+        return_value=_client_raising_on_post(httpx.ConnectError("refused")),
+    ):
+        with pytest.raises(CertificatesOnSolanaException):
+            CertificatesOnSolana.register_certificate_on_solana(sample_payload)
+
+    assert "stage=connect" in caplog.text
+    assert "test-api-key" not in caplog.text
+    assert sample_payload["email"] not in caplog.text
+    assert sample_payload["name"] not in caplog.text
+
+
+def _client_returning(response):
+    mock_client_instance = MagicMock()
+    mock_client_instance.post.return_value = response
+    mock_client_instance.__enter__.return_value = mock_client_instance
+    mock_client_instance.__exit__.return_value = False
+    return mock_client_instance
+
+
+def test_register_certificate_4xx_body_echoing_payload_not_logged(
+    sample_payload, no_retry_sleep, caplog
+):
+    import httpx
+
+    request = httpx.Request("POST", "https://example.test/solana/register")
+    response = httpx.Response(
+        422,
+        request=request,
+        json={"detail": [{"loc": ["body", "email"], "input": sample_payload["email"]}]},
+    )
+
+    with patch(
+        "certified_builder.certificates_on_solana.httpx.Client",
+        return_value=_client_returning(response),
+    ):
+        with pytest.raises(CertificatesOnSolanaException) as exc:
+            CertificatesOnSolana.register_certificate_on_solana(sample_payload)
+
+    assert exc.value.stage == "http_status"
+    assert "body=<omitted: content-type=application/json" in caplog.text
+    assert sample_payload["email"] not in caplog.text
+
+
+def test_register_certificate_5xx_body_logged(sample_payload, no_retry_sleep, caplog):
+    import httpx
+
+    request = httpx.Request("POST", "https://example.test/solana/register")
+    response = httpx.Response(503, request=request, text="solana rpc unavailable")
+
+    with patch(
+        "certified_builder.certificates_on_solana.httpx.Client",
+        return_value=_client_returning(response),
+    ):
+        with pytest.raises(CertificatesOnSolanaException):
+            CertificatesOnSolana.register_certificate_on_solana(sample_payload)
+
+    assert "body=solana rpc unavailable" in caplog.text
+
+
+def test_register_certificate_non_json_2xx_is_response_parse(
+    sample_payload, no_retry_sleep, caplog
+):
+    import httpx
+
+    request = httpx.Request("POST", "https://example.test/solana/register")
+    response = httpx.Response(200, request=request, text="<html>not json</html>")
+
+    with patch(
+        "certified_builder.certificates_on_solana.httpx.Client",
+        return_value=_client_returning(response),
+    ):
+        with pytest.raises(CertificatesOnSolanaException) as exc:
+            CertificatesOnSolana.register_certificate_on_solana(sample_payload)
+
+    assert exc.value.stage == "response_parse"
+    assert "StopIteration" not in caplog.text