Bump version to 0.1.3; enhance logging with correlation_id for better error tracing and add request lifecycle middleware
This commit is contained in:
@@ -16,6 +16,7 @@ nexus-claude-api.local.json
|
||||
.omo
|
||||
.codegraph
|
||||
.agents
|
||||
.claude
|
||||
|
||||
# logs
|
||||
logs
|
||||
|
||||
@@ -60,6 +60,7 @@ The proxy defaults to Opus because this deployment is intended for users whose N
|
||||
- As a Claude Code user, I can use tool calls and tool results.
|
||||
- As a multimodal user, I can send images through Claude-compatible image content blocks.
|
||||
- As a developer debugging setup, I can enable verbose logs without exposing tokens.
|
||||
- As a developer debugging issues, I can trace any error in the log file using a correlation_id that appears in both the client response and the log entry.
|
||||
|
||||
## Acceptance Criteria
|
||||
|
||||
@@ -70,6 +71,7 @@ The proxy defaults to Opus because this deployment is intended for users whose N
|
||||
- `--dev` startup reads current-directory `nexus-claude-api.local.json` instead of user config.
|
||||
- Default logs are written to `~/.config/nexus-claude-api/logs/nexus-claude-api-YYYY-MM-DD.log`.
|
||||
- `--dev` logs are written to current-directory `logs/nexus-claude-api-YYYY-MM-DD.log`.
|
||||
- All API errors (4xx, 5xx, network failures, client disconnects) are logged with correlation_id and duration.
|
||||
- Missing Nexus credentials fail fast with a clear error.
|
||||
- `GET /health` returns healthy status.
|
||||
- `GET /v1/models` returns the supported Claude models.
|
||||
|
||||
@@ -29,7 +29,9 @@ nexus-claude-api/
|
||||
__main__.py
|
||||
cli.py
|
||||
config.py
|
||||
diagnostics.py
|
||||
errors.py
|
||||
logging_config.py
|
||||
models.py
|
||||
nexus_client.py
|
||||
server.py
|
||||
@@ -212,6 +214,28 @@ Status mapping:
|
||||
- Nexus throttling: `429`
|
||||
- Nexus network/timeout: `502` or `504`
|
||||
- unexpected server error: `500`
|
||||
- client disconnected: `499` (logged only, not sent)
|
||||
|
||||
## Observability
|
||||
|
||||
All errors are logged to the daily log file with a `correlation_id` for tracing.
|
||||
|
||||
Request lifecycle middleware logs:
|
||||
|
||||
- `request_complete` with method, path, status, and duration_ms for every `/v1/messages` request.
|
||||
- `client_disconnected` when the client drops connection mid-request or mid-stream.
|
||||
- `unhandled_exception` with traceback for unexpected errors (returns 500).
|
||||
|
||||
Error logging at point of origin:
|
||||
|
||||
- `nexus_client_error` (WARNING): Nexus API returned an error (4xx/5xx) with error code, message, HTTP status, and request ID.
|
||||
- `nexus_botocore_error` (WARNING): Network/transport failure (timeout, DNS, connection reset).
|
||||
- `stream_nexus_error` (WARNING): Error during streaming response iteration.
|
||||
- `stream_client_disconnected` (INFO): Client closed connection during streaming.
|
||||
- `validation_error` (WARNING): Malformed request that failed pydantic validation.
|
||||
- `nexus_error` (WARNING): NexusClaudeError in non-streaming response path.
|
||||
|
||||
Diagnostics summarize each request (model, stream flag, message count, content block types, tool info) without logging secrets, prompt text, or base64 data.
|
||||
|
||||
## Testing
|
||||
|
||||
@@ -234,6 +258,11 @@ Route tests:
|
||||
- `POST /v1/messages` non-stream
|
||||
- `POST /v1/messages` stream
|
||||
- `POST /v1/messages/count_tokens`
|
||||
- Validation errors are logged with correlation_id.
|
||||
- Nexus errors (non-stream) are logged with status and type.
|
||||
- Nexus errors (stream) are logged as `stream_nexus_error`.
|
||||
- Request completion is logged with duration_ms.
|
||||
- Unexpected exceptions return 500 and are logged.
|
||||
|
||||
CLI tests:
|
||||
|
||||
|
||||
+1
-1
@@ -1,6 +1,6 @@
|
||||
[project]
|
||||
name = "nexus-claude-api"
|
||||
version = "0.1.2"
|
||||
version = "0.1.3"
|
||||
description = "Local Anthropic-compatible Claude Code proxy for AI Nexus Bedrock Converse."
|
||||
readme = "README.md"
|
||||
requires-python = ">=3.11"
|
||||
|
||||
@@ -1,3 +1,3 @@
|
||||
"""Local Anthropic-compatible proxy for AI Nexus Claude models."""
|
||||
|
||||
__version__ = "0.1.2"
|
||||
__version__ = "0.1.3"
|
||||
|
||||
@@ -40,6 +40,11 @@ class NexusClient:
|
||||
correlation_id=correlation_id,
|
||||
) from exc
|
||||
except BotoCoreError as exc:
|
||||
logger.warning(
|
||||
"nexus_botocore_error operation=converse correlation_id=%s error=%s",
|
||||
correlation_id,
|
||||
str(exc),
|
||||
)
|
||||
raise NexusClaudeError(
|
||||
"Failed to call Nexus Converse API",
|
||||
status_code=502,
|
||||
@@ -62,6 +67,11 @@ class NexusClient:
|
||||
correlation_id=correlation_id,
|
||||
) from exc
|
||||
except BotoCoreError as exc:
|
||||
logger.warning(
|
||||
"nexus_botocore_error operation=converse_stream correlation_id=%s error=%s",
|
||||
correlation_id,
|
||||
str(exc),
|
||||
)
|
||||
raise NexusClaudeError(
|
||||
"Failed to call Nexus Converse Stream API",
|
||||
status_code=502,
|
||||
|
||||
@@ -71,6 +71,13 @@ def anthropic_sse_stream(
|
||||
for event in bedrock_stream_to_anthropic_events(stream, model=model):
|
||||
yield sse_frame(event)
|
||||
except NexusClaudeError as exc:
|
||||
logger.warning(
|
||||
"stream_nexus_error correlation_id=%s status=%d type=%s message=%s",
|
||||
correlation_id,
|
||||
exc.status_code,
|
||||
exc.error_type,
|
||||
exc.message,
|
||||
)
|
||||
yield sse_frame(
|
||||
{
|
||||
"type": "error",
|
||||
@@ -81,6 +88,9 @@ def anthropic_sse_stream(
|
||||
},
|
||||
}
|
||||
)
|
||||
except GeneratorExit:
|
||||
logger.info("stream_client_disconnected correlation_id=%s", correlation_id)
|
||||
return
|
||||
except Exception:
|
||||
logger.exception(
|
||||
"anthropic_messages_stream_error correlation_id=%s",
|
||||
@@ -144,12 +154,24 @@ async def create_message(
|
||||
)
|
||||
return JSONResponse(content=anthropic_response.model_dump(exclude_none=True))
|
||||
except ValidationError as exc:
|
||||
logger.warning(
|
||||
"validation_error correlation_id=%s error=%s",
|
||||
correlation_id,
|
||||
str(exc)[:500],
|
||||
)
|
||||
return anthropic_error_response(
|
||||
str(exc),
|
||||
status_code=400,
|
||||
correlation_id=correlation_id,
|
||||
)
|
||||
except NexusClaudeError as exc:
|
||||
logger.warning(
|
||||
"nexus_error correlation_id=%s status=%d type=%s message=%s",
|
||||
correlation_id,
|
||||
exc.status_code,
|
||||
exc.error_type,
|
||||
exc.message,
|
||||
)
|
||||
return anthropic_error_response(
|
||||
exc.message,
|
||||
status_code=exc.status_code,
|
||||
|
||||
@@ -1,9 +1,14 @@
|
||||
from __future__ import annotations
|
||||
|
||||
import logging
|
||||
import time
|
||||
|
||||
from fastapi import FastAPI
|
||||
from fastapi.middleware.cors import CORSMiddleware
|
||||
from fastapi.requests import Request
|
||||
from fastapi.responses import JSONResponse
|
||||
from fastapi.responses import JSONResponse, Response
|
||||
from starlette.middleware.base import BaseHTTPMiddleware
|
||||
from starlette.requests import ClientDisconnect
|
||||
|
||||
from nexus_claude_api import __version__
|
||||
from nexus_claude_api.config import Settings
|
||||
@@ -13,6 +18,54 @@ from nexus_claude_api.routes.health import router as health_router
|
||||
from nexus_claude_api.routes.messages import router as messages_router
|
||||
from nexus_claude_api.routes.models import router as models_router
|
||||
|
||||
logger = logging.getLogger(__name__)
|
||||
|
||||
|
||||
class RequestLifecycleMiddleware(BaseHTTPMiddleware):
|
||||
async def dispatch(self, request: Request, call_next):
|
||||
if not request.url.path.startswith("/v1/messages"):
|
||||
return await call_next(request)
|
||||
|
||||
start = time.perf_counter()
|
||||
try:
|
||||
response = await call_next(request)
|
||||
duration_ms = (time.perf_counter() - start) * 1000
|
||||
logger.info(
|
||||
"request_complete method=%s path=%s status=%d duration_ms=%.1f",
|
||||
request.method,
|
||||
request.url.path,
|
||||
response.status_code,
|
||||
duration_ms,
|
||||
)
|
||||
return response
|
||||
except ClientDisconnect:
|
||||
duration_ms = (time.perf_counter() - start) * 1000
|
||||
logger.info(
|
||||
"client_disconnected method=%s path=%s duration_ms=%.1f",
|
||||
request.method,
|
||||
request.url.path,
|
||||
duration_ms,
|
||||
)
|
||||
return Response(status_code=499)
|
||||
except Exception:
|
||||
duration_ms = (time.perf_counter() - start) * 1000
|
||||
logger.exception(
|
||||
"unhandled_exception method=%s path=%s duration_ms=%.1f",
|
||||
request.method,
|
||||
request.url.path,
|
||||
duration_ms,
|
||||
)
|
||||
return JSONResponse(
|
||||
status_code=500,
|
||||
content={
|
||||
"type": "error",
|
||||
"error": {
|
||||
"type": "api_error",
|
||||
"message": "Internal server error",
|
||||
},
|
||||
},
|
||||
)
|
||||
|
||||
|
||||
def create_app(
|
||||
settings: Settings | None = None,
|
||||
@@ -23,6 +76,7 @@ def create_app(
|
||||
app.state.settings = resolved_settings
|
||||
app.state.nexus_client = nexus_client or NexusClient(resolved_settings)
|
||||
|
||||
app.add_middleware(RequestLifecycleMiddleware)
|
||||
app.add_middleware(
|
||||
CORSMiddleware,
|
||||
allow_origins=["*"],
|
||||
@@ -43,4 +97,18 @@ def create_app(
|
||||
error_type=exc.error_type,
|
||||
)
|
||||
|
||||
@app.exception_handler(ClientDisconnect)
|
||||
async def handle_client_disconnect(_: Request, exc: ClientDisconnect) -> Response:
|
||||
logger.debug("client_disconnect_handler_invoked")
|
||||
return Response(status_code=499)
|
||||
|
||||
@app.exception_handler(Exception)
|
||||
async def handle_unexpected_error(_: Request, exc: Exception) -> JSONResponse:
|
||||
logger.exception("unhandled_exception")
|
||||
return anthropic_error_response(
|
||||
"Internal server error",
|
||||
status_code=500,
|
||||
error_type="api_error",
|
||||
)
|
||||
|
||||
return app
|
||||
|
||||
@@ -230,3 +230,87 @@ def test_count_tokens() -> None:
|
||||
|
||||
assert response.status_code == 200
|
||||
assert response.json()["input_tokens"] > 0
|
||||
|
||||
|
||||
def test_validation_error_is_logged(caplog) -> None:
|
||||
caplog.set_level(logging.WARNING, logger="nexus_claude_api.routes.messages")
|
||||
|
||||
response = client().post(
|
||||
"/v1/messages",
|
||||
json={"model": "claude-opus-4.6", "max_tokens": -1},
|
||||
)
|
||||
|
||||
assert response.status_code == 400
|
||||
assert any("validation_error" in r.message for r in caplog.records)
|
||||
|
||||
|
||||
def test_nexus_error_non_stream_is_logged(caplog) -> None:
|
||||
caplog.set_level(logging.WARNING, logger="nexus_claude_api.routes.messages")
|
||||
|
||||
response = client(AccessDeniedNexusClient()).post(
|
||||
"/v1/messages",
|
||||
json={
|
||||
"model": "claude-opus-4.6",
|
||||
"messages": [{"role": "user", "content": "Hello"}],
|
||||
"max_tokens": 32,
|
||||
},
|
||||
)
|
||||
|
||||
assert response.status_code == 403
|
||||
assert any("nexus_error" in r.message for r in caplog.records)
|
||||
|
||||
|
||||
def test_stream_nexus_error_is_logged(caplog) -> None:
|
||||
caplog.set_level(logging.WARNING, logger="nexus_claude_api.routes.messages")
|
||||
|
||||
with client(StreamErrorNexusClient()).stream(
|
||||
"POST",
|
||||
"/v1/messages",
|
||||
json={
|
||||
"model": "claude-opus-4.6",
|
||||
"messages": [{"role": "user", "content": "Hello"}],
|
||||
"max_tokens": 32,
|
||||
"stream": True,
|
||||
},
|
||||
) as response:
|
||||
response.read()
|
||||
|
||||
assert any("stream_nexus_error" in r.message for r in caplog.records)
|
||||
|
||||
|
||||
def test_request_complete_is_logged(caplog) -> None:
|
||||
caplog.set_level(logging.INFO, logger="nexus_claude_api.server")
|
||||
|
||||
client().post(
|
||||
"/v1/messages",
|
||||
json={
|
||||
"model": "claude-opus-4.6",
|
||||
"messages": [{"role": "user", "content": "Hello"}],
|
||||
"max_tokens": 32,
|
||||
},
|
||||
)
|
||||
|
||||
assert any("request_complete" in r.message and "duration_ms" in r.message for r in caplog.records)
|
||||
|
||||
|
||||
class ExplodingNexusClient:
|
||||
def converse(self, request: dict, *, correlation_id: str | None = None) -> dict:
|
||||
raise RuntimeError("unexpected kaboom")
|
||||
|
||||
|
||||
def test_unexpected_exception_returns_500_and_is_logged(caplog) -> None:
|
||||
caplog.set_level(logging.ERROR, logger="nexus_claude_api.server")
|
||||
|
||||
response = client(ExplodingNexusClient()).post(
|
||||
"/v1/messages",
|
||||
json={
|
||||
"model": "claude-opus-4.6",
|
||||
"messages": [{"role": "user", "content": "Hello"}],
|
||||
"max_tokens": 32,
|
||||
},
|
||||
)
|
||||
|
||||
assert response.status_code == 500
|
||||
body = response.json()
|
||||
assert body["error"]["type"] == "api_error"
|
||||
assert any("unhandled_exception" in r.message for r in caplog.records)
|
||||
|
||||
Reference in New Issue
Block a user