Skip to content

fix(logging): prevent infinite recursion in InterceptHandler fixes:#708#792

Closed
VasuS609 wants to merge 8 commits intoAOSSIE-Org:mainfrom
VasuS609:fix-logging-recursion
Closed

fix(logging): prevent infinite recursion in InterceptHandler fixes:#708#792
VasuS609 wants to merge 8 commits intoAOSSIE-Org:mainfrom
VasuS609:fix-logging-recursion

Conversation

@VasuS609
Copy link
Contributor

@VasuS609 VasuS609 commented Dec 17, 2025

This PR fixes a RecursionError that occurs when Uvicorn (or other stdlib loggers) emit logs, and the InterceptHandler tries to re-log them.

What was happening?
The handler called logger.log(...) inside emit(), which triggered the same handler again → infinite loop → crash.

How is it fixed?

  • The incoming log record is cloned.
  • The message is prefixed with [uvicorn].
  • The new record is sent directly to the root logger’s handlers, skipping any InterceptHandler instances to avoid re-entrancy.

This approach:

  • Eliminates recursion
  • Is thread-safe
  • Preserves log structure
  • Works for both backend and sync-microservice

Tested locally — the backend now starts without crashing, and Uvicorn logs appear as expected.

Fixes the issue described in #708

Summary by CodeRabbit

  • Bug Fixes

    • Improved logging reliability by preventing recursive handling, preserving log timing metadata, prefixing log messages with module context, and adding defensive error handling to avoid crashes and ensure consistent log output.
  • Documentation

    • Updated OpenAPI for the Face Tagging endpoint (clarified input_type parameter title/structure) and tightened image metadata schema to improve validation accuracy.

✏️ Tip: You can customize this high-level summary in your review settings.

@github-actions github-actions bot added backend bug Something isn't working labels Dec 17, 2025
@coderabbitai
Copy link
Contributor

coderabbitai bot commented Dec 17, 2025

Important

Review skipped

Review was skipped due to path filters

⛔ Files ignored due to path filters (1)
  • frontend/package-lock.json is excluded by !**/package-lock.json

CodeRabbit blocks several paths by default. You can override this behavior by explicitly including those paths in the path filters. For example, including **/dist/** will override the default block on the dist directory, by removing the pattern from both the lists.

You can disable this status message by setting the reviews.review_status to false in the CodeRabbit configuration file.

  • 🔍 Trigger a full review
📝 Walkthrough

Walkthrough

Updated InterceptHandler.emit in backend and sync-microservice to stop mutating incoming LogRecord by constructing a new LogRecord and forwarding it directly to root logger handlers (skipping InterceptHandler/self) with defensive error handling; tightened OpenAPI: wrapped input_type ref in allOf with a title and removed additionalProperties from ImageInCluster.Metadata.

Changes

Cohort / File(s) Summary
Logging Interceptor Refactor
backend/app/logging/setup_logging.py, sync-microservice/app/logging/setup_logging.py
Replaced in-place mutation of incoming LogRecord with creation of a new LogRecord whose message is prefixed with the module name; preserved timing attributes (created, msecs, relativeCreated); iterate root logger handlers and call handler.handle(new_record) while skipping InterceptHandler/self to avoid recursion; wrap handler calls in try/except to silently ignore handler errors.
OpenAPI Schema Tightening
docs/backend/backend_python/openapi.json
For face_tagging_face_clusters_face_search_post: input_type query parameter $ref changed to allOf: [ { "$ref": "#/components/schemas/InputType" } ] and given "title": "Input Type" (default preserved). In ImageInCluster, removed "additionalProperties": true from Metadata, leaving type: "object".

Sequence Diagram(s)

sequenceDiagram
  participant AppLogger as Logger
  participant Intercept as InterceptHandler
  participant Root as RootLogger
  participant H1 as RootHandler1
  participant Hn as RootHandlerN

  AppLogger->>Intercept: emit(original_record)
  rect rgba(173,216,230,0.5)
    Intercept->>Intercept: build new_record (prefix module, copy timing)
  end
  Intercept->>Root: forward new_record
  Root->>H1: handler.handle(new_record)
  Root->>Hn: handler.handle(new_record)
  note right of Hn: handler exceptions are caught and ignored
Loading

Estimated code review effort

🎯 3 (Moderate) | ⏱️ ~25 minutes

Possibly related PRs

Suggested reviewers

  • rahulharpal1603

Poem

🐰 I hop in, craft a tidy record with cheer,

I tuck the module name so the path stays clear.
I pass it to roots, let handlers softly play,
Errors I hush so loggers don't fray.
A nibble, a skip — logs tidy today.

🚥 Pre-merge checks | ✅ 3
✅ Passed checks (3 passed)
Check name Status Explanation
Description Check ✅ Passed Check skipped - CodeRabbit’s high-level summary is enabled.
Title check ✅ Passed The title 'fix(logging): prevent infinite recursion in InterceptHandler' directly and clearly summarizes the main change: fixing a recursion issue in the logging handler.
Docstring Coverage ✅ Passed Docstring coverage is 100.00% which is sufficient. The required threshold is 80.00%.

✏️ Tip: You can configure your own custom pre-merge checks in the settings.


Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out.

❤️ Share

Comment @coderabbitai help to get the list of available commands and usage tips.

Copy link
Contributor

@coderabbitai coderabbitai bot left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Actionable comments posted: 0

🧹 Nitpick comments (4)
sync-microservice/app/logging/setup_logging.py (2)

253-263: Remove exc_info and stack_info from the new LogRecord.

Based on learnings, stack traces should not be shown in logs when rerouting through InterceptHandler. The current implementation preserves exc_info and stack_info, which contradicts this requirement.

Apply this diff:

         new_record = logging.LogRecord(
             name=module_name,
             level=record.levelno,
             pathname=record.pathname,
             lineno=record.lineno,
             msg=f"[uvicorn] {msg}",
             args=(),
-            exc_info=record.exc_info,
+            exc_info=None,
             func=record.funcName,
-            sinfo=record.stack_info,
+            sinfo=None,
         )

258-258: Consider using a dynamic prefix based on the source logger.

The [uvicorn] prefix is hardcoded, but this handler also intercepts asyncio logs (see line 316-319). Consider using the original logger name or module_name for the prefix to avoid misleading log output.

-            msg=f"[uvicorn] {msg}",
+            msg=f"[{module_name}] {msg}",
backend/app/logging/setup_logging.py (2)

248-258: Remove exc_info and stack_info from the new LogRecord.

Same issue as in sync-microservice/app/logging/setup_logging.py. Based on learnings, stack traces should not be shown in logs when rerouting through InterceptHandler.

Apply this diff:

         new_record = logging.LogRecord(
             name=module_name,
             level=record.levelno,
             pathname=record.pathname,
             lineno=record.lineno,
             msg=f"[uvicorn] {msg}",
             args=(),
-            exc_info=record.exc_info,
+            exc_info=None,
             func=record.funcName,
-            sinfo=record.stack_info,
+            sinfo=None,
         )

212-274: Consider extracting shared InterceptHandler to reduce duplication.

The InterceptHandler class is nearly identical between backend/app/logging/setup_logging.py and sync-microservice/app/logging/setup_logging.py. This duplication increases maintenance burden and risks the implementations drifting apart.

Consider moving InterceptHandler to a shared module under utils/logging/ that both services can import.

📜 Review details

Configuration used: defaults

Review profile: CHILL

Plan: Pro

📥 Commits

Reviewing files that changed from the base of the PR and between d07d817 and 176d758.

📒 Files selected for processing (3)
  • backend/app/logging/setup_logging.py (1 hunks)
  • docs/backend/backend_python/openapi.json (1 hunks)
  • sync-microservice/app/logging/setup_logging.py (1 hunks)
🧰 Additional context used
🧠 Learnings (1)
📚 Learning: 2025-10-13T16:40:22.622Z
Learnt from: Hemil36
Repo: AOSSIE-Org/PictoPy PR: 548
File: backend/app/logging/setup_logging.py:224-243
Timestamp: 2025-10-13T16:40:22.622Z
Learning: In the PictoPy project's centralized logging system (backend/app/logging/setup_logging.py and sync-microservice/app/logging/setup_logging.py), stack traces should not be shown in logs. When rerouting logs through InterceptHandler, exc_info and stack_info should not be preserved.

Applied to files:

  • backend/app/logging/setup_logging.py
  • sync-microservice/app/logging/setup_logging.py
🧬 Code graph analysis (2)
backend/app/logging/setup_logging.py (1)
sync-microservice/app/logging/setup_logging.py (1)
  • InterceptHandler (220-277)
sync-microservice/app/logging/setup_logging.py (1)
backend/app/logging/setup_logging.py (1)
  • InterceptHandler (212-274)
⏰ Context from checks skipped due to timeout of 90000ms. You can increase the timeout in your CodeRabbit configuration to a maximum of 15 minutes (900000ms). (1)
  • GitHub Check: Backend Tests
🔇 Additional comments (3)
sync-microservice/app/logging/setup_logging.py (1)

270-277: Recursion prevention approach looks correct.

The strategy of dispatching directly to root handlers while skipping InterceptHandler instances effectively breaks the recursion loop. The identity check (handler is not self) combined with the type check provides robust protection.

backend/app/logging/setup_logging.py (1)

265-274: Recursion prevention implementation is sound.

The approach of routing directly to root handlers while skipping InterceptHandler instances correctly eliminates the infinite recursion. The silent exception handling prevents handler failures from crashing the application.

docs/backend/backend_python/openapi.json (1)

1120-1127: Schema wrapping change looks correct.

The allOf wrapper around the $ref is a standard OpenAPI pattern for adding metadata (like title and default) to a referenced schema. This is typically auto-generated by FastAPI/Pydantic and doesn't change the API behavior.

Confirm this file is auto-generated (e.g., via openapi.json export from FastAPI) and not manually edited, to ensure consistency with the actual API schema.

Copy link
Contributor

@coderabbitai coderabbitai bot left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Actionable comments posted: 2

🧹 Nitpick comments (1)
backend/app/logging/setup_logging.py (1)

300-302: Consider removing unused formatter configuration.

The formatter configured on the InterceptHandler (lines 300-302) is never used because emit() bypasses the handler's formatting pipeline by sending records directly to root logger handlers (lines 266-271). This code can be safely removed to improve clarity.

Apply this diff to remove the unused formatter setup:

     # Create an intercept handler with our component name
     intercept_handler = InterceptHandler(component_name)
 
-    # Make sure the handler uses our ColorFormatter
-    config = load_config()
-    component_config = config.get("components", {}).get(
-        component_name, {"prefix": component_name.upper(), "color": "white"}
-    )
-    level_colors = config.get("colors", {})
-    env_settings = config.get("environments", {}).get(
-        os.environ.get("ENV", config.get("default_environment", "development")), {}
-    )
-    use_colors = env_settings.get("colored_output", True)
-
-    fmt = "[%(component)s] | %(module)s | %(levelname)s | %(message)s"
-    formatter = ColorFormatter(fmt, component_config, level_colors, use_colors)
-    intercept_handler.setFormatter(formatter)
-
     # Configure Uvicorn loggers to use our handler
     for logger_name in ["uvicorn", "uvicorn.error", "uvicorn.access"]:
📜 Review details

Configuration used: defaults

Review profile: CHILL

Plan: Pro

📥 Commits

Reviewing files that changed from the base of the PR and between 176d758 and 26b8450.

📒 Files selected for processing (1)
  • backend/app/logging/setup_logging.py (1 hunks)
🧰 Additional context used
🧠 Learnings (1)
📚 Learning: 2025-10-13T16:40:22.622Z
Learnt from: Hemil36
Repo: AOSSIE-Org/PictoPy PR: 548
File: backend/app/logging/setup_logging.py:224-243
Timestamp: 2025-10-13T16:40:22.622Z
Learning: In the PictoPy project's centralized logging system (backend/app/logging/setup_logging.py and sync-microservice/app/logging/setup_logging.py), stack traces should not be shown in logs. When rerouting logs through InterceptHandler, exc_info and stack_info should not be preserved.

Applied to files:

  • backend/app/logging/setup_logging.py
🧬 Code graph analysis (1)
backend/app/logging/setup_logging.py (1)
sync-microservice/app/logging/setup_logging.py (1)
  • InterceptHandler (220-277)

@VasuS609 VasuS609 deleted the fix-logging-recursion branch January 27, 2026 18:33
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

backend bug Something isn't working

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants