-
Notifications
You must be signed in to change notification settings - Fork 24
feat(logging): fixes issue 58: Implement Centralized Logging and Request/Response Middleware #75
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Conversation
…and replace print statements with logger calls, also added request/response logging middleware and updated backend md file.
WalkthroughThis update removes all print statements from the backend, replacing them with a structured logging system configured in Changes
Sequence Diagram(s)sequenceDiagram
participant Client
participant FastAPI App
participant RequestResponseLoggingMiddleware
participant Endpoint Handler
participant Logger
Client->>FastAPI App: Sends HTTP Request
FastAPI App->>RequestResponseLoggingMiddleware: Passes Request
RequestResponseLoggingMiddleware->>Logger: Log request method and URL
RequestResponseLoggingMiddleware->>Endpoint Handler: Process request
Endpoint Handler-->>RequestResponseLoggingMiddleware: Returns Response
RequestResponseLoggingMiddleware->>Logger: Log response status and timing
RequestResponseLoggingMiddleware-->>FastAPI App: Returns Response
FastAPI App-->>Client: Sends HTTP Response
Estimated code review effort🎯 3 (Moderate) | ⏱️ ~15 minutes Suggested labels
Poem
Note ⚡️ Unit Test Generation is now available in beta!Learn more here, or try it out under "Finishing Touches" below. 📜 Recent review detailsConfiguration used: CodeRabbit UI 📒 Files selected for processing (2)
🚧 Files skipped from review as they are similar to previous changes (2)
✨ Finishing Touches
🧪 Generate unit tests
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. 🪧 TipsChatThere are 3 ways to chat with CodeRabbit:
SupportNeed help? Create a ticket on our support page for assistance with any issues or questions. Note: Be mindful of the bot's finite context window. It's strongly recommended to break down tasks such as reading entire modules into smaller chunks. For a focused discussion, use review comments to chat about specific files and their changes, instead of using the PR comments. CodeRabbit Commands (Invoked using PR comments)
Other keywords and placeholders
CodeRabbit Configuration File (
|
✅ Deploy Preview for splitwizer canceled.
|
|
Hi @Devasy23 @VrajPatel11 |
There was a problem hiding this 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 (4)
backend/app/config.py (1)
46-65: Consider enhancing the logging configuration for production readiness.The basic logging configuration is functional but could benefit from production-oriented improvements:
LOGGING_CONFIG = { "version": 1, "disable_existing_loggers": False, "formatters": { "default": { - "format": "%(asctime)s - %(levelname)s - %(message)s", + "format": "%(asctime)s - %(name)s - %(levelname)s - %(funcName)s:%(lineno)d - %(message)s", }, + "json": { + "()": "pythonjsonlogger.jsonlogger.JsonFormatter", + "format": "%(asctime)s %(name)s %(levelname)s %(funcName)s %(lineno)d %(message)s" + } }, "handlers": { "console": { "class": "logging.StreamHandler", "formatter": "default", }, + "file": { + "class": "logging.handlers.RotatingFileHandler", + "filename": "logs/splitwiser.log", + "maxBytes": 10485760, + "backupCount": 5, + "formatter": "json", + }, }, + "loggers": { + "splitwiser": { + "level": "INFO", + "handlers": ["console", "file"], + "propagate": False, + } + }, "root": { - "level": "INFO", + "level": "WARNING", "handlers": ["console"], }, }Consider adding:
- More detailed formatter with function names and line numbers
- File logging with rotation for persistent logs
- JSON formatting for structured logging
- Separate logger configuration for the application
backend/generate_secret.py (1)
20-24: Consider improving the logging format for script output.The logger usage is correct, but the formatting could be more user-friendly for a utility script:
if __name__ == "__main__": secret = generate_jwt_secret() - logger.info("Generated JWT Secret Key:") - logger.info(secret) - logger.info("\nCopy this key to your .env file:") - logger.info(f"SECRET_KEY={secret}") + logger.info("Generated JWT Secret Key") + logger.info(f"Secret: {secret}") + logger.info("Copy this key to your .env file:") + logger.info(f"SECRET_KEY={secret}")The newline character (
\n) in the log message might not render as expected in structured logging systems. Each piece of information should be in separate log entries or formatted differently.backend/app/database.py (1)
18-18: Enhance database connection logging with more context.The logging is good but could provide more operational context:
- logger.info("Connected to MongoDB") + logger.info(f"Connected to MongoDB at {settings.mongodb_url} using database '{settings.database_name}'")This provides more context for debugging and monitoring, especially useful when multiple database connections or environments are involved.
backend/README.md (1)
54-59: Enhance logging documentation with practical examples and configuration options.The logging documentation is a good start but could be more comprehensive:
## Logging Configuration -The logging configuration is defined in the `app/config.py` file. It includes: + +The application uses a centralized logging system configured in `app/config.py`. + +### Configuration Details - **Log Levels**: `DEBUG`, `INFO`, `WARNING`, `ERROR`, `CRITICAL` - **Format**: Logs include timestamps, log levels, and messages. - **Handlers**: Logs are output to the console. + +### Usage Examples +```python +from app.config import logger + +# Info logging +logger.info("User successfully authenticated") + +# Error logging with context +logger.error(f"Database connection failed: {error_message}") + +# Warning for non-critical issues +logger.warning("Rate limit approaching for user") +``` + +### Request/Response Logging +The application automatically logs all HTTP requests and responses through middleware, including: +- Request method and path +- Response status codes +- Processing time + +### Environment Configuration +Log levels can be adjusted by modifying the `LOGGING_CONFIG` in `app/config.py`. For production deployments, consider: +- Setting log level to `WARNING` or `ERROR` to reduce verbosity +- Adding file handlers for persistent logging +- Using structured JSON logging for better parsingThis provides developers with practical usage examples and guidance for different environments.
📜 Review details
Configuration used: CodeRabbit UI
Review profile: CHILL
Plan: Pro
📒 Files selected for processing (8)
backend/README.md(1 hunks)backend/app/auth/service.py(3 hunks)backend/app/config.py(2 hunks)backend/app/database.py(3 hunks)backend/app/expenses/routes.py(2 hunks)backend/app/expenses/service.py(3 hunks)backend/generate_secret.py(2 hunks)backend/main.py(3 hunks)
🧰 Additional context used
🧬 Code Graph Analysis (1)
backend/main.py (2)
backend/app/config.py (1)
RequestResponseLoggingMiddleware(70-83)backend/app/database.py (2)
connect_to_mongo(10-18)close_mongo_connection(20-29)
🔇 Additional comments (18)
backend/app/config.py (2)
4-8: LGTM! Clean import organization for logging functionality.The imports are well-organized and include all necessary modules for the centralized logging implementation and middleware.
67-68: LGTM! Proper logger initialization.The dictConfig application and logger instantiation follow best practices.
backend/generate_secret.py (1)
3-3: LGTM! Proper logger import.The import statement correctly brings in the centralized logger from the config module.
backend/app/database.py (2)
2-2: LGTM! Proper logger import integration.The import statement correctly includes the logger alongside the existing settings import.
29-29: LGTM! Appropriate logging for disconnection event.The disconnection logging is correctly placed and provides useful operational information.
backend/app/auth/service.py (3)
11-11: LGTM! Proper logger import integration.The import statement correctly includes the logger alongside existing imports from the config module.
42-42: LGTM! Appropriate logging for Firebase initialization.The logging provides useful information about Firebase initialization success with different credential sources.
Also applies to: 49-49
51-51: LGTM! Appropriate warning level for missing Firebase configuration.Using
logger.warningis the correct level for a missing but non-critical service configuration.backend/app/expenses/service.py (3)
5-5: LGTM: Correct logger import for centralized logging.The import follows the centralized logging pattern established in the PR.
345-345: LGTM: Proper error logging with traceback.Good use of
logger.errorwithexc_info=Trueto capture both the error message and traceback information when settlement recalculation fails.
358-358: LGTM: Consistent error logging pattern.Proper use of
logger.errorwithexc_info=Truefor capturing unexpected exceptions during expense updates.backend/app/expenses/routes.py (2)
11-11: LGTM: Correct logger import for routes module.Consistent with the centralized logging approach across the backend.
87-87: LGTM: Proper error logging in route handler.Good use of
logger.errorwithexc_info=Trueto capture both the error message and traceback before raising the HTTP exception.backend/main.py (5)
10-10: LGTM: Correct imports for logging and middleware.Proper imports for both the centralized logger and the new request/response logging middleware.
15-17: LGTM: Improved lifecycle logging.Good replacement of print statements with
logger.infofor MongoDB connection lifecycle events. The log messages are clear and use appropriate log levels.Also applies to: 20-22
38-38: LGTM: Appropriate CORS configuration logging.Good use of different log levels -
debugfor development-specific information andinfofor general configuration. This helps with debugging CORS issues.Also applies to: 46-46
48-48: LGTM: Correct middleware integration.The RequestResponseLoggingMiddleware is properly added before CORS middleware, which ensures all requests are logged with their processing times and status codes.
75-76: LGTM: Consistent OPTIONS request logging.Good replacement of print statements with
logger.infofor OPTIONS request debugging. The logged information (path and origin) is useful for CORS troubleshooting.
backend/app/auth/service.py
Outdated
| logger.info(f"Password reset token for {email}: {reset_token}") | ||
| logger.info(f"Reset link: https://yourapp.com/reset-password?token={reset_token}") | ||
|
|
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Security concern: Logging sensitive password reset tokens.
Logging password reset tokens poses a security risk as they could be exposed in log files:
# For development/free tier: just log the reset token
# In production, you would send this via email
- logger.info(f"Password reset token for {email}: {reset_token}")
- logger.info(f"Reset link: https://yourapp.com/reset-password?token={reset_token}")
+ if settings.debug:
+ logger.info(f"Password reset requested for {email}")
+ logger.info(f"Reset token (DEBUG ONLY): {reset_token}")
+ logger.info(f"Reset link (DEBUG ONLY): https://yourapp.com/reset-password?token={reset_token}")
+ else:
+ logger.info(f"Password reset requested for {email}")Security concerns:
- Password reset tokens are sensitive credentials that shouldn't be logged in production
- Log files could be accessed by unauthorized parties
- Tokens in logs could be used maliciously if logs are compromised
The fix ensures tokens are only logged in debug mode and adds clear warnings about the sensitivity of the information.
📝 Committable suggestion
‼️ IMPORTANT
Carefully review the code before committing. Ensure that it accurately replaces the highlighted code, contains no missing lines, and has no issues with indentation. Thoroughly test & benchmark the code to ensure it meets the requirements.
| logger.info(f"Password reset token for {email}: {reset_token}") | |
| logger.info(f"Reset link: https://yourapp.com/reset-password?token={reset_token}") | |
| # For development/free tier: just log the reset token | |
| # In production, you would send this via email | |
| if settings.debug: | |
| logger.info(f"Password reset requested for {email}") | |
| logger.info(f"Reset token (DEBUG ONLY): {reset_token}") | |
| logger.info(f"Reset link (DEBUG ONLY): https://yourapp.com/reset-password?token={reset_token}") | |
| else: | |
| logger.info(f"Password reset requested for {email}") |
🤖 Prompt for AI Agents
In backend/app/auth/service.py around lines 338 to 340, the code logs password
reset tokens which is a security risk. Modify the logging to only output the
reset token and reset link when the logger is in debug mode, and add a warning
comment about the sensitivity of this information. Remove or avoid logging these
tokens in info or higher log levels to prevent exposure in production logs.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
the actual text content of the logger is same as that when there were print statements. in this file
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
@AneeshAhuja31 You're absolutely right that the logger content is identical to the previous print statements. My security concern applies to both the original print statements and the current logging - the issue isn't that the content changed, but that sensitive password reset tokens are being output where they could be captured.
The key difference is that while print statements go to stdout (which might not be persisted), logger output is typically:
- Saved to log files that persist on disk
- Often centrally aggregated in production systems
- More likely to be accessed by multiple team members
- Potentially backed up or retained longer
I understand from the comment that this is intended for "development/free tier" usage, but the code doesn't currently differentiate between development and production environments when logging these tokens. The security risk remains the same whether it was print() or logger.info().
If this logging is intentional for development purposes, consider using a debug-only approach to ensure tokens aren't logged in production environments.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
@AneeshAhuja31 I agree can you truncate the token while printing in debug log
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Seems like the humans are having a chat. I'll hop back into my burrow for now. If you need me again, just tag @coderabbitai in a new comment, and I'll come hopping out!
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
@Devasy23 ok will do
|
@AneeshAhuja31 Great job so far, just one thing can you please add tests for the logger file you added such that the coverage doesn't drop after this PR |
Devasy
left a comment
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
You can truncate the log statements with an access token
…t and diff levels. updated gitignore to ignore .coverage files
There was a problem hiding this 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
♻️ Duplicate comments (1)
backend/app/config.py (1)
71-84: Fix redundant logger instantiation and enhance request logging.The middleware implementation still has the same issues identified in the previous review that need to be addressed.
🧹 Nitpick comments (2)
backend/tests/logger/test_logger.py (2)
1-10: Consider isolating logging configuration in tests.Applying
dictConfig(LOGGING_CONFIG)at the module level could interfere with other tests since logging configuration is global.-dictConfig(LOGGING_CONFIG) +@pytest.fixture(autouse=True) +def setup_logging(): + dictConfig(LOGGING_CONFIG)Consider using a fixture to ensure proper test isolation.
11-13: Clarify logger level test.The test checks
logger.root.levelbut should verify the specific logger's effective level.def test_logger_init(): assert logger.name == "splitwiser" - assert logger.root.level == logging.INFO + assert logger.getEffectiveLevel() == logging.INFOThis better reflects what level the "splitwiser" logger will actually use.
📜 Review details
Configuration used: CodeRabbit UI
Review profile: CHILL
Plan: Pro
📒 Files selected for processing (4)
.gitignore(1 hunks)backend/app/auth/service.py(3 hunks)backend/app/config.py(2 hunks)backend/tests/logger/test_logger.py(1 hunks)
✅ Files skipped from review due to trivial changes (2)
- .gitignore
- backend/app/auth/service.py
🧰 Additional context used
📓 Path-based instructions (3)
backend/**/*.py
📄 CodeRabbit Inference Engine (.github/copilot-instructions.md)
Backend code must be implemented using FastAPI with Python 3.9+ and organized under the /backend/ directory.
Files:
backend/app/config.pybackend/tests/logger/test_logger.py
backend/app/config.py
📄 CodeRabbit Inference Engine (.github/copilot-instructions.md)
Backend configuration settings must be managed in backend/app/config.py.
Files:
backend/app/config.py
backend/tests/**/*.py
📄 CodeRabbit Inference Engine (.github/copilot-instructions.md)
Backend tests must be placed in the /backend/tests/ directory and run using pytest.
Files:
backend/tests/logger/test_logger.py
🧠 Learnings (2)
📓 Common learnings
Learnt from: CR
PR: Devasy23/splitwiser#0
File: .github/copilot-instructions.md:0-0
Timestamp: 2025-07-26T09:41:01.290Z
Learning: Applies to backend/app/config.py : Backend configuration settings must be managed in backend/app/config.py.
Learnt from: CR
PR: Devasy23/splitwiser#0
File: .github/copilot-instructions.md:0-0
Timestamp: 2025-07-26T09:41:01.290Z
Learning: Applies to backend/app/{auth,user,groups,expenses}/**/*.py : Backend services should be modular, with authentication and user registration in app/auth/, user profile management in app/user/, group management in app/groups/, and expense tracking in app/expenses/.
backend/app/config.py (1)
Learnt from: CR
PR: Devasy23/splitwiser#0
File: .github/copilot-instructions.md:0-0
Timestamp: 2025-07-26T09:41:01.290Z
Learning: Applies to backend/app/config.py : Backend configuration settings must be managed in backend/app/config.py.
🧬 Code Graph Analysis (1)
backend/tests/logger/test_logger.py (2)
backend/app/config.py (1)
RequestResponseLoggingMiddleware(71-84)backend/tests/user/test_user_routes.py (1)
client(13-15)
🔇 Additional comments (2)
backend/app/config.py (1)
4-8: LGTM: Clean import statements for logging functionality.The imports are well-organized and include all necessary modules for the centralized logging system and middleware implementation.
backend/tests/logger/test_logger.py (1)
35-52: Good test coverage for middleware functionality.The test comprehensively validates the middleware's logging behavior. However, once the middleware implementation is fixed (as noted in the duplicate comment), this test will need to be updated to match the expected behavior.
Consider adding edge case tests for error scenarios when you update the middleware.
| def test_logger_logs_info(caplog): | ||
| with caplog.at_level(logging.INFO): | ||
| logger.info("Test info message") | ||
| assert "Test info message" in caplog.text | ||
|
|
||
| def test_logger_logs_debug(caplog): | ||
| with caplog.at_level(logging.DEBUG): | ||
| logging.debug("Test debug message") | ||
| assert "Test debug message" in caplog.text | ||
|
|
||
| def test_logger_logs_error(caplog): | ||
| with caplog.at_level(logging.ERROR): | ||
| logger.error("Test error message") | ||
| assert "Test error message" in caplog.text | ||
|
|
||
| def test_logger_logs_warning(caplog): | ||
| with caplog.at_level(logging.WARNING): | ||
| logging.warning("Test warning message") | ||
| assert "Test warning message" in caplog.text |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
🛠️ Refactor suggestion
Fix inconsistent logger usage in tests.
The tests inconsistently use the logger instance vs the logging module directly.
def test_logger_logs_debug(caplog):
with caplog.at_level(logging.DEBUG):
- logging.debug("Test debug message")
+ logger.debug("Test debug message")
assert "Test debug message" in caplog.text
def test_logger_logs_warning(caplog):
with caplog.at_level(logging.WARNING):
- logging.warning("Test warning message")
+ logger.warning("Test warning message")
assert "Test warning message" in caplog.textUse the imported logger instance consistently to test the specific logger configuration.
📝 Committable suggestion
‼️ IMPORTANT
Carefully review the code before committing. Ensure that it accurately replaces the highlighted code, contains no missing lines, and has no issues with indentation. Thoroughly test & benchmark the code to ensure it meets the requirements.
| def test_logger_logs_info(caplog): | |
| with caplog.at_level(logging.INFO): | |
| logger.info("Test info message") | |
| assert "Test info message" in caplog.text | |
| def test_logger_logs_debug(caplog): | |
| with caplog.at_level(logging.DEBUG): | |
| logging.debug("Test debug message") | |
| assert "Test debug message" in caplog.text | |
| def test_logger_logs_error(caplog): | |
| with caplog.at_level(logging.ERROR): | |
| logger.error("Test error message") | |
| assert "Test error message" in caplog.text | |
| def test_logger_logs_warning(caplog): | |
| with caplog.at_level(logging.WARNING): | |
| logging.warning("Test warning message") | |
| assert "Test warning message" in caplog.text | |
| def test_logger_logs_info(caplog): | |
| with caplog.at_level(logging.INFO): | |
| logger.info("Test info message") | |
| assert "Test info message" in caplog.text | |
| def test_logger_logs_debug(caplog): | |
| with caplog.at_level(logging.DEBUG): | |
| logger.debug("Test debug message") | |
| assert "Test debug message" in caplog.text | |
| def test_logger_logs_error(caplog): | |
| with caplog.at_level(logging.ERROR): | |
| logger.error("Test error message") | |
| assert "Test error message" in caplog.text | |
| def test_logger_logs_warning(caplog): | |
| with caplog.at_level(logging.WARNING): | |
| logger.warning("Test warning message") | |
| assert "Test warning message" in caplog.text |
🤖 Prompt for AI Agents
In backend/tests/logger/test_logger.py between lines 15 and 33, the tests
inconsistently use the logger instance and the logging module directly. To fix
this, replace all calls to logging.debug and logging.warning with calls to the
imported logger instance (logger.debug and logger.warning) to ensure consistent
usage of the specific logger configuration throughout the tests.
|
Hi @Devasy23, I've made the requested changes.
|
…ogger initialization tests
Devasy
left a comment
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
LGTM
Fixes #58
This pr adds centralized logging system and request/response logging middleware to improve observability and debugging in the backend.
Files updated:
Summary by CodeRabbit
New Features
Documentation
Refactor
Tests
Chores
.gitignoreto exclude coverage report files.