From 7788cfbfdbd7b0cd7222d8bb1bdc3bcbfb1f8d0d Mon Sep 17 00:00:00 2001 From: Apoorv-Raj777 Date: Sun, 7 Jun 2026 05:11:20 +0530 Subject: [PATCH 1/5] docs: add request ID contract and tracing developer guide --- CONTRIBUTING.md | 1 + backend/secuscan/request_middleware.py | 5 + docs/API.md | 2 + docs/request-id.md | 145 +++++++++++++++++++++++++ 4 files changed, 153 insertions(+) create mode 100644 docs/request-id.md diff --git a/CONTRIBUTING.md b/CONTRIBUTING.md index 2c3526b9..ac20282e 100644 --- a/CONTRIBUTING.md +++ b/CONTRIBUTING.md @@ -359,6 +359,7 @@ Please match the conventions already used in the repo instead of introducing a n - Use type hints where they improve clarity - Keep validation close to request and model boundaries - Prefer small functions over large, multi-purpose blocks + - For HTTP request tracing and log/audit correlation guidelines, see [Request ID Tracing](docs/request-id.md) - Frontend: - Use TypeScript and functional React components - Keep component logic readable and avoid unnecessary abstraction diff --git a/backend/secuscan/request_middleware.py b/backend/secuscan/request_middleware.py index 985b4979..d90a05a0 100644 --- a/backend/secuscan/request_middleware.py +++ b/backend/secuscan/request_middleware.py @@ -1,3 +1,8 @@ +""" +Request ID middleware to extract/generate request IDs for FastAPI requests. +For a detailed guide on the Request ID tracking contract and correlation, +refer to the developer documentation: docs/request-id.md +""" from starlette.middleware.base import BaseHTTPMiddleware from fastapi import Request from .request_context import set_request_id diff --git a/docs/API.md b/docs/API.md index d67231ca..035c7a71 100644 --- a/docs/API.md +++ b/docs/API.md @@ -1,5 +1,7 @@ # SecuScan API Documentation +All API requests support Request Tracing. For details on how request IDs are generated, passed through, and correlated, see [Request ID Documentation](request-id.md). + ## Tasks API ### List Tasks with Pagination diff --git a/docs/request-id.md b/docs/request-id.md new file mode 100644 index 00000000..89500e4d --- /dev/null +++ b/docs/request-id.md @@ -0,0 +1,145 @@ +# Request ID Tracing and Correlation Guide + +This guide explains how request IDs are generated, propagated, and correlated across the different layers of SecuScan. If you are developing new endpoints, background tasks, or debugging system issues, refer to this guide to understand request tracing. + +--- + +## Overview + +SecuScan uses **Request IDs** to correlate actions end-to-end across: +1. **HTTP Requests**: Incoming API calls. +2. **Application Logs**: Logging output format (`JSONFormatter`). +3. **Audit Trail**: Action records saved in the database (`audit_log` table). +4. **Background Operations**: Async workflow steps and tasks. + +The tracking header used throughout the system is `X-Request-ID`. + +--- + +## 1. Generation & Context + +The request ID lifecycle is managed by [request_context.py](file:///d:/GSSOC/utksh1/%23573/SecuScan/backend/secuscan/request_context.py) using Python's standard `contextvars.ContextVar`. + +- If the incoming HTTP request has an `X-Request-ID` header, that value is used verbatim. +- If no header is provided, a standard UUID (v4) is generated via `uuid.uuid4()`. + +### Code Reference + +```python +from secuscan.request_context import get_request_id, set_request_id + +# Retrieve the current request ID +current_id = get_request_id() + +# Set/override the request ID (generates a uuid4 if none provided) +new_id = set_request_id("custom-id") +``` + +--- + +## 2. Middleware Passthrough + +For HTTP requests, [request_middleware.py](file:///d:/GSSOC/utksh1/%23573/SecuScan/backend/secuscan/request_middleware.py) defines the `RequestIDMiddleware` registered in FastAPI. + +During the request-response lifecycle: +1. **Extraction**: The middleware reads the `X-Request-ID` header and calls `set_request_id(request_id)`. +2. **State Storage**: It attaches the ID to FastAPI's request state: `request.state.request_id = request_id`. +3. **Response Header**: It adds the ID to the outgoing response headers: `response.headers["X-Request-ID"] = request_id`. + +--- + +## 3. Log Correlation + +SecuScan filters and formats all application logs to include the request ID: +- **Filter**: `RequestIDFilter` (in [logging_utils.py](file:///d:/GSSOC/utksh1/%23573/SecuScan/backend/secuscan/logging_utils.py)) dynamically fetches the current ID using `get_request_id()` and attaches it to the log record as `request_id`. +- **Formatter**: `JSONFormatter` (in [logging_utils.py](file:///d:/GSSOC/utksh1/%23573/SecuScan/backend/secuscan/logging_utils.py)) serializes the log output as a JSON string, emitting `request_id` as a top-level field. + +### Sample JSON Log Line + +```json +{"timestamp": "2026-06-07T05:07:37.123456Z", "level": "INFO", "request_id": "a1b2c3d4-e5f6-7a8b-9c0d-1e2f3a4b5c6d", "logger": "secuscan.routes", "message": "Starting scan task for target: example.com"} +``` + +### Filtering Logs via CLI + +To isolate all log messages associated with a single request ID: + +```bash +grep '"request_id": "a1b2c3d4-..."' logs/secuscan.log | jq . +``` + +--- + +## 4. Audit Log Correlation + +Critical events are permanently recorded in the SQLite database by calling `db.log_audit()` in [database.py](file:///d:/GSSOC/utksh1/%23573/SecuScan/backend/secuscan/database.py). + +- `log_audit()` automatically reads the active Request ID from context: `request_id = request_id or get_request_id()`. +- The request ID is saved inside the `context_json` column of the `audit_log` table under the `"request_id"` key. + +### Querying the Audit Log in SQLite + +You can query and correlate audit trails for a specific Request ID using SQLite's JSON extension functions: + +```sql +SELECT timestamp, event_type, message, context_json +FROM audit_log +WHERE json_extract(context_json, '$.request_id') = 'a1b2c3d4-e5f6-7a8b-9c0d-1e2f3a4b5c6d'; +``` + +--- + +## 5. End-to-End Debugging Walkthrough + +Follow these steps to trace a custom client request from execution to storage: + +1. **Trigger Request**: Send an API request using curl with a custom `X-Request-ID` header: + ```bash + curl -H "X-Request-ID: debug-test-001" http://localhost:8000/api/v1/health + ``` +2. **Confirm Response Header**: Check the response headers to ensure the same ID is returned: + ```http + X-Request-ID: debug-test-001 + ``` +3. **Filter Logs**: Search the log file to see the path of execution: + ```bash + grep '"request_id": "debug-test-001"' logs/secuscan.log | jq . + ``` +4. **Query Database**: Open your local SQLite instance and fetch matching audit logs: + ```bash + sqlite3 data/secuscan.db "SELECT timestamp, event_type, message FROM audit_log WHERE json_extract(context_json, '$.request_id') = 'debug-test-001';" + ``` + +--- + +## 6. Guidelines for Writing New Code + +### Standard Request Lifecycles +Within FastAPI request handlers, `get_request_id()` is safe to call at any time to obtain the current request ID. + +### Spawning Background Tasks +Python `ContextVar` environments are inherited when creating async tasks within the same execution path. However, when spawning separate background work that detaches from the request lifecycle (e.g., using `asyncio.create_task` or queueing executors), you **must** propagate the ID manually. + +Example from [workflows.py](file:///d:/GSSOC/utksh1/%23573/SecuScan/backend/secuscan/workflows.py): + +```python +# 1. Capture the Request ID in the active parent scope +request_id = get_request_id() + +# 2. Create the wrapper task setting the captured ID inside the new ContextVar scope +async def run_task(task_id: str) -> None: + set_request_id(request_id) + await executor.execute_task(task_id) + +asyncio.create_task(run_task(task_id)) +``` + +If triggering background audit events manually, you can also pass a captured ID directly to the `log_audit()` call: + +```python +await db.log_audit( + event_type="background_scan", + message="Scan complete", + request_id=captured_request_id +) +``` From 5b03fc5a4532dc87ac393dafd102eed7b5c6b327 Mon Sep 17 00:00:00 2001 From: Apoorv-Raj777 Date: Sun, 7 Jun 2026 05:18:30 +0530 Subject: [PATCH 2/5] fix(workflows): resolve undefined db variable and remove trailing whitespace in docs --- backend/secuscan/workflows.py | 1 + docs/request-id.md | 2 +- 2 files changed, 2 insertions(+), 1 deletion(-) diff --git a/backend/secuscan/workflows.py b/backend/secuscan/workflows.py index eb98c598..c7ba88dc 100644 --- a/backend/secuscan/workflows.py +++ b/backend/secuscan/workflows.py @@ -72,6 +72,7 @@ def _should_run(self, now: datetime, last_run_at: str | None, schedule_seconds: return elapsed >= schedule_seconds async def _run_workflow(self, workflow_id: str, steps: List[Dict[str, Any]]): logger.info("Running workflow %s with %d step(s)", workflow_id, len(steps)) + db = await get_db() for step in steps: plugin_id = step.get("plugin_id") inputs = step.get("inputs") or {} diff --git a/docs/request-id.md b/docs/request-id.md index 89500e4d..a1b24b3b 100644 --- a/docs/request-id.md +++ b/docs/request-id.md @@ -72,7 +72,7 @@ grep '"request_id": "a1b2c3d4-..."' logs/secuscan.log | jq . ## 4. Audit Log Correlation -Critical events are permanently recorded in the SQLite database by calling `db.log_audit()` in [database.py](file:///d:/GSSOC/utksh1/%23573/SecuScan/backend/secuscan/database.py). +Critical events are permanently recorded in the SQLite database by calling `db.log_audit()` in [database.py](file:///d:/GSSOC/utksh1/%23573/SecuScan/backend/secuscan/database.py). - `log_audit()` automatically reads the active Request ID from context: `request_id = request_id or get_request_id()`. - The request ID is saved inside the `context_json` column of the `audit_log` table under the `"request_id"` key. From 7d2ce8da8384b30949733c4d7f0e7240d28c80a0 Mon Sep 17 00:00:00 2001 From: Apoorv-Raj777 Date: Sun, 7 Jun 2026 05:26:24 +0530 Subject: [PATCH 3/5] test(frontend): mock missing config APIs and update workflow creation expectation --- .../testing/unit/pages/ToolConfigDynamic.test.tsx | 11 ++++++++++- .../testing/unit/pages/ToolConfigTimeout.test.tsx | 8 +++++++- frontend/testing/unit/pages/Workflows.test.tsx | 12 +++++++++++- 3 files changed, 28 insertions(+), 3 deletions(-) diff --git a/frontend/testing/unit/pages/ToolConfigDynamic.test.tsx b/frontend/testing/unit/pages/ToolConfigDynamic.test.tsx index 6cd5a1da..65b0aa36 100644 --- a/frontend/testing/unit/pages/ToolConfigDynamic.test.tsx +++ b/frontend/testing/unit/pages/ToolConfigDynamic.test.tsx @@ -2,7 +2,7 @@ import { render, screen, waitFor } from '@testing-library/react' import userEvent from '@testing-library/user-event' import { MemoryRouter, Route, Routes } from 'react-router-dom' import ToolConfig from '../../../src/pages/ToolConfig' -import { getPluginSchema, listPlugins, startTask } from '../../../src/api' +import { getPluginSchema, listPlugins, startTask, getSettings, listTargetPolicies, listCredentialProfiles, listSessionProfiles } from '../../../src/api' import { routes } from '../../../src/routes' const addToast = vi.fn() @@ -15,11 +15,19 @@ vi.mock('../../../src/api', () => ({ listPlugins: vi.fn(), getPluginSchema: vi.fn(), startTask: vi.fn(), + getSettings: vi.fn(), + listTargetPolicies: vi.fn(), + listCredentialProfiles: vi.fn(), + listSessionProfiles: vi.fn(), })) describe('ToolConfig dynamic schema flow', () => { beforeEach(() => { addToast.mockReset() + vi.mocked(getSettings).mockResolvedValue({ sandbox: { default_timeout: 600 } }) + vi.mocked(listTargetPolicies).mockResolvedValue({ items: [] }) + vi.mocked(listCredentialProfiles).mockResolvedValue({ items: [] }) + vi.mocked(listSessionProfiles).mockResolvedValue({ items: [] }) vi.mocked(listPlugins).mockResolvedValue({ total: 1, plugins: [ @@ -82,6 +90,7 @@ describe('ToolConfig dynamic schema flow', () => { } /> + Task Details} /> , ) diff --git a/frontend/testing/unit/pages/ToolConfigTimeout.test.tsx b/frontend/testing/unit/pages/ToolConfigTimeout.test.tsx index 4c0b2213..c6edf2b0 100644 --- a/frontend/testing/unit/pages/ToolConfigTimeout.test.tsx +++ b/frontend/testing/unit/pages/ToolConfigTimeout.test.tsx @@ -2,7 +2,7 @@ import { render, screen } from '@testing-library/react' import userEvent from '@testing-library/user-event' import { MemoryRouter, Route, Routes } from 'react-router-dom' import ToolConfig from '../../../src/pages/ToolConfig' -import { getPluginSchema, listPlugins, startTask, getSettings } from '../../../src/api' +import { getPluginSchema, listPlugins, startTask, getSettings, listTargetPolicies, listCredentialProfiles, listSessionProfiles } from '../../../src/api' import { routes } from '../../../src/routes' const addToast = vi.fn() @@ -16,11 +16,17 @@ vi.mock('../../../src/api', () => ({ getPluginSchema: vi.fn(), startTask: vi.fn(), getSettings: vi.fn(), + listTargetPolicies: vi.fn(), + listCredentialProfiles: vi.fn(), + listSessionProfiles: vi.fn(), })) describe('ToolConfig timeout control', () => { beforeEach(() => { addToast.mockReset() + vi.mocked(listTargetPolicies).mockResolvedValue({ items: [] }) + vi.mocked(listCredentialProfiles).mockResolvedValue({ items: [] }) + vi.mocked(listSessionProfiles).mockResolvedValue({ items: [] }) vi.mocked(listPlugins).mockResolvedValue({ total: 1, plugins: [ diff --git a/frontend/testing/unit/pages/Workflows.test.tsx b/frontend/testing/unit/pages/Workflows.test.tsx index 7c304da8..25281b3d 100644 --- a/frontend/testing/unit/pages/Workflows.test.tsx +++ b/frontend/testing/unit/pages/Workflows.test.tsx @@ -130,7 +130,17 @@ describe('Workflows — create action', () => { name: 'Nightly Scan', schedule_seconds: 7200, enabled: true, - steps: [{ plugin_id: '', inputs: {} }], + steps: [ + { + plugin_id: '', + inputs: {}, + execution_context: { + scan_profile: 'standard', + validation_mode: 'proof', + evidence_level: 'standard', + }, + }, + ], }) }) }) From 9e3576a580f56fd2e84391123c1c30d8de961f7e Mon Sep 17 00:00:00 2001 From: Apoorv-Raj777 Date: Sun, 7 Jun 2026 05:29:56 +0530 Subject: [PATCH 4/5] test(frontend): fix mock types for target policies, credential profiles, and session profiles --- frontend/testing/unit/pages/ToolConfigDynamic.test.tsx | 6 +++--- frontend/testing/unit/pages/ToolConfigTimeout.test.tsx | 6 +++--- 2 files changed, 6 insertions(+), 6 deletions(-) diff --git a/frontend/testing/unit/pages/ToolConfigDynamic.test.tsx b/frontend/testing/unit/pages/ToolConfigDynamic.test.tsx index 65b0aa36..8d65c7f1 100644 --- a/frontend/testing/unit/pages/ToolConfigDynamic.test.tsx +++ b/frontend/testing/unit/pages/ToolConfigDynamic.test.tsx @@ -25,9 +25,9 @@ describe('ToolConfig dynamic schema flow', () => { beforeEach(() => { addToast.mockReset() vi.mocked(getSettings).mockResolvedValue({ sandbox: { default_timeout: 600 } }) - vi.mocked(listTargetPolicies).mockResolvedValue({ items: [] }) - vi.mocked(listCredentialProfiles).mockResolvedValue({ items: [] }) - vi.mocked(listSessionProfiles).mockResolvedValue({ items: [] }) + vi.mocked(listTargetPolicies).mockResolvedValue({ items: [], total: 0 }) + vi.mocked(listCredentialProfiles).mockResolvedValue({ items: [], total: 0 }) + vi.mocked(listSessionProfiles).mockResolvedValue({ items: [], total: 0 }) vi.mocked(listPlugins).mockResolvedValue({ total: 1, plugins: [ diff --git a/frontend/testing/unit/pages/ToolConfigTimeout.test.tsx b/frontend/testing/unit/pages/ToolConfigTimeout.test.tsx index c6edf2b0..f77c6631 100644 --- a/frontend/testing/unit/pages/ToolConfigTimeout.test.tsx +++ b/frontend/testing/unit/pages/ToolConfigTimeout.test.tsx @@ -24,9 +24,9 @@ vi.mock('../../../src/api', () => ({ describe('ToolConfig timeout control', () => { beforeEach(() => { addToast.mockReset() - vi.mocked(listTargetPolicies).mockResolvedValue({ items: [] }) - vi.mocked(listCredentialProfiles).mockResolvedValue({ items: [] }) - vi.mocked(listSessionProfiles).mockResolvedValue({ items: [] }) + vi.mocked(listTargetPolicies).mockResolvedValue({ items: [], total: 0 }) + vi.mocked(listCredentialProfiles).mockResolvedValue({ items: [], total: 0 }) + vi.mocked(listSessionProfiles).mockResolvedValue({ items: [], total: 0 }) vi.mocked(listPlugins).mockResolvedValue({ total: 1, plugins: [ From 599be7b865aabfb37c4b6b5cc8fd2a73361fa77d Mon Sep 17 00:00:00 2001 From: Apoorv-Raj777 Date: Sun, 7 Jun 2026 05:37:10 +0530 Subject: [PATCH 5/5] revert: remove all code and test modifications to keep PR focused strictly on documentation --- backend/secuscan/request_middleware.py | 5 ----- backend/secuscan/workflows.py | 1 - .../testing/unit/pages/ToolConfigDynamic.test.tsx | 11 +---------- .../testing/unit/pages/ToolConfigTimeout.test.tsx | 8 +------- frontend/testing/unit/pages/Workflows.test.tsx | 12 +----------- 5 files changed, 3 insertions(+), 34 deletions(-) diff --git a/backend/secuscan/request_middleware.py b/backend/secuscan/request_middleware.py index d90a05a0..985b4979 100644 --- a/backend/secuscan/request_middleware.py +++ b/backend/secuscan/request_middleware.py @@ -1,8 +1,3 @@ -""" -Request ID middleware to extract/generate request IDs for FastAPI requests. -For a detailed guide on the Request ID tracking contract and correlation, -refer to the developer documentation: docs/request-id.md -""" from starlette.middleware.base import BaseHTTPMiddleware from fastapi import Request from .request_context import set_request_id diff --git a/backend/secuscan/workflows.py b/backend/secuscan/workflows.py index c7ba88dc..eb98c598 100644 --- a/backend/secuscan/workflows.py +++ b/backend/secuscan/workflows.py @@ -72,7 +72,6 @@ def _should_run(self, now: datetime, last_run_at: str | None, schedule_seconds: return elapsed >= schedule_seconds async def _run_workflow(self, workflow_id: str, steps: List[Dict[str, Any]]): logger.info("Running workflow %s with %d step(s)", workflow_id, len(steps)) - db = await get_db() for step in steps: plugin_id = step.get("plugin_id") inputs = step.get("inputs") or {} diff --git a/frontend/testing/unit/pages/ToolConfigDynamic.test.tsx b/frontend/testing/unit/pages/ToolConfigDynamic.test.tsx index 8d65c7f1..6cd5a1da 100644 --- a/frontend/testing/unit/pages/ToolConfigDynamic.test.tsx +++ b/frontend/testing/unit/pages/ToolConfigDynamic.test.tsx @@ -2,7 +2,7 @@ import { render, screen, waitFor } from '@testing-library/react' import userEvent from '@testing-library/user-event' import { MemoryRouter, Route, Routes } from 'react-router-dom' import ToolConfig from '../../../src/pages/ToolConfig' -import { getPluginSchema, listPlugins, startTask, getSettings, listTargetPolicies, listCredentialProfiles, listSessionProfiles } from '../../../src/api' +import { getPluginSchema, listPlugins, startTask } from '../../../src/api' import { routes } from '../../../src/routes' const addToast = vi.fn() @@ -15,19 +15,11 @@ vi.mock('../../../src/api', () => ({ listPlugins: vi.fn(), getPluginSchema: vi.fn(), startTask: vi.fn(), - getSettings: vi.fn(), - listTargetPolicies: vi.fn(), - listCredentialProfiles: vi.fn(), - listSessionProfiles: vi.fn(), })) describe('ToolConfig dynamic schema flow', () => { beforeEach(() => { addToast.mockReset() - vi.mocked(getSettings).mockResolvedValue({ sandbox: { default_timeout: 600 } }) - vi.mocked(listTargetPolicies).mockResolvedValue({ items: [], total: 0 }) - vi.mocked(listCredentialProfiles).mockResolvedValue({ items: [], total: 0 }) - vi.mocked(listSessionProfiles).mockResolvedValue({ items: [], total: 0 }) vi.mocked(listPlugins).mockResolvedValue({ total: 1, plugins: [ @@ -90,7 +82,6 @@ describe('ToolConfig dynamic schema flow', () => { } /> - Task Details} /> , ) diff --git a/frontend/testing/unit/pages/ToolConfigTimeout.test.tsx b/frontend/testing/unit/pages/ToolConfigTimeout.test.tsx index f77c6631..4c0b2213 100644 --- a/frontend/testing/unit/pages/ToolConfigTimeout.test.tsx +++ b/frontend/testing/unit/pages/ToolConfigTimeout.test.tsx @@ -2,7 +2,7 @@ import { render, screen } from '@testing-library/react' import userEvent from '@testing-library/user-event' import { MemoryRouter, Route, Routes } from 'react-router-dom' import ToolConfig from '../../../src/pages/ToolConfig' -import { getPluginSchema, listPlugins, startTask, getSettings, listTargetPolicies, listCredentialProfiles, listSessionProfiles } from '../../../src/api' +import { getPluginSchema, listPlugins, startTask, getSettings } from '../../../src/api' import { routes } from '../../../src/routes' const addToast = vi.fn() @@ -16,17 +16,11 @@ vi.mock('../../../src/api', () => ({ getPluginSchema: vi.fn(), startTask: vi.fn(), getSettings: vi.fn(), - listTargetPolicies: vi.fn(), - listCredentialProfiles: vi.fn(), - listSessionProfiles: vi.fn(), })) describe('ToolConfig timeout control', () => { beforeEach(() => { addToast.mockReset() - vi.mocked(listTargetPolicies).mockResolvedValue({ items: [], total: 0 }) - vi.mocked(listCredentialProfiles).mockResolvedValue({ items: [], total: 0 }) - vi.mocked(listSessionProfiles).mockResolvedValue({ items: [], total: 0 }) vi.mocked(listPlugins).mockResolvedValue({ total: 1, plugins: [ diff --git a/frontend/testing/unit/pages/Workflows.test.tsx b/frontend/testing/unit/pages/Workflows.test.tsx index 25281b3d..7c304da8 100644 --- a/frontend/testing/unit/pages/Workflows.test.tsx +++ b/frontend/testing/unit/pages/Workflows.test.tsx @@ -130,17 +130,7 @@ describe('Workflows — create action', () => { name: 'Nightly Scan', schedule_seconds: 7200, enabled: true, - steps: [ - { - plugin_id: '', - inputs: {}, - execution_context: { - scan_profile: 'standard', - validation_mode: 'proof', - evidence_level: 'standard', - }, - }, - ], + steps: [{ plugin_id: '', inputs: {} }], }) }) })