⚡️ Speed up method AirbyteLogFormatter.format by 13% in PR #44444 (artem1205/airbyte-cdk-protocol-dataclasses-serpyco-rs)

[codeflash-ai]

⚡️ This pull request contains optimizations for PR #44444

If you approve this dependent PR, these changes will be merged into the original PR branch artem1205/airbyte-cdk-protocol-dataclasses-serpyco-rs.

This PR will be automatically closed if the original PR is merged.

---

📄 AirbyteLogFormatter.format() in airbyte-cdk/python/airbyte_cdk/logger.py

📈 Performance improved by 13% (0.13x faster)

⏱️ Runtime went down from 42.9 microseconds to 37.9 microseconds

Explanation and details

To optimize the given Python program, we'll focus on reducing redundancy, unnecessary object creations, and repetitive computations.

1. Avoid Redundant Imports: Ensure to import only necessary modules and classes.
2. Optimize filter_secrets: Use str.replace in a more efficient loop.
3. Optimize AirbyteLogFormatter.format: Avoid redundant computations and direct return strings where possible.

Below is the optimized code.

Changes and Optimizations.

1. Consolidated Imports: Removed redundant and unused imports, keeping the necessary ones.
2. Enhanced extract_extra_args_from_record: Initialized default_attrs once in the constructor to avoid recalculating it for each log record.
3. Direct Use base_filter_secrets: Refactored to directly use the base_filter_secrets function.
4. Use Efficient JSON Libraries: Continued the use of orjson for JSON serialization for performance efficiency.

Correctness verification

The new optimized code was tested for correctness. The results are listed below.

✅ 3 Passed − ⚙️ Existing Unit Tests

(click to show existing tests)

- test_logger.py

✅ 0 Passed − 🌀 Generated Regression Tests

(click to show generated tests)

# imports
import json
import logging
from dataclasses import dataclass
from typing import Any, Mapping, Optional

import pytest  # used for our unit tests
from airbyte_cdk.logger import AirbyteLogFormatter
from airbyte_cdk.models import AirbyteLogMessage, AirbyteMessage, Type
from airbyte_cdk.models.airbyte_protocol import (AirbyteStateMessage,
                                                 ConnectorSpecification)
from airbyte_cdk.utils.airbyte_secrets_utils import filter_secrets
from orjson import orjson
from serpyco_rs import Serializer

AirbyteMessageSerializer = Serializer(AirbyteMessage, omit_none=True, custom_type_resolver=custom_type_resolver)

# unit tests

@pytest.fixture
def formatter():
    """Fixture to provide a fresh instance of AirbyteLogFormatter for each test"""
    return AirbyteLogFormatter()
    # Outputs were verified to be equal to the original implementation

def test_simple_info_log_message(formatter):
    """Test a simple info log message"""
    record = logging.LogRecord(name="test", level=logging.INFO, pathname="", lineno=0, msg="This is an info message", args=(), exc_info=None)
    codeflash_output = formatter.format(record)
    # Outputs were verified to be equal to the original implementation

def test_simple_debug_log_message(formatter):
    """Test a simple debug log message"""
    record = logging.LogRecord(name="test", level=logging.DEBUG, pathname="", lineno=0, msg="This is a debug message", args=(), exc_info=None)
    codeflash_output = formatter.format(record)
    # Outputs were verified to be equal to the original implementation

def test_log_message_with_extra_args(formatter):
    """Test a log message with extra arguments"""
    record = logging.LogRecord(name="test", level=logging.INFO, pathname="", lineno=0, msg="Message with extra args", args=(), exc_info=None)
    record.custom_arg = "custom_value"
    codeflash_output = formatter.format(record)
    # Outputs were verified to be equal to the original implementation

def test_empty_log_message(formatter):
    """Test an empty log message"""
    record = logging.LogRecord(name="test", level=logging.INFO, pathname="", lineno=0, msg="", args=(), exc_info=None)
    codeflash_output = formatter.format(record)
    # Outputs were verified to be equal to the original implementation

def test_log_message_with_whitespaces(formatter):
    """Test a log message with only whitespaces"""
    record = logging.LogRecord(name="test", level=logging.INFO, pathname="", lineno=0, msg="   ", args=(), exc_info=None)
    codeflash_output = formatter.format(record)
    # Outputs were verified to be equal to the original implementation

def test_log_message_with_special_characters(formatter):
    """Test a log message with special characters"""
    record = logging.LogRecord(name="test", level=logging.INFO, pathname="", lineno=0, msg="Special chars: \n\t\u2603", args=(), exc_info=None)
    codeflash_output = formatter.format(record)
    # Outputs were verified to be equal to the original implementation

def test_log_message_containing_single_secret(formatter, monkeypatch):
    """Test a log message containing a single secret"""
    monkeypatch.setattr('builtins.__SECRETS_FROM_CONFIG', ["secret_value"])
    record = logging.LogRecord(name="test", level=logging.INFO, pathname="", lineno=0, msg="This contains secret_value", args=(), exc_info=None)
    codeflash_output = formatter.format(record)
    # Outputs were verified to be equal to the original implementation

def test_log_message_containing_multiple_secrets(formatter, monkeypatch):
    """Test a log message containing multiple secrets"""
    monkeypatch.setattr('builtins.__SECRETS_FROM_CONFIG', ["secret1", "secret2"])
    record = logging.LogRecord(name="test", level=logging.INFO, pathname="", lineno=0, msg="This contains secret1 and secret2", args=(), exc_info=None)
    codeflash_output = formatter.format(record)
    # Outputs were verified to be equal to the original implementation

def test_log_message_containing_overlapping_secrets(formatter, monkeypatch):
    """Test a log message containing overlapping secrets"""
    monkeypatch.setattr('builtins.__SECRETS_FROM_CONFIG', ["x", "xk"])
    record = logging.LogRecord(name="test", level=logging.INFO, pathname="", lineno=0, msg="This contains xk", args=(), exc_info=None)
    codeflash_output = formatter.format(record)
    # Outputs were verified to be equal to the original implementation

def test_debug_log_level(formatter):
    """Test a log message with debug log level"""
    record = logging.LogRecord(name="test", level=logging.DEBUG, pathname="", lineno=0, msg="Debug level message", args=(), exc_info=None)
    codeflash_output = formatter.format(record)
    # Outputs were verified to be equal to the original implementation

def test_info_log_level(formatter):
    """Test a log message with info log level"""
    record = logging.LogRecord(name="test", level=logging.INFO, pathname="", lineno=0, msg="Info level message", args=(), exc_info=None)
    codeflash_output = formatter.format(record)
    # Outputs were verified to be equal to the original implementation

def test_warning_log_level(formatter):
    """Test a log message with warning log level"""
    record = logging.LogRecord(name="test", level=logging.WARNING, pathname="", lineno=0, msg="Warning level message", args=(), exc_info=None)
    codeflash_output = formatter.format(record)
    # Outputs were verified to be equal to the original implementation

def test_error_log_level(formatter):
    """Test a log message with error log level"""
    record = logging.LogRecord(name="test", level=logging.ERROR, pathname="", lineno=0, msg="Error level message", args=(), exc_info=None)
    codeflash_output = formatter.format(record)
    # Outputs were verified to be equal to the original implementation

def test_critical_log_level(formatter):
    """Test a log message with critical log level"""
    record = logging.LogRecord(name="test", level=logging.CRITICAL, pathname="", lineno=0, msg="Critical level message", args=(), exc_info=None)
    codeflash_output = formatter.format(record)
    # Outputs were verified to be equal to the original implementation

def test_log_record_with_exception_info(formatter):
    """Test a log record with exception information"""
    try:
        raise ValueError("Test exception")
    except ValueError as e:
        record = logging.LogRecord(name="test", level=logging.ERROR, pathname="", lineno=0, msg="Exception occurred", args=(), exc_info=e)
        codeflash_output = formatter.format(record)
    # Outputs were verified to be equal to the original implementation

def test_log_record_with_nested_extra_args(formatter):
    """Test a log record with nested extra arguments"""
    record = logging.LogRecord(name="test", level=logging.INFO, pathname="", lineno=0, msg="Message with nested args", args=(), exc_info=None)
    record.extra = {"nested": {"key": "value"}}
    codeflash_output = formatter.format(record)
    # Outputs were verified to be equal to the original implementation

def test_large_log_message(formatter):
    """Test a very large log message"""
    large_message = "A" * 10000  # 10,000 characters long
    record = logging.LogRecord(name="test", level=logging.INFO, pathname="", lineno=0, msg=large_message, args=(), exc_info=None)
    codeflash_output = formatter.format(record)
    # Outputs were verified to be equal to the original implementation

def test_log_message_with_many_extra_args(formatter):
    """Test a log message with many extra arguments"""
    record = logging.LogRecord(name="test", level=logging.INFO, pathname="", lineno=0, msg="Message with many extra args", args=(), exc_info=None)
    for i in range(100):
        setattr(record, f"extra_arg_{i}", f"value_{i}")
    codeflash_output = formatter.format(record)
    for i in range(100):
        pass
    # Outputs were verified to be equal to the original implementation

def test_consistent_output_for_identical_inputs(formatter):
    """Ensure consistent output for identical inputs"""
    record1 = logging.LogRecord(name="test", level=logging.INFO, pathname="", lineno=0, msg="Consistent message", args=(), exc_info=None)
    record2 = logging.LogRecord(name="test", level=logging.INFO, pathname="", lineno=0, msg="Consistent message", args=(), exc_info=None)
    codeflash_output = formatter.format(record1)
    codeflash_output = formatter.format(record2)
    # Outputs were verified to be equal to the original implementation

def test_high_volume_of_log_messages(formatter):
    """Simulate a high volume of log messages to assess performance under load"""
    for _ in range(1000):
        record = logging.LogRecord(name="test", level=logging.INFO, pathname="", lineno=0, msg="High volume message", args=(), exc_info=None)
        codeflash_output = formatter.format(record)
    # Outputs were verified to be equal to the original implementation

def test_complex_and_large_log_records(formatter):
    """Test with complex and large log records to evaluate scalability"""
    large_message = "A" * 10000  # 10,000 characters long
    record = logging.LogRecord(name="test", level=logging.INFO, pathname="", lineno=0, msg=large_message, args=(), exc_info=None)
    record.extra = {"nested": {"key": "value"}, "list": [i for i in range(1000)]}
    codeflash_output = formatter.format(record)
    # Outputs were verified to be equal to the original implementation

🔘 (none found) − ⏪ Replay Tests

[vercel]

The latest updates on your projects. Learn more about Vercel for Git ↗︎

1 Skipped Deployment

Name	Status	Preview	Comments	Updated (UTC)
airbyte-docs	⬜️ Ignored (Inspect)	Visit Preview		Aug 30, 2024 9:54pm

[CLAassistant]

Thank you for your submission! We really appreciate it. Like many open source projects, we ask that you sign our Contributor License Agreement before we can accept your contribution.
_{You have signed the CLA already but the status is still pending? Let us recheck it.}

[codeflash-ai]

This PR has been automatically closed because the original PR #44444 by artem1205 was closed.