perf: cache inspect.signature() at decoration time (#97)

Move inspect.signature(func) calls from inside wrapper functions to the
outer decorator function so the introspection cost is paid once at
decoration time instead of on every invocation.

- logged_command: sig, param_names, and exclude_set computed at decoration time;
  wrapper.__signature__ reuses the pre-computed sig
- cached_api_call: sig moved to decorator scope; bound_args still computed
  per-call (requires runtime args)
- cached_single_item: same as cached_api_call

Closes #97

Co-Authored-By: Claude Sonnet 4.6 <noreply@anthropic.com>
This commit is contained in:
Cal Corum 2026-03-20 11:33:43 -05:00 committed by cal
parent f0934937cb
commit a3e63f730f

View File

@ -11,29 +11,29 @@ from functools import wraps
from typing import List, Optional, Callable, Any from typing import List, Optional, Callable, Any
from utils.logging import set_discord_context, get_contextual_logger from utils.logging import set_discord_context, get_contextual_logger
cache_logger = logging.getLogger(f'{__name__}.CacheDecorators') cache_logger = logging.getLogger(f"{__name__}.CacheDecorators")
period_check_logger = logging.getLogger(f'{__name__}.PeriodCheckDecorators') period_check_logger = logging.getLogger(f"{__name__}.PeriodCheckDecorators")
def logged_command( def logged_command(
command_name: Optional[str] = None, command_name: Optional[str] = None,
log_params: bool = True, log_params: bool = True,
exclude_params: Optional[List[str]] = None exclude_params: Optional[List[str]] = None,
): ):
""" """
Decorator for Discord commands that adds comprehensive logging. Decorator for Discord commands that adds comprehensive logging.
This decorator automatically handles: This decorator automatically handles:
- Setting Discord context with interaction details - Setting Discord context with interaction details
- Starting/ending operation timing - Starting/ending operation timing
- Logging command start/completion/failure - Logging command start/completion/failure
- Preserving function metadata and signature - Preserving function metadata and signature
Args: Args:
command_name: Override command name (defaults to function name with slashes) command_name: Override command name (defaults to function name with slashes)
log_params: Whether to log command parameters (default: True) log_params: Whether to log command parameters (default: True)
exclude_params: List of parameter names to exclude from logging exclude_params: List of parameter names to exclude from logging
Example: Example:
@logged_command("/roster", exclude_params=["sensitive_data"]) @logged_command("/roster", exclude_params=["sensitive_data"])
async def team_roster(self, interaction, team_name: str, season: int = None): async def team_roster(self, interaction, team_name: str, season: int = None):
@ -42,57 +42,65 @@ def logged_command(
players = await team_service.get_roster(team.id, season) players = await team_service.get_roster(team.id, season)
embed = create_roster_embed(team, players) embed = create_roster_embed(team, players)
await interaction.followup.send(embed=embed) await interaction.followup.send(embed=embed)
Side Effects: Side Effects:
- Automatically sets Discord context for all subsequent log entries - Automatically sets Discord context for all subsequent log entries
- Creates trace_id for request correlation - Creates trace_id for request correlation
- Logs command execution timing and results - Logs command execution timing and results
- Re-raises all exceptions after logging (preserves original behavior) - Re-raises all exceptions after logging (preserves original behavior)
Requirements: Requirements:
- The decorated class must have a 'logger' attribute, or one will be created - The decorated class must have a 'logger' attribute, or one will be created
- Function must be an async method with (self, interaction, ...) signature - Function must be an async method with (self, interaction, ...) signature
- Preserves Discord.py command registration compatibility - Preserves Discord.py command registration compatibility
""" """
def decorator(func): def decorator(func):
sig = inspect.signature(func)
param_names = list(sig.parameters.keys())[2:] # Skip self, interaction
exclude_set = set(exclude_params or [])
@wraps(func) @wraps(func)
async def wrapper(self, interaction, *args, **kwargs): async def wrapper(self, interaction, *args, **kwargs):
# Auto-detect command name if not provided # Auto-detect command name if not provided
cmd_name = command_name or f"/{func.__name__.replace('_', '-')}" cmd_name = command_name or f"/{func.__name__.replace('_', '-')}"
# Build context with safe parameter logging # Build context with safe parameter logging
context = {"command": cmd_name} context = {"command": cmd_name}
if log_params: if log_params:
sig = inspect.signature(func)
param_names = list(sig.parameters.keys())[2:] # Skip self, interaction
exclude_set = set(exclude_params or [])
for i, (name, value) in enumerate(zip(param_names, args)): for i, (name, value) in enumerate(zip(param_names, args)):
if name not in exclude_set: if name not in exclude_set:
context[f"param_{name}"] = value context[f"param_{name}"] = value
set_discord_context(interaction=interaction, **context) set_discord_context(interaction=interaction, **context)
# Get logger from the class instance or create one # Get logger from the class instance or create one
logger = getattr(self, 'logger', get_contextual_logger(f'{self.__class__.__module__}.{self.__class__.__name__}')) logger = getattr(
self,
"logger",
get_contextual_logger(
f"{self.__class__.__module__}.{self.__class__.__name__}"
),
)
trace_id = logger.start_operation(f"{func.__name__}_command") trace_id = logger.start_operation(f"{func.__name__}_command")
try: try:
logger.info(f"{cmd_name} command started") logger.info(f"{cmd_name} command started")
result = await func(self, interaction, *args, **kwargs) result = await func(self, interaction, *args, **kwargs)
logger.info(f"{cmd_name} command completed successfully") logger.info(f"{cmd_name} command completed successfully")
logger.end_operation(trace_id, "completed") logger.end_operation(trace_id, "completed")
return result return result
except Exception as e: except Exception as e:
logger.error(f"{cmd_name} command failed", error=e) logger.error(f"{cmd_name} command failed", error=e)
logger.end_operation(trace_id, "failed") logger.end_operation(trace_id, "failed")
# Re-raise to maintain original exception handling behavior # Re-raise to maintain original exception handling behavior
raise raise
# Preserve signature for Discord.py command registration # Preserve signature for Discord.py command registration
wrapper.__signature__ = inspect.signature(func) # type: ignore wrapper.__signature__ = sig # type: ignore
return wrapper return wrapper
return decorator return decorator
@ -122,6 +130,7 @@ def requires_draft_period(func):
- Should be placed before @logged_command decorator - Should be placed before @logged_command decorator
- league_service must be available via import - league_service must be available via import
""" """
@wraps(func) @wraps(func)
async def wrapper(self, interaction, *args, **kwargs): async def wrapper(self, interaction, *args, **kwargs):
# Import here to avoid circular imports # Import here to avoid circular imports
@ -133,10 +142,12 @@ def requires_draft_period(func):
current = await league_service.get_current_state() current = await league_service.get_current_state()
if not current: if not current:
period_check_logger.error("Could not retrieve league state for draft period check") period_check_logger.error(
"Could not retrieve league state for draft period check"
)
embed = EmbedTemplate.error( embed = EmbedTemplate.error(
"System Error", "System Error",
"Could not verify draft period status. Please try again later." "Could not verify draft period status. Please try again later.",
) )
await interaction.response.send_message(embed=embed, ephemeral=True) await interaction.response.send_message(embed=embed, ephemeral=True)
return return
@ -148,12 +159,12 @@ def requires_draft_period(func):
extra={ extra={
"user_id": interaction.user.id, "user_id": interaction.user.id,
"command": func.__name__, "command": func.__name__,
"current_week": current.week "current_week": current.week,
} },
) )
embed = EmbedTemplate.error( embed = EmbedTemplate.error(
"Not Available", "Not Available",
"Draft commands are only available in the offseason." "Draft commands are only available in the offseason.",
) )
await interaction.response.send_message(embed=embed, ephemeral=True) await interaction.response.send_message(embed=embed, ephemeral=True)
return return
@ -161,7 +172,7 @@ def requires_draft_period(func):
# Week <= 0, allow command to proceed # Week <= 0, allow command to proceed
period_check_logger.debug( period_check_logger.debug(
f"Draft period check passed - week {current.week}", f"Draft period check passed - week {current.week}",
extra={"user_id": interaction.user.id, "command": func.__name__} extra={"user_id": interaction.user.id, "command": func.__name__},
) )
return await func(self, interaction, *args, **kwargs) return await func(self, interaction, *args, **kwargs)
@ -169,7 +180,7 @@ def requires_draft_period(func):
period_check_logger.error( period_check_logger.error(
f"Error in draft period check: {e}", f"Error in draft period check: {e}",
exc_info=True, exc_info=True,
extra={"user_id": interaction.user.id, "command": func.__name__} extra={"user_id": interaction.user.id, "command": func.__name__},
) )
# Re-raise to let error handling in logged_command handle it # Re-raise to let error handling in logged_command handle it
raise raise
@ -182,110 +193,115 @@ def requires_draft_period(func):
def cached_api_call(ttl: Optional[int] = None, cache_key_suffix: str = ""): def cached_api_call(ttl: Optional[int] = None, cache_key_suffix: str = ""):
""" """
Decorator to add Redis caching to service methods that return List[T]. Decorator to add Redis caching to service methods that return List[T].
This decorator will: This decorator will:
1. Check cache for existing data using generated key 1. Check cache for existing data using generated key
2. Return cached data if found 2. Return cached data if found
3. Execute original method if cache miss 3. Execute original method if cache miss
4. Cache the result for future calls 4. Cache the result for future calls
Args: Args:
ttl: Time-to-live override in seconds (uses service default if None) ttl: Time-to-live override in seconds (uses service default if None)
cache_key_suffix: Additional suffix for cache key differentiation cache_key_suffix: Additional suffix for cache key differentiation
Usage: Usage:
@cached_api_call(ttl=600, cache_key_suffix="by_season") @cached_api_call(ttl=600, cache_key_suffix="by_season")
async def get_teams_by_season(self, season: int) -> List[Team]: async def get_teams_by_season(self, season: int) -> List[Team]:
# Original method implementation # Original method implementation
Requirements: Requirements:
- Method must be async - Method must be async
- Method must return List[T] where T is a model - Method must return List[T] where T is a model
- Class must have self.cache (CacheManager instance) - Class must have self.cache (CacheManager instance)
- Class must have self._generate_cache_key, self._get_cached_items, self._cache_items methods - Class must have self._generate_cache_key, self._get_cached_items, self._cache_items methods
""" """
def decorator(func: Callable) -> Callable: def decorator(func: Callable) -> Callable:
sig = inspect.signature(func)
@wraps(func) @wraps(func)
async def wrapper(self, *args, **kwargs) -> List[Any]: async def wrapper(self, *args, **kwargs) -> List[Any]:
# Check if caching is available (service has cache manager) # Check if caching is available (service has cache manager)
if not hasattr(self, 'cache') or not hasattr(self, '_generate_cache_key'): if not hasattr(self, "cache") or not hasattr(self, "_generate_cache_key"):
# No caching available, execute original method # No caching available, execute original method
return await func(self, *args, **kwargs) return await func(self, *args, **kwargs)
# Generate cache key from method name, args, and kwargs # Generate cache key from method name, args, and kwargs
method_name = f"{func.__name__}{cache_key_suffix}" method_name = f"{func.__name__}{cache_key_suffix}"
# Convert args and kwargs to params list for consistent cache key # Convert args and kwargs to params list for consistent cache key
sig = inspect.signature(func)
bound_args = sig.bind(self, *args, **kwargs) bound_args = sig.bind(self, *args, **kwargs)
bound_args.apply_defaults() bound_args.apply_defaults()
# Skip 'self' and convert to params format # Skip 'self' and convert to params format
params = [] params = []
for param_name, param_value in bound_args.arguments.items(): for param_name, param_value in bound_args.arguments.items():
if param_name != 'self' and param_value is not None: if param_name != "self" and param_value is not None:
params.append((param_name, param_value)) params.append((param_name, param_value))
cache_key = self._generate_cache_key(method_name, params) cache_key = self._generate_cache_key(method_name, params)
# Try to get from cache # Try to get from cache
if hasattr(self, '_get_cached_items'): if hasattr(self, "_get_cached_items"):
cached_result = await self._get_cached_items(cache_key) cached_result = await self._get_cached_items(cache_key)
if cached_result is not None: if cached_result is not None:
cache_logger.debug(f"Cache hit: {method_name}") cache_logger.debug(f"Cache hit: {method_name}")
return cached_result return cached_result
# Cache miss - execute original method # Cache miss - execute original method
cache_logger.debug(f"Cache miss: {method_name}") cache_logger.debug(f"Cache miss: {method_name}")
result = await func(self, *args, **kwargs) result = await func(self, *args, **kwargs)
# Cache the result if we have items and caching methods # Cache the result if we have items and caching methods
if result and hasattr(self, '_cache_items'): if result and hasattr(self, "_cache_items"):
await self._cache_items(cache_key, result, ttl) await self._cache_items(cache_key, result, ttl)
cache_logger.debug(f"Cached {len(result)} items for {method_name}") cache_logger.debug(f"Cached {len(result)} items for {method_name}")
return result return result
return wrapper return wrapper
return decorator return decorator
def cached_single_item(ttl: Optional[int] = None, cache_key_suffix: str = ""): def cached_single_item(ttl: Optional[int] = None, cache_key_suffix: str = ""):
""" """
Decorator to add Redis caching to service methods that return Optional[T]. Decorator to add Redis caching to service methods that return Optional[T].
Similar to cached_api_call but for methods returning a single model instance. Similar to cached_api_call but for methods returning a single model instance.
Args: Args:
ttl: Time-to-live override in seconds ttl: Time-to-live override in seconds
cache_key_suffix: Additional suffix for cache key differentiation cache_key_suffix: Additional suffix for cache key differentiation
Usage: Usage:
@cached_single_item(ttl=300, cache_key_suffix="by_id") @cached_single_item(ttl=300, cache_key_suffix="by_id")
async def get_player(self, player_id: int) -> Optional[Player]: async def get_player(self, player_id: int) -> Optional[Player]:
# Original method implementation # Original method implementation
""" """
def decorator(func: Callable) -> Callable: def decorator(func: Callable) -> Callable:
sig = inspect.signature(func)
@wraps(func) @wraps(func)
async def wrapper(self, *args, **kwargs) -> Optional[Any]: async def wrapper(self, *args, **kwargs) -> Optional[Any]:
# Check if caching is available # Check if caching is available
if not hasattr(self, 'cache') or not hasattr(self, '_generate_cache_key'): if not hasattr(self, "cache") or not hasattr(self, "_generate_cache_key"):
return await func(self, *args, **kwargs) return await func(self, *args, **kwargs)
# Generate cache key # Generate cache key
method_name = f"{func.__name__}{cache_key_suffix}" method_name = f"{func.__name__}{cache_key_suffix}"
sig = inspect.signature(func)
bound_args = sig.bind(self, *args, **kwargs) bound_args = sig.bind(self, *args, **kwargs)
bound_args.apply_defaults() bound_args.apply_defaults()
params = [] params = []
for param_name, param_value in bound_args.arguments.items(): for param_name, param_value in bound_args.arguments.items():
if param_name != 'self' and param_value is not None: if param_name != "self" and param_value is not None:
params.append((param_name, param_value)) params.append((param_name, param_value))
cache_key = self._generate_cache_key(method_name, params) cache_key = self._generate_cache_key(method_name, params)
# Try cache first # Try cache first
try: try:
cached_data = await self.cache.get(cache_key) cached_data = await self.cache.get(cache_key)
@ -293,12 +309,14 @@ def cached_single_item(ttl: Optional[int] = None, cache_key_suffix: str = ""):
cache_logger.debug(f"Cache hit: {method_name}") cache_logger.debug(f"Cache hit: {method_name}")
return self.model_class.from_api_data(cached_data) return self.model_class.from_api_data(cached_data)
except Exception as e: except Exception as e:
cache_logger.warning(f"Error reading single item cache for {cache_key}: {e}") cache_logger.warning(
f"Error reading single item cache for {cache_key}: {e}"
)
# Cache miss - execute original method # Cache miss - execute original method
cache_logger.debug(f"Cache miss: {method_name}") cache_logger.debug(f"Cache miss: {method_name}")
result = await func(self, *args, **kwargs) result = await func(self, *args, **kwargs)
# Cache the single result # Cache the single result
if result: if result:
try: try:
@ -306,43 +324,54 @@ def cached_single_item(ttl: Optional[int] = None, cache_key_suffix: str = ""):
await self.cache.set(cache_key, cache_data, ttl) await self.cache.set(cache_key, cache_data, ttl)
cache_logger.debug(f"Cached single item for {method_name}") cache_logger.debug(f"Cached single item for {method_name}")
except Exception as e: except Exception as e:
cache_logger.warning(f"Error caching single item for {cache_key}: {e}") cache_logger.warning(
f"Error caching single item for {cache_key}: {e}"
)
return result return result
return wrapper return wrapper
return decorator return decorator
def cache_invalidate(*cache_patterns: str): def cache_invalidate(*cache_patterns: str):
""" """
Decorator to invalidate cache entries when data is modified. Decorator to invalidate cache entries when data is modified.
Args: Args:
cache_patterns: Cache key patterns to invalidate (supports prefix matching) cache_patterns: Cache key patterns to invalidate (supports prefix matching)
Usage: Usage:
@cache_invalidate("players_by_team", "teams_by_season") @cache_invalidate("players_by_team", "teams_by_season")
async def update_player(self, player_id: int, updates: dict) -> Optional[Player]: async def update_player(self, player_id: int, updates: dict) -> Optional[Player]:
# Original method implementation # Original method implementation
""" """
def decorator(func: Callable) -> Callable: def decorator(func: Callable) -> Callable:
@wraps(func) @wraps(func)
async def wrapper(self, *args, **kwargs): async def wrapper(self, *args, **kwargs):
# Execute original method first # Execute original method first
result = await func(self, *args, **kwargs) result = await func(self, *args, **kwargs)
# Invalidate specified cache patterns # Invalidate specified cache patterns
if hasattr(self, 'cache'): if hasattr(self, "cache"):
for pattern in cache_patterns: for pattern in cache_patterns:
try: try:
cleared = await self.cache.clear_prefix(f"sba:{self.endpoint}_{pattern}") cleared = await self.cache.clear_prefix(
f"sba:{self.endpoint}_{pattern}"
)
if cleared > 0: if cleared > 0:
cache_logger.info(f"Invalidated {cleared} cache entries for pattern: {pattern}") cache_logger.info(
f"Invalidated {cleared} cache entries for pattern: {pattern}"
)
except Exception as e: except Exception as e:
cache_logger.warning(f"Error invalidating cache pattern {pattern}: {e}") cache_logger.warning(
f"Error invalidating cache pattern {pattern}: {e}"
)
return result return result
return wrapper return wrapper
return decorator
return decorator