langgenius/dify
1
0
Fork 0
mirror of https://github.com/langgenius/dify.git synced 2026-07-23 04:55:28 -04:00
Code Issues 775 Packages Projects Releases 10 Wiki Activity

[PR #30933] fix(dify): fix request log duplicates #33025

New Issue
Open
opened 2026-02-21 20:52:31 -05:00 by yindo · 0 comments
yindo commented 2026-02-21 20:52:31 -05:00
Owner
Copy Link
Copy Source

Original Pull Request: https://github.com/langgenius/dify/pull/30933

State: open
Merged: No

Fix: Prevent Duplicate Request Logging Handlers

🐛 Problem Description

The request logging extension (ext_request_logging.py) was registering duplicate signal handlers when init_app() was called multiple times, causing the same log entry to be printed multiple times for each HTTP request.

Steps to Reproduce

  1. Enable request logging by setting ENABLE_REQUEST_LOGGING=true
  2. Start the Dify API server
  3. Make any HTTP request to the API
  4. Observe the logs

Expected Behavior

Each HTTP request should produce:

  • One "Received Request" log entry (DEBUG level)
  • One access log line (INFO level)
  • One "Response" log entry (DEBUG level)

Actual Behavior

Each HTTP request produced duplicate log entries. The number of duplicates increased with each application reload/restart:

  • First run: 1x logs (normal)
  • After reload: 2x logs (duplicated)
  • After another reload: 3x logs (triplicated)

Example:

INFO - GET /api/workspaces 200 45.3 trace_id_123
INFO - GET /api/workspaces 200 45.3 trace_id_123
INFO - GET /api/workspaces 200 45.3 trace_id_123

Root Cause

The init_app() function connected Flask signal handlers without checking if they were already connected. Flask signals allow multiple connections to the same handler. If init_app() was called multiple times (e.g., during hot reload, testing, or application factory pattern), the handlers accumulated without being cleared.

✅ Solution

Added a guard mechanism to prevent duplicate initialization:

  1. Instance-level flag: Added _request_logging_initialized flag on the Flask app instance to track initialization state
  2. Early return: If the extension is already initialized, log a warning and return early
  3. Weak reference protection: Used weak=False when connecting handlers to prevent garbage collection issues

📝 Changes Made

Modified Files

  1. api/extensions/ext_request_logging.py

    • Added initialization guard with _request_logging_initialized flag
    • Added warning log when duplicate initialization is attempted
    • Changed signal connection to use weak=False for better reliability

  2. api/tests/unit_tests/extensions/test_ext_request_logging.py

    • Added 4 new test cases in TestDuplicateInitialization class:
      • test_multiple_init_app_calls_do_not_duplicate_logs: Verifies no log duplication
      • test_multiple_init_app_calls_with_mock_receivers: Verifies handlers aren't registered multiple times
      • test_init_app_sets_initialization_flag: Verifies flag is set correctly
      • test_init_app_respects_flag_on_subsequent_calls: Verifies warning is logged on re-initialization

🧪 Testing

Test Results

All tests pass successfully:

  • ✅ 4873 tests passed
  • ✅ 8 tests skipped (expected)
  • ✅ 0 failures
  • ✅ All existing tests continue to pass (no regressions)
  • ✅ New tests verify the fix works correctly

Test Coverage

The fix is covered by comprehensive unit tests that verify:

  • Multiple init_app() calls don't create duplicate handlers
  • Log entries are not duplicated
  • Warning is logged when re-initialization is attempted
  • Flag is properly set and respected

🔍 Code Review Checklist

  • Code follows project style guidelines
  • All tests pass locally
  • No breaking changes introduced
  • Backward compatible
  • Documentation updated (if needed)
  • Type hints maintained
  • Error handling preserved

📊 Impact

  • Type: Bug fix
  • Severity: Medium (affects logging output, not functionality)
  • Breaking Changes: None
  • Backward Compatibility: ✅ Fully compatible

🔗 Related Issues

Fixes duplicate request logging entries that occur when the application is reloaded or init_app() is called multiple times.

📸 Before/After

Before:

def init_app(app: Flask):
    if not dify_config.ENABLE_REQUEST_LOGGING:
        return
    request_started.connect(_log_request_started, app)
    request_finished.connect(_log_request_finished, app)

After:

def init_app(app: Flask):
    if not dify_config.ENABLE_REQUEST_LOGGING:
        return

    # Prevent duplicate initialization
    if hasattr(app, "_request_logging_initialized"):
        logger.warning("Request logging extension already initialized for this app instance")
        return

    request_started.connect(_log_request_started, app, weak=False)
    request_finished.connect(_log_request_finished, app, weak=False)

    app._request_logging_initialized = True

✨ Benefits

  1. Eliminates log duplication: Each request now produces exactly one set of log entries
  2. Better debugging: Warning log helps identify when duplicate initialization is attempted
  3. More robust: weak=False prevents handler removal by garbage collector
  4. Test coverage: Comprehensive tests ensure the fix works correctly

Important

  1. Make sure you have read our contribution guidelines
  2. Ensure there is an associated issue and you have been assigned to it
  3. Use the correct syntax to link this PR: Fixes #<issue number>.

Summary

Screenshots

Before After
... ...

Checklist

  • This change requires a documentation update, included: Dify Document
  • I understand that this PR may be closed in case there was no previous discussion or issues. (This doesn't apply to typos!)
  • I've added a test for each change that was introduced, and I tried as much as possible to make a single atomic change.
  • I've updated the documentation accordingly.
  • I ran make lint and make type-check (backend) and cd web && npx lint-staged (frontend) to appease the lint gods
**Original Pull Request:** https://github.com/langgenius/dify/pull/30933 **State:** open **Merged:** No --- # Fix: Prevent Duplicate Request Logging Handlers ## 🐛 Problem Description The request logging extension (`ext_request_logging.py`) was registering duplicate signal handlers when `init_app()` was called multiple times, causing the same log entry to be printed multiple times for each HTTP request. ### Steps to Reproduce 1. Enable request logging by setting `ENABLE_REQUEST_LOGGING=true` 2. Start the Dify API server 3. Make any HTTP request to the API 4. Observe the logs ### Expected Behavior Each HTTP request should produce: - One "Received Request" log entry (DEBUG level) - One access log line (INFO level) - One "Response" log entry (DEBUG level) ### Actual Behavior Each HTTP request produced duplicate log entries. The number of duplicates increased with each application reload/restart: - First run: 1x logs (normal) - After reload: 2x logs (duplicated) - After another reload: 3x logs (triplicated) **Example:** ``` INFO - GET /api/workspaces 200 45.3 trace_id_123 INFO - GET /api/workspaces 200 45.3 trace_id_123 INFO - GET /api/workspaces 200 45.3 trace_id_123 ``` ### Root Cause The `init_app()` function connected Flask signal handlers without checking if they were already connected. Flask signals allow multiple connections to the same handler. If `init_app()` was called multiple times (e.g., during hot reload, testing, or application factory pattern), the handlers accumulated without being cleared. ## ✅ Solution Added a guard mechanism to prevent duplicate initialization: 1. **Instance-level flag**: Added `_request_logging_initialized` flag on the Flask app instance to track initialization state 2. **Early return**: If the extension is already initialized, log a warning and return early 3. **Weak reference protection**: Used `weak=False` when connecting handlers to prevent garbage collection issues ## 📝 Changes Made ### Modified Files 1. **`api/extensions/ext_request_logging.py`** - Added initialization guard with `_request_logging_initialized` flag - Added warning log when duplicate initialization is attempted - Changed signal connection to use `weak=False` for better reliability 2. **`api/tests/unit_tests/extensions/test_ext_request_logging.py`** - Added 4 new test cases in `TestDuplicateInitialization` class: - `test_multiple_init_app_calls_do_not_duplicate_logs`: Verifies no log duplication - `test_multiple_init_app_calls_with_mock_receivers`: Verifies handlers aren't registered multiple times - `test_init_app_sets_initialization_flag`: Verifies flag is set correctly - `test_init_app_respects_flag_on_subsequent_calls`: Verifies warning is logged on re-initialization ## 🧪 Testing ### Test Results All tests pass successfully: - ✅ **4873 tests passed** - ✅ **8 tests skipped** (expected) - ✅ **0 failures** - ✅ All existing tests continue to pass (no regressions) - ✅ New tests verify the fix works correctly ### Test Coverage The fix is covered by comprehensive unit tests that verify: - Multiple `init_app()` calls don't create duplicate handlers - Log entries are not duplicated - Warning is logged when re-initialization is attempted - Flag is properly set and respected ## 🔍 Code Review Checklist - [x] Code follows project style guidelines - [x] All tests pass locally - [x] No breaking changes introduced - [x] Backward compatible - [x] Documentation updated (if needed) - [x] Type hints maintained - [x] Error handling preserved ## 📊 Impact - **Type**: Bug fix - **Severity**: Medium (affects logging output, not functionality) - **Breaking Changes**: None - **Backward Compatibility**: ✅ Fully compatible ## 🔗 Related Issues Fixes duplicate request logging entries that occur when the application is reloaded or `init_app()` is called multiple times. ## 📸 Before/After **Before:** ```python def init_app(app: Flask): if not dify_config.ENABLE_REQUEST_LOGGING: return request_started.connect(_log_request_started, app) request_finished.connect(_log_request_finished, app) ``` **After:** ```python def init_app(app: Flask): if not dify_config.ENABLE_REQUEST_LOGGING: return # Prevent duplicate initialization if hasattr(app, "_request_logging_initialized"): logger.warning("Request logging extension already initialized for this app instance") return request_started.connect(_log_request_started, app, weak=False) request_finished.connect(_log_request_finished, app, weak=False) app._request_logging_initialized = True ``` ## ✨ Benefits 1. **Eliminates log duplication**: Each request now produces exactly one set of log entries 2. **Better debugging**: Warning log helps identify when duplicate initialization is attempted 3. **More robust**: `weak=False` prevents handler removal by garbage collector 4. **Test coverage**: Comprehensive tests ensure the fix works correctly > [!IMPORTANT] > > 1. Make sure you have read our [contribution guidelines](https://github.com/langgenius/dify/blob/main/CONTRIBUTING.md) > 1. Ensure there is an associated issue and you have been assigned to it > 1. Use the correct syntax to link this PR: `Fixes #<issue number>`. ## Summary <!-- Please include a summary of the change and which issue is fixed. Please also include relevant motivation and context. List any dependencies that are required for this change. --> ## Screenshots | Before | After | |--------|-------| | ... | ... | ## Checklist - [x] This change requires a documentation update, included: [Dify Document](https://github.com/langgenius/dify-docs) - [x] I understand that this PR may be closed in case there was no previous discussion or issues. (This doesn't apply to typos!) - [x] I've added a test for each change that was introduced, and I tried as much as possible to make a single atomic change. - [x] I've updated the documentation accordingly. - [x] I ran `make lint` and `make type-check` (backend) and `cd web && npx lint-staged` (frontend) to appease the lint gods
yindo added the pull-request label 2026-02-21 20:52:31 -05:00
Sign in to join this conversation.
No Branch/Tag Specified
Branches Tags
Labels
Clear labels
Knowledge Pipeline
Proposal
WIP
cloud
dependencies
feat:webapp
good first issue
outdated
performance
pull-request
Mirrored from GitHub Pull Request
 python:uv
refactor
size:L
stale
status: accepting prs
status: blocked
status: in discussion
stt & tts
vulnerablity
web
wont-fix
🌊 feat:workflow
🌚 invalid
🐞 bug
👻 feat:rag
💪 enhancement
📚 documentation
🔨 feat:tools
🙋‍♂️ question
🙏 help wanted
🤔 cant-reproduce
🤖 feat:agent
No Label pull-request
Milestone
No items
No Milestone
Projects
Clear projects
No project
Assignees
Clear assignees
yindo
No Assignees
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: langgenius/dify#33025
Delete Branch "%!s()"

Deleting a branch is permanent. Although the deleted branch may continue to exist for a short time before it actually gets removed, it CANNOT be undone in most cases. Continue?