diff --git a/.github/dependabot.yml b/.github/dependabot.yml new file mode 100644 index 0000000..82f653c --- /dev/null +++ b/.github/dependabot.yml @@ -0,0 +1,24 @@ +version: 2 +updates: + - package-ecosystem: "uv" + directory: "/" + schedule: + interval: "weekly" + allow: + - dependency-type: "development" + commit-message: + prefix: "chore" + include: "scope" + labels: + - "dependencies" + open-pull-requests-limit: 5 + + - package-ecosystem: "github-actions" + directory: "/" + schedule: + interval: "monthly" + commit-message: + prefix: "chore" + include: "scope" + labels: + - "ci" \ No newline at end of file diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index bbcb3b3..3303a12 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -57,11 +57,10 @@ jobs: run: uv sync --group test - name: Run unit tests - run: uv run pytest --cov --junitxml=junit.xml -o junit_family=legacy + run: uv run pytest --cov -v --cov-report=term --cov-report=xml - name: Upload test results to Codecov - if: ${{ !cancelled() }} - uses: codecov/test-results-action@v1 + uses: codecov/codecov-action@v5 with: token: ${{ secrets.CODECOV_TOKEN }} @@ -106,3 +105,27 @@ jobs: export UV_PUBLISH_TOKEN=${{ secrets.UV_PUBLISH_TOKEN }} uv build uv publish + + pages: + name: "Publish Documentation to GitHub Pages" + if: github.ref == 'refs/heads/main' + needs: release + + runs-on: ubuntu-latest + container: + image: ghcr.io/astral-sh/uv:0.6-python3.11-bookworm + + steps: + - uses: actions/checkout@v4 + + - name: Install docs dependencies + run: uv sync --group docs + + - name: Build documentation + run: uv run sphinx-build -b html docs/source public + + - name: Publish to GitHub Pages + uses: peaceiris/actions-gh-pages@v4 + with: + github_token: ${{ secrets.GITHUB_TOKEN }} + publish_dir: public diff --git a/CODE_OF_CONDUCT.md b/CODE_OF_CONDUCT.md new file mode 100644 index 0000000..39488a1 --- /dev/null +++ b/CODE_OF_CONDUCT.md @@ -0,0 +1,42 @@ +# Contributor Covenant Code of Conduct + +## ⭐ Our Pledge + +We as members, contributors, and leaders pledge to make participation in our project and community a harassment-free experience for everyone, regardless of age, body size, disability, ethnicity, gender identity and expression, level of experience, education, socio-economic status, nationality, personal appearance, race, religion, or sexual identity and orientation. + +We pledge to act and interact in ways that contribute to an open, welcoming, diverse, inclusive, and healthy community. + +--- + +## ⭐ Our Standards + +Examples of behavior that contributes to a positive environment: +- Using welcoming and inclusive language. +- Being respectful of differing viewpoints and experiences. +- Accepting constructive criticism gracefully. +- Showing empathy toward other community members. + +Examples of unacceptable behavior: +- The use of sexualized language or imagery and unwelcome sexual attention. +- Trolling, insulting or derogatory comments, and personal or political attacks. +- Public or private harassment. +- Publishing others' private information (e.g. physical or electronic address) without explicit permission. +- Other conduct which could reasonably be considered inappropriate. + +--- + +## ⭐ Enforcement Responsibilities + +Project maintainers are responsible for clarifying and enforcing standards of acceptable behavior and will take appropriate corrective action in response to any instances of unacceptable behavior. + +--- + +## ⭐ Scope + +This Code of Conduct applies within all project spaces, including issues, pull requests, and all communication channels (e.g. discussions, Slack, etc.). + +--- + +## ⭐ Attribution + +This Code of Conduct is adapted from the [Contributor Covenant](https://www.contributor-covenant.org), version 2.1. \ No newline at end of file diff --git a/CONTRIBUTING.md b/CONTRIBUTING.md new file mode 100644 index 0000000..d74aecf --- /dev/null +++ b/CONTRIBUTING.md @@ -0,0 +1,277 @@ +# Contributing to LogStructor + +Thank you for your interest in contributing to LogStructor! We welcome contributions from the community and are excited to see what you'll bring to the project. + +## Getting Started + +### Prerequisites + +- Python 3.11 or higher +- [uv](https://docs.astral.sh/uv/) for dependency management (recommended) +- Git + +### Setting Up Your Development Environment + +1. **Fork and clone the repository:** + ```bash + git clone https://github.com/your-username/logstructor.git + cd logstructor + ``` + +2. **Install dependencies using uv:** + ```bash + uv sync --all-groups + ``` + + Or if you prefer pip: + ```bash + pip install -e ".[test,linting,docs]" + ``` + +3. **Verify your setup:** + ```bash + uv run pytest + uv run ruff check + uv run mypy logstructor + ``` + +## Development Workflow + +### Code Style and Quality + +We maintain high code quality standards using automated tools: + +- **Ruff** for linting and formatting +- **MyPy** for type checking +- **Pytest** for testing + +Before submitting any changes, ensure your code passes all checks: + +```bash +# Format code +uv run ruff format + +# Check linting +uv run ruff check + +# Type checking +uv run mypy logstructor + +# Run tests +uv run pytest + +# Run tests with coverage +uv run pytest --cov=logstructor --cov-report=html +``` + +### Running Tests + +We have comprehensive test coverage. Run the full test suite: + +```bash +# All tests +uv run pytest + +# Specific test file +uv run pytest tests/test_logger.py + +# With coverage report +uv run pytest --cov=logstructor --cov-report=term-missing + +# Async tests only +uv run pytest -k "async" +``` + +### Documentation + +Documentation is built with Sphinx and hosted as part of the project: + +```bash +# Build documentation +cd docs +uv run sphinx-build -b html source build + +# Serve locally (if you have a simple HTTP server) +cd build && python -m http.server 8000 +``` + +## Contributing Guidelines + +### Types of Contributions + +We welcome several types of contributions: + +- **Bug fixes** - Fix issues in existing functionality +- **Feature enhancements** - Improve existing features +- **New features** - Add new functionality (please discuss first) +- **Documentation** - Improve docs, examples, or tutorials +- **Tests** - Add or improve test coverage +- **Performance** - Optimize existing code + +### Before You Start + +For significant changes, please: + +1. **Open an issue** to discuss your proposed changes +2. **Check existing issues** to avoid duplicate work +3. **Review the roadmap** to align with project direction + +### Making Changes + +1. **Create a feature branch:** + ```bash + git checkout -b feature/your-feature-name + ``` + +2. **Make your changes** following our coding standards + +3. **Add tests** for any new functionality + +4. **Update documentation** if needed + +5. **Ensure all checks pass:** + ```bash + uv run ruff check + uv run mypy logstructor + uv run pytest + ``` + +### Commit Messages + +We use conventional commits for automated changelog generation: + +``` +feat: add support for custom timestamp formats +fix: resolve context isolation issue in async functions +docs: improve context management examples +test: add tests for thread safety +refactor: simplify formatter initialization +``` + +Types: `feat`, `fix`, `docs`, `test`, `refactor`, `perf`, `ci`, `chore` + +### Pull Request Process + +1. **Ensure your branch is up to date:** + ```bash + git checkout main + git pull upstream main + git checkout your-branch + git rebase main + ``` + +2. **Create a pull request** with: + - Clear title and description + - Reference to related issues + - Summary of changes made + - Any breaking changes noted + +3. **Respond to feedback** promptly and make requested changes + +4. **Ensure CI passes** - all automated checks must pass + +## Code Standards + +### Python Code Style + +- Follow PEP 8 (enforced by Ruff) +- Use type hints for all public APIs +- Write comprehensive docstrings with examples +- Keep functions focused and testable +- Prefer composition over inheritance + +### Example of Good Code Style + +```python +def bind_context(**kwargs: Any) -> None: + """ + Bind key-value pairs to the current context's logging context. + + These fields will be automatically included in all subsequent log entries + within the current context until cleared or overwritten. + + Args: + **kwargs: Key-value pairs to bind to the context + + Examples: + Basic usage: + >>> bind_context(request_id="req-123", user_id=456) + >>> logger.info("Processing request") # Will include request_id and user_id + + Web application example: + >>> bind_context(request_id=request.id, user_id=request.user.id) + >>> logger.info("User login attempt") # Automatically includes context + """ + current_context = _context_data.get().copy() + current_context.update(kwargs) + _context_data.set(current_context) +``` + +### Testing Standards + +- Write tests for all new functionality +- Aim for high test coverage (>90%) +- Include both positive and negative test cases +- Test async functionality where applicable +- Use descriptive test names + +```python +def test_bind_context_overwrites_existing(): + """Test that bind_context overwrites existing keys.""" + bind_context(user_id=123) + bind_context(user_id=456) # Should overwrite + + context = get_context() + assert context["user_id"] == 456 +``` + +## Project Structure + +``` +logstructor/ +├── logstructor/ # Main package +│ ├── __init__.py # Public API +│ ├── logger.py # StructLogger implementation +│ ├── formatter.py # JSON formatter +│ ├── context.py # Context management +│ ├── config.py # Configuration utilities +│ └── exceptions.py # Custom exceptions +├── tests/ # Test suite +├── docs/ # Sphinx documentation +├── examples/ # Usage examples +└── pyproject.toml # Project configuration +``` + +## Design Principles + +1. **Backward Compatibility** - Never break existing logging code +2. **Zero Dependencies** - Keep the core lightweight +3. **Thread Safety** - Support multi-threaded applications +4. **Async Support** - First-class async/await support +5. **Performance** - Minimal overhead over standard logging +6. **Simplicity** - Easy to use, hard to misuse + +## Release Process + +Releases are automated using semantic-release: + +1. Merge changes to `main` branch +2. Semantic-release analyzes commit messages +3. Version is bumped automatically +4. Changelog is generated +5. Package is published to PyPI + +## Getting Help + +- **Issues**: Open a GitHub issue for bugs or feature requests +- **Discussions**: Use GitHub Discussions for questions +- **Documentation**: Check the docs at `docs/` + +## Recognition + +Contributors are recognized in: +- GitHub contributors list +- Release notes for significant contributions +- Documentation acknowledgments + +Thank you for contributing to LogStructor! 🚀 \ No newline at end of file diff --git a/README.md b/README.md index 3d94089..01819b4 100644 --- a/README.md +++ b/README.md @@ -17,21 +17,17 @@ Try finding anything in this mess: 2025-01-08 10:32:01 INFO: Order ORD-789 completed successfully ``` -**Questions you can't answer:** +Now ask yourself: Which user experienced the database timeout? How many failed logins did alice have today? Which orders failed due to timeouts? -- Which user had the database timeout? -- How many failed logins did alice have today? -- What orders failed due to timeouts? +With unstructured text logs, you can't easily answer any of these questions. You can’t search, filter, or analyze them in a meaningful way. -**You can't search, filter, or analyze unstructured text logs.** - -## The Solution: 3 Lines of Code +## The Solution: Few Lines of Code ```python import logstructor logger = logstructor.getLogger(__name__) -logger.info("Login failed", user_id="alice", ip="192.168.1.100", attempt=3, reason="invalid_password") +logger.info("Login failed", user_id="alice", ip="192.168.1.100", attempt=3) ``` **Result:** @@ -44,8 +40,7 @@ logger.info("Login failed", user_id="alice", ip="192.168.1.100", attempt=3, reas "context": { "user_id": "alice", "ip": "192.168.1.100", - "attempt": 3, - "reason": "invalid_password" + "attempt": 3 } } ``` @@ -56,9 +51,6 @@ logger.info("Login failed", user_id="alice", ip="192.168.1.100", attempt=3, reas # Find all of alice's actions across all services user_id:"alice" -# Find all failed login attempts -reason:"invalid_password" - # Find users with multiple failed attempts (security alert!) attempt:>2 @@ -66,8 +58,27 @@ attempt:>2 user_id:"alice" AND level:"ERROR" AND timestamp:[now-1h TO now] ``` -**Before:** Grep through gigabytes of text files 😵 -**After:** Instant search and filtering 🚀 +**Before:** Grep through gigabytes of text files ❌
+**After:** Instant search and filtering ✅ + +## Get Started + +Installing and using LogStructor is simple: + +```bash +pip install logstructor +``` + +Replace the standard logger: + +```python +import logstructor + +logger = logstructor.getLogger(__name__) +logger.info("Hello structured world", excited=True) +``` + +That’s it — structured logs with context, ready for debugging and monitoring. ## Why Developers Love It @@ -96,6 +107,19 @@ logger.info("Request completed") logstructor.clear_context() ``` +**Works with async/await:** + +```python +async def handle_request(): + logstructor.bind_context(request_id="req-123") + + await authenticate_user() # Context preserved across await + logger.info("User authenticated") + + await process_data() # Still has request_id + logger.info("Processing complete") +``` + ### 3. Drop-in replacement ```python @@ -113,25 +137,23 @@ logger.error("Connection failed", host="db.example.com", timeout=30) | Feature | Benefit | | ------------------------ | --------------------------------------------------- | | 🔒 **Thread-safe** | Works perfectly in multi-threaded web apps | +| ⚡ **Async-ready** | Full support for async/await with contextvars | | 📦 **Zero dependencies** | No supply chain attacks, no version conflicts | | ⚡ **High performance** | Minimal overhead over standard logging | -| � **Battle-tested** | Running in production handling millions of requests | - -## Get Started - -```bash -pip install logstructor -``` +| 🛡️ **Battle-tested** | Running in production handling millions of requests | -```python -import logstructor +## Why Not structlog? -logger = logstructor.getLogger(__name__) -logger.info("Hello structured world", excited=True) -``` +[structlog](https://www.structlog.org/) is fantastic for complex logging pipelines, but it requires learning a completely new API and philosophy. LogStructor takes a different approach: -That's it. Your logs just got 10x more useful. 📈 +| Aspect | LogStructor | structlog | +| -------------------- | -------------------------------- | ------------------------------------ | +| **Learning curve** | Zero - uses standard logging API | Steep - new concepts and API | +| **Migration effort** | Drop-in replacement | Rewrite all logging calls | +| **Dependencies** | Zero | Multiple (including optional ones) | +| **Complexity** | Minimal - just structured fields | High - processors, contextvars, etc. | +| **Use case** | 80% of structured logging needs | Complex logging architectures | --- -**🚀 Stop fighting your logs. Start using them.** +**🚀 Stop fighting your logs. Start using them.** \ No newline at end of file diff --git a/SECURITY.md b/SECURITY.md new file mode 100644 index 0000000..9e1e40a --- /dev/null +++ b/SECURITY.md @@ -0,0 +1,13 @@ +# 🛡️ Security Policy + +## Reporting a Vulnerability + +If you discover a potential security issue in this project, please report it responsibly. + +Provide as much information as possible to help us reproduce and verify the issue. + +We will work on a timely fix. + +## Supported Versions + +We recommend always using the latest stable release to benefit from security patches and improvements. \ No newline at end of file diff --git a/docs/Makefile b/docs/Makefile new file mode 100644 index 0000000..d0c3cbf --- /dev/null +++ b/docs/Makefile @@ -0,0 +1,20 @@ +# Minimal makefile for Sphinx documentation +# + +# You can set these variables from the command line, and also +# from the environment for the first two. +SPHINXOPTS ?= +SPHINXBUILD ?= sphinx-build +SOURCEDIR = source +BUILDDIR = build + +# Put it first so that "make" without argument is like "make help". +help: + @$(SPHINXBUILD) -M help "$(SOURCEDIR)" "$(BUILDDIR)" $(SPHINXOPTS) $(O) + +.PHONY: help Makefile + +# Catch-all target: route all unknown targets to Sphinx using the new +# "make mode" option. $(O) is meant as a shortcut for $(SPHINXOPTS). +%: Makefile + @$(SPHINXBUILD) -M $@ "$(SOURCEDIR)" "$(BUILDDIR)" $(SPHINXOPTS) $(O) diff --git a/docs/make.bat b/docs/make.bat new file mode 100644 index 0000000..747ffb7 --- /dev/null +++ b/docs/make.bat @@ -0,0 +1,35 @@ +@ECHO OFF + +pushd %~dp0 + +REM Command file for Sphinx documentation + +if "%SPHINXBUILD%" == "" ( + set SPHINXBUILD=sphinx-build +) +set SOURCEDIR=source +set BUILDDIR=build + +%SPHINXBUILD% >NUL 2>NUL +if errorlevel 9009 ( + echo. + echo.The 'sphinx-build' command was not found. Make sure you have Sphinx + echo.installed, then set the SPHINXBUILD environment variable to point + echo.to the full path of the 'sphinx-build' executable. Alternatively you + echo.may add the Sphinx directory to PATH. + echo. + echo.If you don't have Sphinx installed, grab it from + echo.https://www.sphinx-doc.org/ + exit /b 1 +) + +if "%1" == "" goto help + +%SPHINXBUILD% -M %1 %SOURCEDIR% %BUILDDIR% %SPHINXOPTS% %O% +goto end + +:help +%SPHINXBUILD% -M help %SOURCEDIR% %BUILDDIR% %SPHINXOPTS% %O% + +:end +popd diff --git a/docs/source/_static/custom.css b/docs/source/_static/custom.css new file mode 100644 index 0000000..1243c85 --- /dev/null +++ b/docs/source/_static/custom.css @@ -0,0 +1,14 @@ +h2 { + border-bottom: 1px solid darkgray; +} + +h3 { + font-size: 1.3rem; + margin-top: 10px; + margin-bottom: 5px; + color: rgb(158, 158, 158) !important; +} + +:root { + --pst-color-table-row-hover-bg: #3ea5ff71 !important; +} \ No newline at end of file diff --git a/docs/source/conf.py b/docs/source/conf.py new file mode 100644 index 0000000..1a6e537 --- /dev/null +++ b/docs/source/conf.py @@ -0,0 +1,43 @@ +# Configuration file for the Sphinx documentation builder. +# +# For the full list of built-in configuration values, see the documentation: +# https://www.sphinx-doc.org/en/master/usage/configuration.html + +# -- Project information ----------------------------------------------------- +# https://www.sphinx-doc.org/en/master/usage/configuration.html#project-information + +project = 'LogStructor' +copyright = '2025, Marcel Kennert' +author = 'Marcel Kennert' + +# -- General configuration --------------------------------------------------- +# https://www.sphinx-doc.org/en/master/usage/configuration.html#general-configuration + +extensions = [ + "sphinx.ext.autodoc", + "sphinx.ext.autosummary", + "sphinx.ext.napoleon", + "myst_parser", + "sphinx_copybutton", + "sphinx.ext.viewcode", +] + +templates_path = ['_templates'] +exclude_patterns = [] + + + +# -- Options for HTML output ------------------------------------------------- +# https://www.sphinx-doc.org/en/master/usage/configuration.html#options-for-html-output + +html_theme = 'sphinx_book_theme' +html_title = "LogStructor Documentation" +html_static_path = ['_static'] +html_css_files = ["custom.css"] +html_theme_options = { + "repository_url": "https://github.com/flitzpiepe93/logstructor", + "use_repository_button": True, +} +html_context = { + "default_mode": "dark" +} \ No newline at end of file diff --git a/docs/source/index.rst b/docs/source/index.rst new file mode 100644 index 0000000..9a432ba --- /dev/null +++ b/docs/source/index.rst @@ -0,0 +1,22 @@ +.. logstructor documentation master file, created by + sphinx-quickstart on Sun Aug 3 14:34:06 2025. + You can adapt this file completely to your liking, but it should at least + contain the root `toctree` directive. + +LogStructor Documentation +========================= + +.. include:: ../../README.md + :parser: myst_parser.sphinx_ + :start-after: LogStructor + +.. toctree:: + :maxdepth: 2 + :caption: Tutorial + :hidden: + + tutorial/getting-started + tutorial/basic-usage + tutorial/json-formatting + tutorial/context-management + tutorial/best-practices diff --git a/docs/source/tutorial/basic-usage.rst b/docs/source/tutorial/basic-usage.rst new file mode 100644 index 0000000..d4ea84b --- /dev/null +++ b/docs/source/tutorial/basic-usage.rst @@ -0,0 +1,347 @@ +Basic Usage +=========== + +This guide covers all the fundamental features of LogStructor and how to use them effectively. + +Logger Creation +--------------- + +LogStructor provides a drop-in replacement for Python's standard logging with automatic JSON formatting: + +.. code-block:: python + + import logstructor + + # Create a logger - automatically configured with JSON output + logger = logstructor.getLogger(__name__) + + # Or with a custom name + logger = logstructor.getLogger("my_app") + + # Logs are automatically structured JSON - no manual setup needed! + logger.info("User action", user_id=123, action="login") + +Logging Methods +--------------- + +LogStructor supports all standard logging levels with structured field support: + +Debug +~~~~~ + +.. code-block:: python + + logger.debug( + "Debugging info", + variable_name="user_data", + variable_value={"id": 123, "name": "alice"} + ) + +Info +~~~~ + +.. code-block:: python + + logger.info( + "User action completed", + user_id=123, + action="profile_update", + duration_ms=150 + ) + +Warning +~~~~~~~ + +.. code-block:: python + + logger.warning( + "Rate limit approaching", + user_id=456, + current_requests=95, + limit=100, + window_minutes=60 + ) + +Error +~~~~~ + +.. code-block:: python + + logger.error( + "Payment processing failed", + transaction_id="txn_789", + error_code="INSUFFICIENT_FUNDS", + amount=250.00, + account_balance=180.50 + ) + +Critical +~~~~~~~~ + +.. code-block:: python + + logger.critical( + "System shutdown initiated", + reason="out_of_memory", + available_mb=0, + required_mb=1024 + ) + +Structured Fields +----------------- + +Add structured data using keyword arguments: + +Basic Types +~~~~~~~~~~~ + +.. code-block:: python + + logger.info( + "Data types example", + string_field="hello world", + integer_field=42, + float_field=3.14159, + boolean_field=True, + none_field=None + ) + +Complex Types +~~~~~~~~~~~~~ + +.. code-block:: python + + from datetime import datetime + + logger.info( + "Complex data example", + timestamp=datetime.now(), + list_field=[1, 2, 3, "four"], + dict_field={"nested": "value", "count": 5}, + user_data={ + "id": 123, + "preferences": { + "theme": "dark", + "notifications": True + } + } + ) + +Backward Compatibility +---------------------- + +All standard logging features continue to work: + +String Formatting +~~~~~~~~~~~~~~~~~ + +.. code-block:: python + + # Standard string formatting + logger.info("User %s logged in", username) + logger.info("Processing order {} for customer {}", order_id, customer_id) + + # f-strings + logger.info(f"User {username} logged in from {ip_address}") + +Exception Information +~~~~~~~~~~~~~~~~~~~~~ + +.. code-block:: python + + try: + risky_operation() + except Exception as e: + logger.error( + "Operation failed", + exc_info=True, # Include traceback + operation="data_processing", + error_type=type(e).__name__ + ) + +Stack Information +~~~~~~~~~~~~~~~~~ + +.. code-block:: python + + logger.debug( + "Debug checkpoint", + stack_info=True, # Include stack trace + checkpoint="data_validation" + ) + +Extra Fields (Standard Logging) +~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ + +.. code-block:: python + + # Standard logging extra parameter still works + logger.info( + "Standard extra", + extra={"request_id": "req-123"}, + user_id=456 + ) + +Combining Standard and Structured +---------------------------------- + +You can mix standard logging patterns with structured fields: + +.. code-block:: python + + # Message with formatting + structured fields + logger.info( + "User %s performed action", username, + user_id=123, + action="login", + ip_address="192.168.1.100", + user_agent="Mozilla/5.0..." + ) + + # Exception handling with structured context + try: + process_payment(amount, card_token) + except PaymentError as e: + logger.error( + "Payment failed: %s", str(e), + exc_info=True, + payment_id=payment_id, + amount=amount, + error_code=e.code, + retry_count=retry_count + ) + +Data Serialization +------------------ + +LogStructor automatically handles data serialization: + +Automatic Conversion +~~~~~~~~~~~~~~~~~~~~ + +.. code-block:: python + + from datetime import datetime, date + from decimal import Decimal + + logger.info( + "Serialization example", + timestamp=datetime.now(), # → ISO string + date_field=date.today(), # → ISO date string + decimal_field=Decimal("99.99"), # → float + custom_object=MyClass() # → str(object) + ) + +Custom Objects +~~~~~~~~~~~~~~ + +.. code-block:: python + + class User: + def __init__(self, id, name): + self.id = id + self.name = name + + def __str__(self): + return f"User({self.id}, {self.name})" + + user = User(123, "alice") + logger.info("User created", user_object=user) # Uses __str__ + +Integration Examples +-------------------- + +Web Framework Integration +~~~~~~~~~~~~~~~~~~~~~~~~~ + +.. code-block:: python + + from flask import Flask, request + import logstructor + + app = Flask(__name__) + logger = logstructor.getLogger(__name__) + + @app.route('/api/users/') + def get_user(user_id): + logger.info("API request received", + endpoint="/api/users", + method=request.method, + user_id=user_id, + ip_address=request.remote_addr, + user_agent=request.headers.get('User-Agent')) + + # Process request... + + logger.info("API request completed", + status_code=200, + response_time_ms=150) + +Database Integration +~~~~~~~~~~~~~~~~~~~~ + +.. code-block:: python + + import time + + def execute_query(sql, params=None): + start_time = time.time() + + try: + logger.debug("Executing query", + sql=sql, + params=params) + + # Execute query... + result = cursor.execute(sql, params) + + duration = (time.time() - start_time) * 1000 + logger.info("Query completed", + query_duration_ms=round(duration, 2), + rows_affected=cursor.rowcount) + + return result + + except Exception as e: + duration = (time.time() - start_time) * 1000 + logger.error("Query failed", + exc_info=True, + sql=sql, + query_duration_ms=round(duration, 2), + error_type=type(e).__name__) + raise + +Async Usage +----------- + +LogStructor works seamlessly with async/await: + +.. code-block:: python + + import asyncio + import logstructor + + logger = logstructor.getLogger(__name__) + + async def handle_request(): + logstructor.bind_context(request_id="req-123") + + await authenticate_user() # Context preserved across await + logger.info("User authenticated") + + await process_data() # Still has request_id + logger.info("Processing complete") + + logstructor.clear_context() + + # Context is isolated between concurrent tasks + async def main(): + tasks = [handle_request() for _ in range(10)] + await asyncio.gather(*tasks) # Each task has its own context + +Next Steps +---------- + +- :doc:`json-formatting` - Configure structured JSON output +- :doc:`context-management` - Learn about context management +- :doc:`best-practices` - Optimal patterns and techniques \ No newline at end of file diff --git a/docs/source/tutorial/best-practices.rst b/docs/source/tutorial/best-practices.rst new file mode 100644 index 0000000..5b671f6 --- /dev/null +++ b/docs/source/tutorial/best-practices.rst @@ -0,0 +1,708 @@ +Best Practices +============== + +This guide covers proven patterns and techniques for using LogStructor effectively in production environments. + +Field Naming Conventions +------------------------- + +Use Consistent Field Names +~~~~~~~~~~~~~~~~~~~~~~~~~~~ + +Establish naming conventions across your application: + +.. code-block:: python + + # Good: Consistent snake_case + logger.info("User action", + user_id=123, + event_type="login", + ip_address="192.168.1.100") + + # Avoid: Mixed naming styles + logger.info("User action", + userId=123, # camelCase + event_type="login", # snake_case + IPAddress="192.168.1.100") # PascalCase + +Standard Field Names +~~~~~~~~~~~~~~~~~~~~ + +Use these common field names consistently: + +.. code-block:: python + + # User identification + user_id=123 + username="alice" + user_email="alice@example.com" + user_role="admin" + + # Request tracking + request_id="req-abc123" + session_id="sess-xyz789" + correlation_id="corr-456def" + + # Network information + ip_address="192.168.1.100" + user_agent="Mozilla/5.0..." + remote_addr="10.0.0.1" + + # Performance metrics + duration_ms=150 + response_time_ms=250 + query_time_ms=45 + processing_time_ms=100 + + # Business entities + order_id="ORD-12345" + transaction_id="txn-67890" + customer_id=789 + product_id="PROD-456" + + # Error information + error_code="PAYMENT_FAILED" + error_type="ValidationError" + error_message="Invalid credit card" + +Units in Field Names +~~~~~~~~~~~~~~~~~~~~ + +Always include units in field names: + +.. code-block:: python + + # Good: Units are clear + logger.info("API response", + response_time_ms=250, # milliseconds + response_size_bytes=1024, # bytes + cache_ttl_seconds=3600) # seconds + + # Avoid: Ambiguous units + logger.info("API response", + response_time=250, # ms? seconds? + response_size=1024, # bytes? KB? + cache_ttl=3600) # seconds? minutes? + +Structured Logging Patterns +---------------------------- + +Event-Based Logging +~~~~~~~~~~~~~~~~~~~ + +Structure logs around business events: + +.. code-block:: python + + # User events + logger.info("user.login", + user_id=123, + login_method="password", + success=True) + + logger.info("user.logout", + user_id=123, + session_duration_minutes=45) + + # Order events + logger.info("order.created", + order_id="ORD-123", + customer_id=456, + total_amount=99.99) + + logger.info("order.payment_processed", + order_id="ORD-123", + payment_method="credit_card", + amount=99.99) + +State Transitions +~~~~~~~~~~~~~~~~~ + +Log important state changes: + +.. code-block:: python + + def process_order(order_id): + logger.info("order.state_changed", + order_id=order_id, + from_state="pending", + to_state="processing") + + try: + # Process order + logger.info("order.state_changed", + order_id=order_id, + from_state="processing", + to_state="completed") + except Exception as e: + logger.error("order.state_changed", + order_id=order_id, + from_state="processing", + to_state="failed", + error_reason=str(e)) + +Performance Monitoring +~~~~~~~~~~~~~~~~~~~~~~ + +Log performance metrics consistently: + +.. code-block:: python + + import time + from contextlib import contextmanager + + @contextmanager + def timed_operation(operation_name, **context): + start_time = time.time() + + logger.info(f"{operation_name}.started", **context) + + try: + yield + duration_ms = (time.time() - start_time) * 1000 + logger.info(f"{operation_name}.completed", + duration_ms=round(duration_ms, 2), + **context) + except Exception as e: + duration_ms = (time.time() - start_time) * 1000 + logger.error(f"{operation_name}.failed", + duration_ms=round(duration_ms, 2), + error_type=type(e).__name__, + error_message=str(e), + **context) + raise + + # Usage + with timed_operation("database.query", table="users", query_type="SELECT"): + results = db.execute("SELECT * FROM users WHERE active = true") + +Error Handling Patterns +------------------------ + +Structured Error Logging +~~~~~~~~~~~~~~~~~~~~~~~~~ + +Always include relevant context in error logs: + +.. code-block:: python + + def process_payment(user_id, amount, payment_method): + try: + # Payment processing logic + result = payment_gateway.charge(amount, payment_method) + + logger.info("payment.successful", + user_id=user_id, + amount=amount, + payment_method=payment_method, + transaction_id=result.transaction_id) + + except PaymentDeclinedError as e: + logger.warning("payment.declined", + user_id=user_id, + amount=amount, + payment_method=payment_method, + decline_reason=e.reason, + decline_code=e.code) + raise + + except PaymentGatewayError as e: + logger.error("payment.gateway_error", + exc_info=True, + user_id=user_id, + amount=amount, + payment_method=payment_method, + gateway_error_code=e.error_code, + gateway_message=e.message, + retry_count=getattr(e, 'retry_count', 0)) + raise + + except Exception as e: + logger.critical("payment.unexpected_error", + exc_info=True, + user_id=user_id, + amount=amount, + payment_method=payment_method, + error_type=type(e).__name__) + raise + +Error Classification +~~~~~~~~~~~~~~~~~~~~~ + +Use consistent error classification: + +.. code-block:: python + + # Client errors (4xx equivalent) + logger.warning("validation.failed", + field="email", + value="invalid-email", + error_type="client_error") + + # Server errors (5xx equivalent) + logger.error("database.connection_failed", + host="db.example.com", + error_type="server_error") + + # Business logic errors + logger.info("business_rule.violated", + rule="max_daily_transactions", + user_id=123, + current_count=10, + limit=5, + error_type="business_error") + +Context Management Best Practices +---------------------------------- + +Web Application Context +~~~~~~~~~~~~~~~~~~~~~~~ + +Set up comprehensive request context: + +.. code-block:: python + + def setup_request_context(request): + """Set up logging context for web requests""" + context = { + 'request_id': generate_request_id(), + 'method': request.method, + 'path': request.path, + 'ip_address': get_client_ip(request), + 'user_agent': request.headers.get('User-Agent', 'Unknown')[:200] # Truncate long user agents + } + + # Add user context if authenticated + if hasattr(request, 'user') and request.user.is_authenticated: + context.update({ + 'user_id': request.user.id, + 'username': request.user.username, + 'user_role': getattr(request.user, 'role', 'user') + }) + + # Add API version if available + if 'X-API-Version' in request.headers: + context['api_version'] = request.headers['X-API-Version'] + + logstructor.bind_context(**context) + +Background Task Context +~~~~~~~~~~~~~~~~~~~~~~~ + +For background tasks, preserve relevant context: + +.. code-block:: python + + def enqueue_background_task(task_func, *args, **kwargs): + """Enqueue background task with current context""" + current_context = logstructor.get_context() + + def wrapped_task(): + # Restore context in background thread + logstructor.bind_context(**current_context) + try: + logger.info("background_task.started", + task_name=task_func.__name__) + result = task_func(*args, **kwargs) + logger.info("background_task.completed", + task_name=task_func.__name__) + return result + except Exception as e: + logger.error("background_task.failed", + task_name=task_func.__name__, + error_type=type(e).__name__, + error_message=str(e)) + raise + finally: + logstructor.clear_context() + + # Queue the wrapped task + task_queue.enqueue(wrapped_task) + +Async Context Management +~~~~~~~~~~~~~~~~~~~~~~~~ + +For async applications, context is automatically preserved: + +.. code-block:: python + + async def handle_async_request(): + logstructor.bind_context(request_id="req-123") + + try: + await authenticate_user() # Context preserved across await + logger.info("User authenticated") + + await process_data() # Still has request_id + logger.info("Processing complete") + + finally: + logstructor.clear_context() + + # Context is isolated between concurrent tasks + async def main(): + tasks = [handle_async_request() for _ in range(10)] + await asyncio.gather(*tasks) # Each task has its own context + +Performance Optimization +------------------------ + +Lazy Evaluation +~~~~~~~~~~~~~~~ + +Use lazy evaluation for expensive operations: + +.. code-block:: python + + # Bad: Always calculates, even if debug is disabled + logger.debug("User data", user_data=expensive_user_calculation()) + + # Good: Only calculate if debug logging is enabled + if logger.isEnabledFor(logging.DEBUG): + logger.debug("User data", user_data=expensive_user_calculation()) + + # Even better: Use a lambda for truly lazy evaluation + def log_debug_data(): + if logger.isEnabledFor(logging.DEBUG): + logger.debug("User data", user_data=expensive_user_calculation()) + +Efficient Data Extraction +~~~~~~~~~~~~~~~~~~~~~~~~~~ + +Extract only what you need for logging: + +.. code-block:: python + + # Bad: Serializing entire complex object + logger.info("User updated", user_object=user) + + # Good: Extract specific fields + logger.info("User updated", + user_id=user.id, + username=user.username, + email=user.email, + last_login=user.last_login.isoformat() if user.last_login else None) + +Batch Context Updates +~~~~~~~~~~~~~~~~~~~~~ + +Set context once, not repeatedly: + +.. code-block:: python + + # Bad: Setting context multiple times + for item in items: + logstructor.bind_context(item_id=item.id) + logger.info("Processing item") + logstructor.clear_context() + + # Good: Process in batches or use different approach + logstructor.bind_context(batch_id="batch-123", total_items=len(items)) + for i, item in enumerate(items): + logger.info("Processing item", + item_id=item.id, + item_index=i) + logstructor.clear_context() + +Production Deployment +--------------------- + +Log Level Configuration +~~~~~~~~~~~~~~~~~~~~~~~ + +Use appropriate log levels in production: + +.. code-block:: python + + # Development + logging.getLogger().setLevel(logging.DEBUG) + + # Staging + logging.getLogger().setLevel(logging.INFO) + + # Production + logging.getLogger().setLevel(logging.WARNING) + + # Critical systems + logging.getLogger().setLevel(logging.ERROR) + +Sensitive Data Handling +~~~~~~~~~~~~~~~~~~~~~~~ + +Never log sensitive information: + +.. code-block:: python + + # Bad: Logging sensitive data + logger.info("User login", + username=username, + password=password) # Never log passwords! + + # Good: Log safely + logger.info("User login", + username=username, + password_length=len(password), + has_special_chars=any(c in password for c in "!@#$%")) + + # For debugging, use hashed values + import hashlib + password_hash = hashlib.sha256(password.encode()).hexdigest()[:8] + logger.debug("Login attempt", + username=username, + password_hash=password_hash) + +Data Sanitization +~~~~~~~~~~~~~~~~~ + +Sanitize user input in logs: + +.. code-block:: python + + def sanitize_for_logging(value, max_length=200): + """Sanitize user input for safe logging""" + if value is None: + return None + + # Convert to string and truncate + str_value = str(value)[:max_length] + + # Remove potentially dangerous characters + safe_value = ''.join(c for c in str_value if c.isprintable()) + + return safe_value + + # Usage + logger.info("User input received", + user_input=sanitize_for_logging(user_input), + input_length=len(user_input)) + +Monitoring and Alerting +----------------------- + +Health Check Logging +~~~~~~~~~~~~~~~~~~~~ + +Log application health metrics: + +.. code-block:: python + + def log_health_metrics(): + """Log application health metrics""" + import psutil + import gc + + logger.info("health.metrics", + cpu_percent=psutil.cpu_percent(), + memory_percent=psutil.virtual_memory().percent, + disk_usage_percent=psutil.disk_usage('/').percent, + active_connections=len(psutil.net_connections()), + gc_collections=sum(gc.get_stats(), []).get('collections', 0)) + + # Call periodically + import threading + import time + + def health_monitor(): + while True: + log_health_metrics() + time.sleep(60) # Every minute + + health_thread = threading.Thread(target=health_monitor, daemon=True) + health_thread.start() + +Business Metrics +~~~~~~~~~~~~~~~~ + +Log business-relevant metrics: + +.. code-block:: python + + def log_business_metrics(): + """Log business metrics for monitoring""" + logger.info("business.metrics", + active_users_count=get_active_users_count(), + orders_today=get_orders_count_today(), + revenue_today=get_revenue_today(), + error_rate_percent=get_error_rate_last_hour(), + avg_response_time_ms=get_avg_response_time()) + +Alert-Worthy Events +~~~~~~~~~~~~~~~~~~~ + +Structure logs for easy alerting: + +.. code-block:: python + + # High-priority alerts + logger.critical("system.critical_error", + error_type="database_unavailable", + affected_users="all", + estimated_downtime_minutes=5) + + # Medium-priority alerts + logger.error("business.threshold_exceeded", + metric="error_rate", + current_value=15.5, + threshold=10.0, + time_window_minutes=5) + + # Low-priority alerts + logger.warning("system.resource_warning", + resource="memory", + current_usage_percent=85, + threshold_percent=80) + +Testing Structured Logs +------------------------ + +Log Testing Utilities +~~~~~~~~~~~~~~~~~~~~~ + +Create utilities for testing log output: + +.. code-block:: python + + import json + from io import StringIO + import logging + + class LogCapture: + """Utility for capturing and testing log output""" + + def __init__(self): + self.stream = StringIO() + self.handler = logging.StreamHandler(self.stream) + self.handler.setFormatter(logstructor.StructFormatter()) + + def __enter__(self): + logger = logstructor.getLogger("test") + logger.addHandler(self.handler) + logger.setLevel(logging.DEBUG) + return self + + def __exit__(self, exc_type, exc_val, exc_tb): + logger = logstructor.getLogger("test") + logger.removeHandler(self.handler) + + def get_logs(self): + """Get all captured logs as parsed JSON objects""" + logs = [] + for line in self.stream.getvalue().strip().split('\n'): + if line: + logs.append(json.loads(line)) + return logs + + def assert_log_contains(self, level, message, **expected_context): + """Assert that a log entry exists with expected content""" + logs = self.get_logs() + + for log in logs: + if (log.get('level') == level and + log.get('message') == message): + + # Check context fields + context = log.get('context', {}) + for key, value in expected_context.items(): + if context.get(key) != value: + break + else: + return True + + raise AssertionError(f"Expected log not found: {level} {message} {expected_context}") + + # Usage in tests + def test_user_login_logging(): + with LogCapture() as capture: + logger = logstructor.getLogger("test") + logger.info("User logged in", user_id=123, method="password") + + capture.assert_log_contains("INFO", "User logged in", + user_id=123, method="password") + +Integration Testing +~~~~~~~~~~~~~~~~~~~ + +Test log output in integration tests: + +.. code-block:: python + + def test_api_request_logging(client): + """Test that API requests are properly logged""" + with LogCapture() as capture: + response = client.get('/api/users/123') + + logs = capture.get_logs() + + # Check request started log + request_logs = [log for log in logs if "Request started" in log.get('message', '')] + assert len(request_logs) == 1 + assert request_logs[0]['context']['method'] == 'GET' + assert request_logs[0]['context']['path'] == '/api/users/123' + + # Check request completed log + completion_logs = [log for log in logs if "Request completed" in log.get('message', '')] + assert len(completion_logs) == 1 + assert completion_logs[0]['context']['status_code'] == 200 + +Common Anti-Patterns +-------------------- + +Avoid These Mistakes +~~~~~~~~~~~~~~~~~~~~ + +.. code-block:: python + + # ❌ Don't log sensitive data + logger.info("User login", password=password, credit_card=card_number) + + # ❌ Don't use inconsistent field names + logger.info("Event", userId=123) # camelCase + logger.info("Event", user_id=123) # snake_case (pick one!) + + # ❌ Don't forget to clear context + logstructor.bind_context(request_id="req-123") + # ... process request ... + # Context never cleared - memory leak! + + # ❌ Don't log complex objects directly + logger.info("User data", user=complex_user_object) # Hard to search + + # ❌ Don't use vague messages + logger.info("Something happened", data=some_data) # Not helpful + + # ❌ Don't ignore performance + logger.debug("Debug info", expensive_data=slow_calculation()) # Always calculated + +Better Alternatives +~~~~~~~~~~~~~~~~~~~ + +.. code-block:: python + + # ✅ Log safely + logger.info("User login", username=username, login_successful=True) + + # ✅ Use consistent naming + logger.info("Event", user_id=123) # Always snake_case + + # ✅ Always clear context + try: + logstructor.bind_context(request_id="req-123") + # ... process request ... + finally: + logstructor.clear_context() + + # ✅ Extract relevant fields + logger.info("User data", user_id=user.id, username=user.username) + + # ✅ Use descriptive messages + logger.info("User authentication successful", user_id=123, method="password") + + # ✅ Use lazy evaluation + if logger.isEnabledFor(logging.DEBUG): + logger.debug("Debug info", expensive_data=slow_calculation()) + +Next Steps +---------- + +- :doc:`context-management` - Advanced context management +- :doc:`json-formatting` - JSON formatting configuration \ No newline at end of file diff --git a/docs/source/tutorial/context-management.rst b/docs/source/tutorial/context-management.rst new file mode 100644 index 0000000..d5f35a0 --- /dev/null +++ b/docs/source/tutorial/context-management.rst @@ -0,0 +1,598 @@ +Context Management +================== + +LogStructor's context management allows you to bind data to the current context, which is then automatically included in all subsequent log entries. This is particularly powerful for web applications where you want request-specific data in every log. + +Basic Context Usage +------------------- + +Binding Context +~~~~~~~~~~~~~~~ + +Use ``bind_context()`` to add fields that will be included in all logs: + +.. code-block:: python + + import logstructor + + logger = logstructor.getLogger(__name__) + + # Bind context data + logstructor.bind_context( + request_id="req-abc123", + user_id=456, + session_id="sess-xyz789" + ) + + # All subsequent logs include the context automatically + logger.info("Processing request") + logger.info("Validating input", field="email") + logger.info("Database query", table="users") + logger.info("Request completed", status_code=200) + +**Output (with JSON formatter):** + +.. code-block:: json + + { + "timestamp": "2025-01-08T10:30:45Z", + "level": "INFO", + "logger": "__main__", + "message": "Processing request", + "context": { + "request_id": "req-abc123", + "user_id": 456, + "session_id": "sess-xyz789" + } + } + +Clearing Context +~~~~~~~~~~~~~~~~ + +Always clear context when done to prevent data leakage: + +.. code-block:: python + + # Clear all context data + logstructor.clear_context() + + # Logs no longer include the previous context + logger.info("Context cleared") # No context fields + +Viewing Current Context +~~~~~~~~~~~~~~~~~~~~~~~ + +Check what's currently in context: + +.. code-block:: python + + # Get current context as a dictionary + current_context = logstructor.get_context() + print(current_context) + # Output: {'request_id': 'req-abc123', 'user_id': 456, 'session_id': 'sess-xyz789'} + +Context Isolation +----------------- + +Context is automatically isolated between different execution contexts, including threads and async tasks: + +Thread Isolation +~~~~~~~~~~~~~~~~ + +.. code-block:: python + + import threading + import time + + def worker_function(worker_id): + # Each thread sets its own context + logstructor.bind_context( + worker_id=worker_id, + thread_name=threading.current_thread().name + ) + + logger.info("Worker started") + time.sleep(1) # Simulate work + logger.info("Worker completed") + + # Clean up this thread's context + logstructor.clear_context() + + # Start multiple threads + for i in range(3): + thread = threading.Thread(target=worker_function, args=(i,)) + thread.start() + +Each thread's logs will only include its own context data. + +Async Task Isolation +~~~~~~~~~~~~~~~~~~~~ + +.. code-block:: python + + import asyncio + import logstructor + + logger = logstructor.getLogger(__name__) + + async def async_task(task_id): + # Each async task has its own context + logstructor.bind_context(task_id=task_id) + + await asyncio.sleep(0.1) # Context preserved across await + logger.info("Task processing") + + await asyncio.sleep(0.1) # Still has task_id + logger.info("Task completed") + + logstructor.clear_context() + + # Run multiple tasks concurrently - each has isolated context + async def main(): + tasks = [async_task(i) for i in range(5)] + await asyncio.gather(*tasks) + +Web Application Patterns +------------------------- + +Flask Integration +~~~~~~~~~~~~~~~~~ + +.. code-block:: python + + from flask import Flask, request, g + import logstructor + import uuid + + app = Flask(__name__) + logger = logstructor.getLogger(__name__) + + @app.before_request + def before_request(): + # Generate unique request ID + g.request_id = str(uuid.uuid4()) + + # Bind request context + logstructor.bind_context( + request_id=g.request_id, + method=request.method, + path=request.path, + ip_address=request.remote_addr, + user_agent=request.headers.get('User-Agent', 'Unknown') + ) + + logger.info("Request started") + + @app.after_request + def after_request(response): + logger.info("Request completed", + status_code=response.status_code, + content_length=response.content_length) + + # Clean up context + logstructor.clear_context() + return response + + @app.route('/api/users/') + def get_user(user_id): + # Add user-specific context + logstructor.bind_context(user_id=user_id) + + logger.info("Fetching user data") + # ... business logic ... + logger.info("User data retrieved", record_count=1) + + return {"user_id": user_id, "name": "Alice"} + +Django Integration +~~~~~~~~~~~~~~~~~~ + +.. code-block:: python + + # middleware.py + import logstructor + import uuid + + class LogContextMiddleware: + def __init__(self, get_response): + self.get_response = get_response + + def __call__(self, request): + # Set up context for this request + request_id = str(uuid.uuid4()) + + logstructor.bind_context( + request_id=request_id, + method=request.method, + path=request.path, + ip_address=self.get_client_ip(request) + ) + + # Add user context if authenticated + if hasattr(request, 'user') and request.user.is_authenticated: + logstructor.bind_context(user_id=request.user.id) + + try: + response = self.get_response(request) + return response + finally: + # Always clean up context + logstructor.clear_context() + + def get_client_ip(self, request): + x_forwarded_for = request.META.get('HTTP_X_FORWARDED_FOR') + if x_forwarded_for: + return x_forwarded_for.split(',')[0] + return request.META.get('REMOTE_ADDR') + + # views.py + import logstructor + + logger = logstructor.getLogger(__name__) + + def user_profile(request, user_id): + logger.info("Fetching user profile") + # All logs automatically include request context + user_id + + try: + # Business logic + logger.info("Database query", table="users") + user = User.objects.get(id=user_id) + logger.info("Profile retrieved successfully") + return JsonResponse({"user": user.to_dict()}) + + except User.DoesNotExist: + logger.warning("User not found", requested_user_id=user_id) + return JsonResponse({"error": "User not found"}, status=404) + +FastAPI Integration +~~~~~~~~~~~~~~~~~~~ + +.. code-block:: python + + from fastapi import FastAPI, Request + import logstructor + import uuid + + app = FastAPI() + logger = logstructor.getLogger(__name__) + + @app.middleware("http") + async def logging_middleware(request: Request, call_next): + # Set up context for this request + request_id = str(uuid.uuid4()) + + logstructor.bind_context( + request_id=request_id, + method=request.method, + path=request.url.path, + ip_address=request.client.host + ) + + logger.info("Request started") + + try: + response = await call_next(request) + logger.info("Request completed", status_code=response.status_code) + return response + finally: + logstructor.clear_context() + + @app.get("/users/{user_id}") + async def get_user(user_id: int): + logstructor.bind_context(user_id=user_id) + + logger.info("Fetching user data") + # Context is preserved across await calls + await asyncio.sleep(0.1) # Simulate async work + logger.info("User data retrieved") + + return {"user_id": user_id, "name": "Alice"} + +Context Updates +--------------- + +Adding More Context +~~~~~~~~~~~~~~~~~~~ + +You can add more context data at any time: + +.. code-block:: python + + # Initial context + logstructor.bind_context(request_id="req-123") + + logger.info("Request started") + + # Add more context later + logstructor.bind_context(user_id=456, operation="checkout") + + logger.info("User authenticated") # Includes request_id + user_id + operation + + # Add even more context + logstructor.bind_context(cart_items=3, total_amount=99.99) + + logger.info("Processing payment") # Includes all context fields + +Updating Context +~~~~~~~~~~~~~~~~ + +Use ``update_context()`` (alias for ``bind_context()``): + +.. code-block:: python + + # These are equivalent + logstructor.bind_context(user_id=123) + logstructor.update_context(user_id=123) + +Overwriting Context Fields +~~~~~~~~~~~~~~~~~~~~~~~~~~ + +Later calls overwrite existing fields: + +.. code-block:: python + + logstructor.bind_context(user_id=123, status="pending") + logger.info("Initial state") # user_id=123, status="pending" + + logstructor.bind_context(status="completed") # Overwrites status + logger.info("Updated state") # user_id=123, status="completed" + +Advanced Patterns +----------------- + +Context Managers +~~~~~~~~~~~~~~~~ + +Create reusable context managers: + +.. code-block:: python + + from contextlib import contextmanager + + @contextmanager + def user_context(user_id, username=None): + """Context manager for user-specific logging""" + logstructor.bind_context(user_id=user_id) + if username: + logstructor.bind_context(username=username) + + try: + yield + finally: + # Context is automatically cleared when exiting + logstructor.clear_context() + + # Usage + with user_context(123, "alice"): + logger.info("Processing user data") + logger.info("User operation completed") + # Context automatically cleared here + +Nested Contexts +~~~~~~~~~~~~~~~ + +For complex operations, you might want nested contexts: + +.. code-block:: python + + def process_order(order_id, user_id): + # Set order context + logstructor.bind_context(order_id=order_id, user_id=user_id) + + try: + logger.info("Order processing started") + + # Process each item + for item_id in get_order_items(order_id): + # Add item-specific context (temporary) + logstructor.bind_context(current_item_id=item_id) + + logger.info("Processing item") + process_item(item_id) + + # Remove item-specific context + current_context = logstructor.get_context() + current_context.pop('current_item_id', None) + logstructor.clear_context() + logstructor.bind_context(**current_context) + + logger.info("Order processing completed") + + finally: + logstructor.clear_context() + +Conditional Context +~~~~~~~~~~~~~~~~~~~ + +Add context based on conditions: + +.. code-block:: python + + def handle_request(request): + # Always add request context + logstructor.bind_context( + request_id=request.id, + method=request.method + ) + + # Add user context if authenticated + if request.user.is_authenticated: + logstructor.bind_context( + user_id=request.user.id, + user_type=request.user.user_type + ) + + # Add admin context for admin users + if request.user.is_staff: + logstructor.bind_context(is_admin=True) + + # Add debug context in development + if settings.DEBUG: + logstructor.bind_context( + debug_mode=True, + request_headers=dict(request.headers) + ) + + try: + # Process request + logger.info("Processing request") + # ... business logic ... + + finally: + logstructor.clear_context() + +Performance Considerations +-------------------------- + +Context Overhead +~~~~~~~~~~~~~~~~ + +Context management has minimal performance impact: + +.. code-block:: python + + # Benchmark results (approximate) + # Without context: 100,000 msgs/sec + # With context: 95,000 msgs/sec + # Overhead: ~5% + +Best Practices +~~~~~~~~~~~~~~ + +1. **Set context once per request**: + +.. code-block:: python + + # Good: Set once + logstructor.bind_context(request_id="req-123", user_id=456) + logger.info("Step 1") + logger.info("Step 2") + logger.info("Step 3") + + # Avoid: Setting context repeatedly + logger.info("Step 1", request_id="req-123", user_id=456) + logger.info("Step 2", request_id="req-123", user_id=456) + logger.info("Step 3", request_id="req-123", user_id=456) + +2. **Always clear context**: + +.. code-block:: python + + try: + logstructor.bind_context(request_id="req-123") + # ... process request ... + finally: + logstructor.clear_context() # Always clean up + +3. **Use simple data types in context**: + +.. code-block:: python + + # Good: Simple types + logstructor.bind_context(user_id=123, action="login") + + # Avoid: Complex objects + logstructor.bind_context(user_object=complex_user_instance) + +Debugging Context +----------------- + +Inspecting Context +~~~~~~~~~~~~~~~~~~ + +.. code-block:: python + + # Check current context + context = logstructor.get_context() + print(f"Current context: {context}") + + # Log current context + logger.debug("Current context", current_context=context) + +Context Validation +~~~~~~~~~~~~~~~~~~ + +.. code-block:: python + + def validate_context(): + """Ensure required context is present""" + context = logstructor.get_context() + required_fields = ['request_id', 'user_id'] + + missing = [field for field in required_fields if field not in context] + if missing: + logger.warning("Missing required context fields", missing_fields=missing) + return False + return True + + # Use in request handlers + if not validate_context(): + logger.error("Request processing aborted due to missing context") + return error_response() + +Common Pitfalls +--------------- + +Memory Leaks +~~~~~~~~~~~~ + +**Problem**: Forgetting to clear context + +.. code-block:: python + + # BAD: Context never cleared + def handle_request(): + logstructor.bind_context(request_id="req-123") + # ... process request ... + # Context remains in memory! + +**Solution**: Always use try/finally + +.. code-block:: python + + # GOOD: Context always cleared + def handle_request(): + try: + logstructor.bind_context(request_id="req-123") + # ... process request ... + finally: + logstructor.clear_context() + +Context Confusion +~~~~~~~~~~~~~~~~~ + +**Problem**: Expecting context to cross execution boundaries incorrectly + +.. code-block:: python + + # BAD: Context won't be available in the new thread + logstructor.bind_context(user_id=123) + + def background_task(): + logger.info("Background work") # No context here! + + thread = threading.Thread(target=background_task) + thread.start() + +**Solution**: Pass context explicitly or set it in each execution context + +.. code-block:: python + + # GOOD: Set context in each execution context + def background_task(context_data): + logstructor.bind_context(**context_data) + try: + logger.info("Background work") # Context available + finally: + logstructor.clear_context() + + context_data = logstructor.get_context() + thread = threading.Thread(target=background_task, args=(context_data,)) + thread.start() + +Next Steps +---------- + +- :doc:`json-formatting` - JSON formatting configuration +- :doc:`best-practices` - Production deployment patterns \ No newline at end of file diff --git a/docs/source/tutorial/getting-started.rst b/docs/source/tutorial/getting-started.rst new file mode 100644 index 0000000..c810df8 --- /dev/null +++ b/docs/source/tutorial/getting-started.rst @@ -0,0 +1,172 @@ +Getting Started +=============== + +This guide will get you up and running with LogStructor in under 5 minutes. + +.. code-block:: bash + + pip install logstructor + +Your First Structured Log +------------------------- + +Replace your standard logging import: + +.. code-block:: python + + # Before + import logging + logger = logging.getLogger(__name__) + + # After + import logstructor + logger = logstructor.getLogger(__name__) + +That's it! Your existing logging code continues to work unchanged. + +Adding Structure +---------------- + +Now enhance your logs with structured fields: + +.. code-block:: python + + import logstructor + + logger = logstructor.getLogger(__name__) + + # Standard logging still works + logger.info("Application started") + + # Add structured fields as keyword arguments + logger.error( + "Database connection failed", + host="db.example.com", + port=5432, + timeout_seconds=30, + retry_count=3 + ) + +LogStructor automatically configures JSON output - no manual setup needed: + +Custom Configuration (Optional) +------------------------------- + +If you need custom settings, use ``configure()``: + +.. code-block:: python + + import logstructor + + # Optional: Custom configuration + logstructor.configure( + level="DEBUG", + extra_fields={ + "service": "user-api", + "version": "1.2.3" + } + ) + + logger = logstructor.getLogger(__name__) + +Context Management +------------------ + +For web applications, use context to automatically include request-specific data: + +.. code-block:: python + + import logstructor + + logger = logstructor.getLogger(__name__) + + def handle_request(request): + # Set context once per request + logstructor.bind_context( + request_id=request.id, + user_id=request.user.id, + ip_address=request.remote_addr + ) + + try: + # All logs automatically include the context + logger.info("Processing request") + logger.info("Validating input", field="email") + logger.info("Database query", table="users", duration_ms=45) + logger.info("Request completed", status_code=200) + + finally: + # Clean up context when done + logstructor.clear_context() + +Async Support +------------- + +LogStructor works seamlessly with async/await: + +.. code-block:: python + + import asyncio + import logstructor + + logger = logstructor.getLogger(__name__) + + async def handle_async_request(): + logstructor.bind_context(request_id="req-123") + + await authenticate_user() # Context preserved across await + logger.info("User authenticated") + + await process_data() # Still has request_id + logger.info("Processing complete") + + logstructor.clear_context() + + # Context is isolated between concurrent tasks + async def main(): + tasks = [handle_async_request() for _ in range(10)] + await asyncio.gather(*tasks) # Each task has its own context + +Next Steps +---------- + +Now that you have LogStructor running, explore these guides to get the most out of structured logging: + +**Essential Reading:** + +- :doc:`basic-usage` - Learn all the fundamental features and patterns +- :doc:`context-management` - Master request-scoped context for web apps +- :doc:`json-formatting` - Understand JSON output and log aggregator integration + +**Advanced Topics:** + +- :doc:`best-practices` - Production-ready patterns and performance optimization + +**Quick Reference:** + +.. code-block:: python + + import logstructor + + # Get a logger (automatically configured) + logger = logstructor.getLogger(__name__) + + # Log with structured fields + logger.info("User action", user_id=123, action="login") + + # Set context for automatic inclusion + logstructor.bind_context(request_id="req-123") + logger.info("Processing") # Includes request_id automatically + + # Clean up when done + logstructor.clear_context() + +**Common Use Cases:** + +- **Web APIs**: Add request_id, user_id to every log +- **Microservices**: Include service name, version in all logs +- **Error Tracking**: Structure error logs for better analysis +- **Performance Monitoring**: Log response times, query durations +- **Async Applications**: Full support for asyncio and concurrent tasks + +Ready to dive deeper? Start with :doc:`basic-usage` to learn all the features! diff --git a/docs/source/tutorial/json-formatting.rst b/docs/source/tutorial/json-formatting.rst new file mode 100644 index 0000000..1877c69 --- /dev/null +++ b/docs/source/tutorial/json-formatting.rst @@ -0,0 +1,516 @@ +JSON Formatting +=============== + +LogStructor automatically configures structured JSON output - no manual setup required! This makes your logs immediately searchable and analyzable by log aggregation systems. + +Automatic JSON Output +--------------------- + +Simply use ``logstructor.getLogger()`` and your logs are automatically JSON: + +.. code-block:: python + + import logstructor + + # LogStructor automatically configures JSON formatting + logger = logstructor.getLogger(__name__) + + # Your logs are automatically structured JSON + logger.info("User logged in", user_id=123, ip="192.168.1.100") + +**Output:** + +.. code-block:: json + + { + "timestamp": "2025-01-08T10:30:45Z", + "level": "INFO", + "logger": "__main__", + "message": "User logged in", + "context": { + "user_id": 123, + "ip": "192.168.1.100" + } + } + +Custom Configuration (Optional) +------------------------------- + +If you need custom settings, use ``logstructor.configure()``: + +.. code-block:: python + + import logstructor + + # Optional: Custom configuration before creating loggers + logstructor.configure( + level="DEBUG", + timestamp_format="epoch", + extra_fields={ + "service": "user-api", + "version": "1.2.3" + } + ) + + # Now all loggers use your custom configuration + logger = logstructor.getLogger(__name__) + logger.info("Custom configured log", user_id=123) + +JSON Structure +-------------- + +Every JSON log entry has this consistent structure: + +Standard Fields +~~~~~~~~~~~~~~~ + +- **timestamp**: ISO 8601 timestamp or Unix epoch +- **level**: Log level (DEBUG, INFO, WARNING, ERROR, CRITICAL) +- **logger**: Logger name +- **message**: Human-readable log message + +Context Field +~~~~~~~~~~~~~ + +- **context**: Object containing all structured fields + +.. code-block:: json + + { + "timestamp": "2025-01-08T10:30:45Z", + "level": "ERROR", + "logger": "payment_service", + "message": "Payment processing failed", + "context": { + "user_id": 123, + "transaction_id": "txn_789", + "amount": 99.99, + "error_code": "INSUFFICIENT_FUNDS" + } + } + +Formatter Configuration +----------------------- + +Timestamp Formats +~~~~~~~~~~~~~~~~~ + +Choose between ISO 8601 and Unix epoch timestamps: + +.. code-block:: python + + from logstructor import StructFormatter + + # ISO 8601 format (default) + iso_formatter = StructFormatter(timestamp_format="iso") + # Output: "2025-01-08T10:30:45Z" + + # Unix epoch format + epoch_formatter = StructFormatter(timestamp_format="epoch") + # Output: 1704715845.123 + +Static Extra Fields +~~~~~~~~~~~~~~~~~~~ + +Add static fields to every log entry: + +.. code-block:: python + + formatter = StructFormatter(extra_fields={ + "service": "user-api", + "version": "1.2.3", + "environment": "production", + "datacenter": "us-east-1" + }) + + logger.info("Request processed", user_id=123) + +**Output:** + +.. code-block:: json + + { + "timestamp": "2025-01-08T10:30:45Z", + "level": "INFO", + "logger": "__main__", + "message": "Request processed", + "context": { + "service": "user-api", + "version": "1.2.3", + "environment": "production", + "datacenter": "us-east-1", + "user_id": 123 + } + } + +Context Field Behavior +---------------------- + +When Context is Included +~~~~~~~~~~~~~~~~~~~~~~~~ + +The ``context`` field appears when there are structured fields to include: + +.. code-block:: python + + # No context field (no structured data) + logger.info("Simple message") + # → {"timestamp": "...", "level": "INFO", "message": "Simple message"} + + # Context field included + logger.info("User action", user_id=123) + # → {"timestamp": "...", "level": "INFO", "message": "User action", "context": {"user_id": 123}} + +Context Sources +~~~~~~~~~~~~~~~ + +The context field combines data from multiple sources: + +1. **Context data** (from ``bind_context()``) +2. **Static extra fields** (from formatter configuration) +3. **Structured fields** (from log call keyword arguments) + +.. code-block:: python + + # Set up static fields + formatter = StructFormatter(extra_fields={"service": "api"}) + + # Set context data + logstructor.bind_context(request_id="req-123") + + # Log with structured fields + logger.info("Processing", user_id=456, action="login") + +**Output:** + +.. code-block:: json + + { + "timestamp": "2025-01-08T10:30:45Z", + "level": "INFO", + "logger": "__main__", + "message": "Processing", + "context": { + "service": "api", + "request_id": "req-123", + "user_id": 456, + "action": "login" + } + } + +Data Type Handling +------------------ + +LogStructor automatically serializes Python data types to JSON: + +Basic Types +~~~~~~~~~~~ + +.. code-block:: python + + logger.info("Data types", + string_val="hello", + int_val=42, + float_val=3.14, + bool_val=True, + null_val=None) + +**Output:** + +.. code-block:: json + + { + "context": { + "string_val": "hello", + "int_val": 42, + "float_val": 3.14, + "bool_val": true, + "null_val": null + } + } + +Complex Types +~~~~~~~~~~~~~ + +.. code-block:: python + + from datetime import datetime + + logger.info("Complex types", + timestamp=datetime.now(), + list_data=[1, 2, "three"], + dict_data={"nested": {"key": "value"}}) + +**Output:** + +.. code-block:: json + + { + "context": { + "timestamp": "2025-01-08T10:30:45.123456", + "list_data": [1, 2, "three"], + "dict_data": { + "nested": { + "key": "value" + } + } + } + } + +Custom Objects +~~~~~~~~~~~~~~ + +Objects are converted using their string representation: + +.. code-block:: python + + class User: + def __init__(self, id, name): + self.id = id + self.name = name + + def __str__(self): + return f"User(id={self.id}, name={self.name})" + + user = User(123, "alice") + logger.info("User created", user_obj=user) + +**Output:** + +.. code-block:: json + + { + "context": { + "user_obj": "User(id=123, name=alice)" + } + } + +Multiple Handlers +----------------- + +Use different formatters for different outputs: + +.. code-block:: python + + import logging + from logstructor import StructFormatter + + logger = logstructor.getLogger(__name__) + + # Console handler with human-readable format + console_handler = logging.StreamHandler() + console_formatter = logging.Formatter('%(asctime)s - %(levelname)s - %(message)s') + console_handler.setFormatter(console_formatter) + + # File handler with JSON format + file_handler = logging.FileHandler('app.log') + json_formatter = StructFormatter() + file_handler.setFormatter(json_formatter) + + # Add both handlers + logger.addHandler(console_handler) + logger.addHandler(file_handler) + + # This log goes to both console (human-readable) and file (JSON) + logger.info("Application started", version="1.0.0", port=8080) + +Log Aggregator Integration +--------------------------- + +ELK Stack (Elasticsearch, Logstash, Kibana) +~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ + +Configure Logstash to parse LogStructor JSON: + +.. code-block:: ruby + + # logstash.conf + input { + file { + path => "/var/log/app.log" + codec => "json" + } + } + + filter { + # LogStructor logs are already structured + # No additional parsing needed + } + + output { + elasticsearch { + hosts => ["localhost:9200"] + index => "app-logs-%{+YYYY.MM.dd}" + } + } + +Query in Kibana: + +.. code-block:: text + + context.user_id:123 + level:ERROR + context.response_time_ms:>1000 + +Splunk +~~~~~~ + +LogStructor JSON works directly with Splunk: + +.. code-block:: text + + # Search for user actions + index=app_logs context.user_id=123 + + # Find slow requests + index=app_logs context.response_time_ms>1000 + + # Error analysis + index=app_logs level=ERROR | stats count by context.error_code + +Datadog +~~~~~~~ + +Configure Datadog agent to parse JSON logs: + +.. code-block:: yaml + + # datadog.yaml + logs: + - type: file + path: /var/log/app.log + service: my-app + source: python + sourcecategory: sourcecode + +Query in Datadog: + +.. code-block:: text + + @context.user_id:123 + @level:ERROR + @context.response_time_ms:>1000 + +Performance Considerations +-------------------------- + +JSON Serialization Overhead +~~~~~~~~~~~~~~~~~~~~~~~~~~~~ + +JSON formatting adds minimal overhead: + +.. code-block:: python + + # Benchmark results (approximate) + # Standard logging: 100,000 msgs/sec + # LogStructor JSON: 85,000 msgs/sec + # Overhead: ~15% + +Optimization Tips +~~~~~~~~~~~~~~~~~ + +1. **Use simple data types** when possible: + +.. code-block:: python + + # Faster + logger.info("User action", user_id=123, action="login") + + # Slower (complex object serialization) + logger.info("User action", user_object=complex_user_object) + +2. **Avoid deep nesting**: + +.. code-block:: python + + # Better + logger.info("Order", order_id=order.id, customer_id=order.customer_id) + + # Avoid + logger.info("Order", order_data=order.to_dict()) # If deeply nested + +3. **Use appropriate log levels**: + +.. code-block:: python + + # Only serialize debug data when needed + if logger.isEnabledFor(logging.DEBUG): + logger.debug("Debug info", expensive_data=calculate_debug_data()) + +Unicode and Special Characters +------------------------------ + +LogStructor handles Unicode correctly: + +.. code-block:: python + + logger.info("International user", + username="José María", + message="Hello 世界 🌍", + emoji_reaction="👍") + +**Output:** + +.. code-block:: json + + { + "context": { + "username": "José María", + "message": "Hello 世界 🌍", + "emoji_reaction": "👍" + } + } + +Error Handling +-------------- + +The formatter handles serialization errors gracefully: + +.. code-block:: python + + class UnserializableObject: + def __init__(self): + self.file_handle = open("somefile.txt") + + # This won't crash - uses str() fallback + logger.info("Problematic object", obj=UnserializableObject()) + +Custom Formatter Example +------------------------- + +Create a custom formatter for specific needs: + +.. code-block:: python + + import json + import logging + from datetime import datetime, timezone + from logstructor import StructFormatter + + class CustomStructFormatter(StructFormatter): + """Custom formatter with additional fields""" + + def format(self, record): + # Get the base JSON structure + log_entry = json.loads(super().format(record)) + + # Add custom fields + log_entry["hostname"] = "server-01" + log_entry["environment"] = "production" + log_entry["version"] = "1.2.3" + + # Custom timestamp format + log_entry["@timestamp"] = datetime.now(timezone.utc).isoformat() + + return json.dumps(log_entry, ensure_ascii=False) + + # Use custom formatter + handler = logging.StreamHandler() + handler.setFormatter(CustomStructFormatter()) + logger.addHandler(handler) + +Next Steps +---------- + +- :doc:`context-management` - Learn about context management +- :doc:`best-practices` - Production deployment patterns \ No newline at end of file diff --git a/examples/01_tutorial.ipynb b/examples/01_tutorial.ipynb new file mode 100644 index 0000000..124ae1c --- /dev/null +++ b/examples/01_tutorial.ipynb @@ -0,0 +1,122 @@ +{ + "cells": [ + { + "cell_type": "markdown", + "metadata": {}, + "source": [ + "# LogStructor Quick Start\n", + "\n", + "Get started with structured logging in 5 minutes." + ] + }, + { + "cell_type": "code", + "execution_count": null, + "metadata": {}, + "outputs": [], + "source": [ + "# !pip install logstructor\n", + "import logstructor\n", + "import logging\n", + "import sys\n", + "\n", + "# Setup\n", + "logging.basicConfig(level=logging.INFO, stream=sys.stdout)\n", + "logger = logstructor.getLogger(__name__)" + ] + }, + { + "cell_type": "markdown", + "metadata": {}, + "source": [ + "## 1. Drop-in Replacement" + ] + }, + { + "cell_type": "code", + "execution_count": null, + "metadata": {}, + "outputs": [], + "source": [ + "# Your existing code works unchanged\n", + "logger.info(\"Application started\")\n", + "logger.error(\"Something went wrong\")" + ] + }, + { + "cell_type": "markdown", + "metadata": {}, + "source": [ + "## 2. Add Structure" + ] + }, + { + "cell_type": "code", + "execution_count": null, + "metadata": {}, + "outputs": [], + "source": [ + "# Add structured fields as keyword arguments\n", + "logger.info(\"User logged in\", user_id=123, ip=\"192.168.1.100\")\n", + "logger.error(\"Payment failed\", user_id=456, amount=99.99, error_code=\"DECLINED\")" + ] + }, + { + "cell_type": "markdown", + "metadata": {}, + "source": [ + "## 3. Context Management" + ] + }, + { + "cell_type": "code", + "execution_count": null, + "metadata": {}, + "outputs": [], + "source": [ + "# Set context once - included in all logs\n", + "logstructor.bind_context(request_id=\"req-456\", user_id=123)\n", + "\n", + "logger.info(\"Processing request\")\n", + "logger.info(\"Database query\", table=\"users\", duration_ms=45)\n", + "logger.info(\"Request completed\", status_code=200)\n", + "\n", + "# Clean up\n", + "logstructor.clear_context()" + ] + }, + { + "cell_type": "markdown", + "metadata": {}, + "source": [ + "## That's It!\n", + "\n", + "You now have:\n", + "- ✅ Structured, searchable logs\n", + "- ✅ JSON output for log aggregators\n", + "- ✅ Automatic context tracking\n", + "- ✅ Zero breaking changes\n", + "\n", + "Query your logs like:\n", + "```bash\n", + "user_id:123\n", + "level:ERROR\n", + "context.amount:>50\n", + "```" + ] + } + ], + "metadata": { + "kernelspec": { + "display_name": "Python 3", + "language": "python", + "name": "python3" + }, + "language_info": { + "name": "python", + "version": "3.11.0" + } + }, + "nbformat": 4, + "nbformat_minor": 4 +} diff --git a/examples/02_migration_guide.ipynb b/examples/02_migration_guide.ipynb new file mode 100644 index 0000000..6d70272 --- /dev/null +++ b/examples/02_migration_guide.ipynb @@ -0,0 +1,177 @@ +{ + "cells": [ + { + "cell_type": "markdown", + "metadata": {}, + "source": [ + "# Migration from Standard Logging\n", + "\n", + "Step-by-step migration guide with before/after examples." + ] + }, + { + "cell_type": "markdown", + "metadata": {}, + "source": [ + "## Step 1: Before (Standard Logging)" + ] + }, + { + "cell_type": "code", + "execution_count": null, + "metadata": {}, + "outputs": [], + "source": [ + "import logging\n", + "import sys\n", + "\n", + "logging.basicConfig(level=logging.INFO, stream=sys.stdout)\n", + "logger = logging.getLogger(__name__)\n", + "\n", + "# Your current code\n", + "def process_user_login(username, user_id, ip_address):\n", + " logger.info(f\"User {username} (ID: {user_id}) logged in from {ip_address}\")\n", + "\n", + "def handle_error(operation, error_msg, user_id=None):\n", + " logger.error(f\"Error in {operation} for user {user_id}: {error_msg}\")\n", + "\n", + "# Test current logging\n", + "process_user_login(\"alice\", 123, \"192.168.1.100\")\n", + "handle_error(\"payment\", \"Card declined\", 123)" + ] + }, + { + "cell_type": "markdown", + "metadata": {}, + "source": [ + "**Problems:** Hard to search, no filtering, string parsing needed" + ] + }, + { + "cell_type": "markdown", + "metadata": {}, + "source": [ + "## Step 2: Drop-in Replacement" + ] + }, + { + "cell_type": "code", + "execution_count": null, + "metadata": {}, + "outputs": [], + "source": [ + "# Just change the import!\n", + "import logstructor\n", + "\n", + "logger = logstructor.getLogger(__name__)\n", + "\n", + "# Same functions work unchanged\n", + "process_user_login(\"alice\", 123, \"192.168.1.100\")\n", + "handle_error(\"payment\", \"Card declined\", 123)\n", + "\n", + "print(\"✅ Existing code works unchanged!\")" + ] + }, + { + "cell_type": "markdown", + "metadata": {}, + "source": [ + "## Step 3: Add Structure" + ] + }, + { + "cell_type": "code", + "execution_count": null, + "metadata": {}, + "outputs": [], + "source": [ + "# Enhanced with structured fields\n", + "def process_user_login_v2(username, user_id, ip_address):\n", + " logger.info(\n", + " \"User logged in\",\n", + " user_id=user_id,\n", + " username=username,\n", + " ip_address=ip_address,\n", + " event_type=\"login\"\n", + " )\n", + "\n", + "def handle_error_v2(operation, error_msg, user_id=None, error_code=None):\n", + " logger.error(\n", + " \"Operation failed\",\n", + " operation=operation,\n", + " error_message=error_msg,\n", + " user_id=user_id,\n", + " error_code=error_code\n", + " )\n", + "\n", + "process_user_login_v2(\"alice\", 123, \"192.168.1.100\")\n", + "handle_error_v2(\"payment\", \"Card declined\", 123, \"CC_DECLINED\")" + ] + }, + { + "cell_type": "markdown", + "metadata": {}, + "source": [ + "## Step 4: Add Context Management" + ] + }, + { + "cell_type": "code", + "execution_count": null, + "metadata": {}, + "outputs": [], + "source": [ + "def simulate_web_request(request_id, user_id):\n", + " # Set context once\n", + " logstructor.bind_context(request_id=request_id, user_id=user_id)\n", + " \n", + " try:\n", + " # All logs automatically include context\n", + " json_logger.info(\"Request started\")\n", + " json_logger.info(\"Processing\", step=\"validation\")\n", + " json_logger.info(\"Request completed\", status_code=200)\n", + " finally:\n", + " logstructor.clear_context()\n", + "\n", + "simulate_web_request(\"req-123\", 456)" + ] + }, + { + "cell_type": "markdown", + "metadata": {}, + "source": [ + "## Benefits After Migration\n", + "\n", + "✅ **Searchable logs**: `user_id:123` \n", + "✅ **Better debugging**: Context automatically included \n", + "✅ **Business insights**: Query logs like a database \n", + "✅ **Faster incident response**: Structured alerts \n", + "\n", + "**Query examples:**\n", + "```bash\n", + "# Find all actions by user 123\n", + "context.user_id:123\n", + "\n", + "# Find all errors\n", + "level:ERROR\n", + "\n", + "# Find payment errors\n", + "context.operation:\"payment\" AND level:ERROR\n", + "```" + ] + } + ], + "metadata": { + "kernelspec": { + "display_name": "Python 3", + "language": "python", + "name": "python3" + }, + "language_info": { + "name": "python", + "version": "3.11.0" + } + }, + "nbformat": 4, + "nbformat_minor": 4 +} diff --git a/examples/03_performance_comparison.ipynb b/examples/03_performance_comparison.ipynb new file mode 100644 index 0000000..e30ffa9 --- /dev/null +++ b/examples/03_performance_comparison.ipynb @@ -0,0 +1,216 @@ +{ + "cells": [ + { + "cell_type": "markdown", + "metadata": {}, + "source": [ + "# LogStructor Performance Comparison\n", + "\n", + "Quick benchmarks showing LogStructor's performance characteristics." + ] + }, + { + "cell_type": "code", + "execution_count": null, + "metadata": {}, + "outputs": [], + "source": [ + "import time\n", + "import logging\n", + "import logstructor\n", + "import io\n", + "import sys\n", + "\n", + "def setup_standard_logger():\n", + " logger = logging.getLogger(\"standard_bench\")\n", + " logger.handlers = [logging.StreamHandler(io.StringIO())]\n", + " logger.setLevel(logging.INFO)\n", + " return logger\n", + "\n", + "def setup_struct_logger():\n", + " logger = logstructor.getLogger(\"struct_bench\")\n", + " return logger" + ] + }, + { + "cell_type": "markdown", + "metadata": {}, + "source": [ + "## Benchmark 1: Simple Messages" + ] + }, + { + "cell_type": "code", + "execution_count": null, + "metadata": {}, + "outputs": [], + "source": [ + "def benchmark_simple(iterations=10000):\n", + " # Standard logging\n", + " std_logger = setup_standard_logger()\n", + " start = time.perf_counter()\n", + " for i in range(iterations):\n", + " std_logger.info(\"Simple message\")\n", + " std_time = time.perf_counter() - start\n", + " \n", + " # LogStructor\n", + " struct_logger = setup_struct_logger()\n", + " start = time.perf_counter()\n", + " for i in range(iterations):\n", + " struct_logger.info(\"Simple message\")\n", + " struct_time = time.perf_counter() - start\n", + " \n", + " overhead = ((struct_time - std_time) / std_time) * 100\n", + " \n", + " print(f\"Simple Messages ({iterations:,} iterations):\")\n", + " print(f\" Standard: {std_time:.4f}s ({iterations/std_time:,.0f} msg/sec)\")\n", + " print(f\" LogStructor: {struct_time:.4f}s ({iterations/struct_time:,.0f} msg/sec)\")\n", + " print(f\" Overhead: {overhead:+.1f}%\")\n", + " \n", + " return overhead\n", + "\n", + "simple_overhead = benchmark_simple()" + ] + }, + { + "cell_type": "markdown", + "metadata": {}, + "source": [ + "## Benchmark 2: Structured Data" + ] + }, + { + "cell_type": "code", + "execution_count": null, + "metadata": {}, + "outputs": [], + "source": [ + "def benchmark_structured(iterations=10000):\n", + " # Standard with f-strings\n", + " std_logger = setup_standard_logger()\n", + " start = time.perf_counter()\n", + " for i in range(iterations):\n", + " std_logger.info(f\"User {123} performed action login from 192.168.1.100\")\n", + " std_time = time.perf_counter() - start\n", + " \n", + " # LogStructor with structured fields\n", + " struct_logger = setup_struct_logger()\n", + " start = time.perf_counter()\n", + " for i in range(iterations):\n", + " struct_logger.info(\"User performed action\", user_id=123, action=\"login\", ip=\"192.168.1.100\")\n", + " struct_time = time.perf_counter() - start\n", + " \n", + " overhead = ((struct_time - std_time) / std_time) * 100\n", + " \n", + " print(f\"\\nStructured Data ({iterations:,} iterations):\")\n", + " print(f\" Standard (f-string): {std_time:.4f}s ({iterations/std_time:,.0f} msg/sec)\")\n", + " print(f\" LogStructor (JSON): {struct_time:.4f}s ({iterations/struct_time:,.0f} msg/sec)\")\n", + " print(f\" Overhead: {overhead:+.1f}%\")\n", + " \n", + " return overhead\n", + "\n", + "structured_overhead = benchmark_structured()" + ] + }, + { + "cell_type": "markdown", + "metadata": {}, + "source": [ + "## Benchmark 3: Context Management" + ] + }, + { + "cell_type": "code", + "execution_count": null, + "metadata": {}, + "outputs": [], + "source": [ + "def benchmark_context(iterations=10000):\n", + " # Without context\n", + " struct_logger = setup_struct_logger()\n", + " start = time.perf_counter()\n", + " for i in range(iterations):\n", + " struct_logger.info(\"Message\", iteration=i)\n", + " no_context_time = time.perf_counter() - start\n", + " \n", + " # With context\n", + " logstructor.bind_context(request_id=\"req-123\", user_id=456)\n", + " start = time.perf_counter()\n", + " for i in range(iterations):\n", + " struct_logger.info(\"Message\", iteration=i)\n", + " with_context_time = time.perf_counter() - start\n", + " logstructor.clear_context()\n", + " \n", + " context_overhead = ((with_context_time - no_context_time) / no_context_time) * 100\n", + " \n", + " print(f\"\\nContext Management ({iterations:,} iterations):\")\n", + " print(f\" Without context: {no_context_time:.4f}s ({iterations/no_context_time:,.0f} msg/sec)\")\n", + " print(f\" With context: {with_context_time:.4f}s ({iterations/with_context_time:,.0f} msg/sec)\")\n", + " print(f\" Context overhead: {context_overhead:+.1f}%\")\n", + " \n", + " return context_overhead\n", + "\n", + "context_overhead = benchmark_context()" + ] + }, + { + "cell_type": "markdown", + "metadata": {}, + "source": [ + "## Performance Summary" + ] + }, + { + "cell_type": "code", + "execution_count": null, + "metadata": {}, + "outputs": [], + "source": [ + "import statistics\n", + "\n", + "avg_overhead = statistics.mean([simple_overhead, structured_overhead])\n", + "\n", + "print(\"\\n\" + \"=\" * 50)\n", + "print(\" PERFORMANCE SUMMARY\")\n", + "print(\"=\" * 50)\n", + "\n", + "print(f\"\\n📊 THROUGHPUT OVERHEAD:\")\n", + "print(f\" Simple messages: {simple_overhead:+.1f}%\")\n", + "print(f\" Structured data: {structured_overhead:+.1f}%\")\n", + "print(f\" Context management: {context_overhead:+.1f}%\")\n", + "print(f\"\\n 📈 Average overhead: {avg_overhead:+.1f}%\")\n", + "\n", + "print(f\"\\n🎯 VERDICT:\")\n", + "if avg_overhead < 10:\n", + " verdict = \"EXCELLENT - Minimal overhead for massive value\"\n", + "elif avg_overhead < 20:\n", + " verdict = \"GOOD - Reasonable overhead for structured logging\"\n", + "else:\n", + " verdict = \"ACCEPTABLE - Higher overhead but still usable\"\n", + "\n", + "print(f\" {verdict}\")\n", + "\n", + "print(f\"\\n✅ RECOMMENDATIONS:\")\n", + "print(f\" • LogStructor adds ~{avg_overhead:.0f}% overhead on average\")\n", + "print(f\" • Perfect for most applications (< 20% overhead)\")\n", + "print(f\" • The structured data benefits far outweigh the cost\")\n", + "print(f\" • Context management adds minimal extra cost\")\n", + "\n", + "print(\"\\n\" + \"=\" * 50)" + ] + } + ], + "metadata": { + "kernelspec": { + "display_name": "Python 3", + "language": "python", + "name": "python3" + }, + "language_info": { + "name": "python", + "version": "3.11.0" + } + }, + "nbformat": 4, + "nbformat_minor": 4 +} diff --git a/junit.xml b/junit.xml deleted file mode 100644 index da92dc6..0000000 --- a/junit.xml +++ /dev/null @@ -1 +0,0 @@ - \ No newline at end of file diff --git a/logstructor/context.py b/logstructor/context.py index e0ad847..a25f904 100644 --- a/logstructor/context.py +++ b/logstructor/context.py @@ -1,26 +1,28 @@ """ -Thread-local context management for structured logging. - -This module provides functions to bind context data to the current thread, -which will be automatically included in all log entries within that thread. -This is particularly useful for web applications where you want to include -request-specific data (like request_id, user_id) in all logs without -passing them explicitly to every logging call. +Context management for structured logging using contextvars. + +This module provides functions to bind context data to the current context, +which will be automatically included in all log entries within that context. +This works with both synchronous and asynchronous code and is the modern +replacement for thread-local storage. It's particularly useful for web +applications where you want to include request-specific data (like request_id, +user_id) in all logs without passing them explicitly to every logging call. """ -import threading +import contextvars from typing import Any, Dict -# Thread-local storage for context data -_context = threading.local() +# Context variable for storing logging context data +_context_data: contextvars.ContextVar[Dict[str, Any]] = contextvars.ContextVar("logging_context", default={}) def bind_context(**kwargs) -> None: """ - Bind key-value pairs to the current thread's logging context. + Bind key-value pairs to the current context's logging context. These fields will be automatically included in all subsequent log entries - within the current thread until cleared or overwritten. + within the current context until cleared or overwritten. Works with both + synchronous and asynchronous code. Args: **kwargs: Key-value pairs to bind to the context @@ -34,18 +36,23 @@ def bind_context(**kwargs) -> None: >>> bind_context(request_id=request.id, user_id=request.user.id, ip=request.remote_addr) >>> logger.info("User login attempt") # Automatically includes all context + Async usage: + >>> async def handle_request(): + ... bind_context(request_id="req-123") + ... await process_request() # Context is preserved across await calls + Overwriting context: >>> bind_context(user_id=123) >>> bind_context(user_id=456) # Overwrites previous user_id """ - if not hasattr(_context, "data"): - _context.data = {} - _context.data.update(kwargs) + current_context = _context_data.get().copy() + current_context.update(kwargs) + _context_data.set(current_context) def clear_context() -> None: """ - Clear all context data for the current thread. + Clear all context data for the current context. This removes all previously bound context fields. Subsequent log entries will not include any context data until new fields are bound. @@ -61,14 +68,21 @@ def clear_context() -> None: ... bind_context(request_id=generate_id()) ... # ... process request ... ... clear_context() # Clean up when done + + Async cleanup: + >>> async def handle_async_request(): + ... bind_context(request_id=generate_id()) + ... try: + ... await process_request() + ... finally: + ... clear_context() # Always clean up """ - if hasattr(_context, "data"): - _context.data.clear() + _context_data.set({}) def get_context() -> Dict[str, Any]: """ - Get current thread's context data. + Get current context's context data. Returns a copy of the current context dictionary. This is primarily used internally by the formatter, but can be useful for debugging @@ -88,10 +102,14 @@ def get_context() -> Dict[str, Any]: ... logger.info("User-specific operation") ... else: ... logger.info("Anonymous operation") + + Async usage: + >>> async def some_async_function(): + ... context = get_context() + ... if context.get('request_id'): + ... await log_request_specific_data() """ - if not hasattr(_context, "data"): - _context.data = {} - return _context.data.copy() + return _context_data.get().copy() def update_context(**kwargs) -> None: @@ -108,5 +126,12 @@ def update_context(**kwargs) -> None: >>> bind_context(request_id="req-123") >>> update_context(user_id=456, action="login") >>> # Context now has: request_id, user_id, action + + Async example: + >>> async def process_user_action(): + ... bind_context(request_id="req-123") + ... await authenticate_user() + ... update_context(user_id=456, authenticated=True) + ... await perform_action() """ bind_context(**kwargs) diff --git a/pyproject.toml b/pyproject.toml index bd707b9..9333747 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -19,6 +19,7 @@ linting = ["mypy>=1.17.1", "ruff>=0.12.7"] test = [ "pytest>=8.4.1", "pytest-cov>=6.2.1", + "pytest-asyncio>=0.24.0", ] [build-system] diff --git a/tests/test_context.py b/tests/test_context.py index e4e6ab5..8ff9525 100644 --- a/tests/test_context.py +++ b/tests/test_context.py @@ -1,9 +1,10 @@ """ Tests for structlogger.context module. -Tests thread-local context management functionality. +Tests context management functionality using contextvars. """ +import asyncio import threading import time from concurrent.futures import ThreadPoolExecutor @@ -89,8 +90,8 @@ def test_empty_context_initially(): assert isinstance(context, dict) -def test_thread_local_isolation(): - """Test that context is isolated between threads.""" +def test_context_isolation_between_threads(): + """Test that context is isolated between threads with contextvars.""" results = {} def thread_function(thread_id): @@ -185,3 +186,64 @@ def test_context_with_empty_values(): assert context["false_val"] is False assert context["empty_list"] == [] assert context["empty_dict"] == {} + + +@pytest.mark.asyncio +async def test_async_context_isolation(): + """Test that context is properly isolated in async functions.""" + results = {} + + async def async_function(task_id): + # Each async task sets its own context + bind_context(task_id=task_id, data=f"task-{task_id}") + + # Simulate async work + await asyncio.sleep(0.1) + + # Context should be preserved across await + results[task_id] = get_context() + + # Run multiple async tasks concurrently + tasks = [async_function(i) for i in range(3)] + await asyncio.gather(*tasks) + + # Verify each task had its own context + assert len(results) == 3 + for i in range(3): + assert results[i]["task_id"] == i + assert results[i]["data"] == f"task-{i}" + + +@pytest.mark.asyncio +async def test_async_context_persistence(): + """Test that context persists across multiple await calls.""" + bind_context(request_id="req-123", user_id=456) + + async def check_context(): + await asyncio.sleep(0.01) + return get_context() + + # Context should persist across multiple async calls + context1 = await check_context() + context2 = await check_context() + + assert context1["request_id"] == "req-123" + assert context1["user_id"] == 456 + assert context2 == context1 + + +@pytest.mark.asyncio +async def test_async_context_updates(): + """Test updating context in async functions.""" + bind_context(request_id="req-123") + + async def update_user_context(): + await asyncio.sleep(0.01) + update_context(user_id=456, authenticated=True) + + await update_user_context() + + context = get_context() + assert context["request_id"] == "req-123" + assert context["user_id"] == 456 + assert context["authenticated"] is True diff --git a/uv.lock b/uv.lock index 64f04c8..2ea75de 100644 --- a/uv.lock +++ b/uv.lock @@ -256,6 +256,7 @@ linting = [ ] test = [ { name = "pytest" }, + { name = "pytest-asyncio" }, { name = "pytest-cov" }, ] @@ -273,6 +274,7 @@ linting = [ ] test = [ { name = "pytest", specifier = ">=8.4.1" }, + { name = "pytest-asyncio", specifier = ">=0.24.0" }, { name = "pytest-cov", specifier = ">=6.2.1" }, ] @@ -492,6 +494,18 @@ wheels = [ { url = "https://files.pythonhosted.org/packages/29/16/c8a903f4c4dffe7a12843191437d7cd8e32751d5de349d45d3fe69544e87/pytest-8.4.1-py3-none-any.whl", hash = "sha256:539c70ba6fcead8e78eebbf1115e8b589e7565830d7d006a8723f19ac8a0afb7", size = 365474 }, ] +[[package]] +name = "pytest-asyncio" +version = "1.1.0" +source = { registry = "https://pypi.org/simple" } +dependencies = [ + { name = "pytest" }, +] +sdist = { url = "https://files.pythonhosted.org/packages/4e/51/f8794af39eeb870e87a8c8068642fc07bce0c854d6865d7dd0f2a9d338c2/pytest_asyncio-1.1.0.tar.gz", hash = "sha256:796aa822981e01b68c12e4827b8697108f7205020f24b5793b3c41555dab68ea", size = 46652 } +wheels = [ + { url = "https://files.pythonhosted.org/packages/c7/9d/bf86eddabf8c6c9cb1ea9a869d6873b46f105a5d292d3a6f7071f5b07935/pytest_asyncio-1.1.0-py3-none-any.whl", hash = "sha256:5fe2d69607b0bd75c656d1211f969cadba035030156745ee09e7d71740e58ecf", size = 15157 }, +] + [[package]] name = "pytest-cov" version = "6.2.1"