Skip to content

Commit 0e84dfa

Browse files
authored
Performance testing (#1204)
* Performance testing: Signed-off-by: Mihai Criveti <[email protected]> * Performance testing Signed-off-by: Mihai Criveti <[email protected]> * Performance testing Signed-off-by: Mihai Criveti <[email protected]> * refactor: consolidate performance testing docs and fix report generator - Consolidate 5 documentation files into 2: - README.md: practical quick start guide (309 lines) - PERFORMANCE_STRATEGY.md: comprehensive deep dive (2,116 lines) - Delete: QUICK_REFERENCE.md, SERVER_PROFILES_GUIDE.md, README_AUTOMATION.md, IMPLEMENTATION_STATUS.md, FINAL_SUMMARY.md - Result: 35% reduction in documentation (3,742 → 2,425 lines) - Fix regex escape issue in report_generator.py: - Use lambda function in re.sub() to avoid backslash interpretation - Fixes: re.error with JSON Unicode sequences (\uXXXX) - Location: utils/report_generator.py:767 Signed-off-by: Mihai Criveti <[email protected]> * perf: reduce token scoping middleware logging to DEBUG level Change INFO level log in token_scoping middleware to DEBUG to avoid performance degradation during load testing. Logging every request at INFO level was causing: - Massive disk I/O bottleneck - CPU overhead for log formatting - Lock contention on log files With 50 concurrent requests, this reduced RPS from expected 500+ to just 6.67. This log statement triggers for every request to endpoints without resource IDs (like /rpc, /health, etc.), making it unsuitable for INFO level. Signed-off-by: Mihai Criveti <[email protected]> * perf: optimize logging for production performance 1. Change default LOG_LEVEL from INFO to ERROR - Reduces unnecessary log I/O overhead - config.py:629: Changed default from INFO to ERROR 2. Add DISABLE_ACCESS_LOG environment variable support - run-gunicorn.sh: Added conditional access logging - When true, routes logs to /dev/null (massive performance gain) - docker-compose.yml: Added DISABLE_ACCESS_LOG=true 3. Performance impact analysis: - uvicorn.access logs EVERY request at INFO level - With 50 concurrent requests: ~6.67 RPS (bottlenecked by log I/O) - Expected after fix: 500+ RPS 4. Related middleware logging fix (previous commit) - token_scoping.py: Changed INFO to DEBUG for high-frequency logs The combination of excessive access logging and INFO-level middleware logging was causing ~75x performance degradation during load testing. Signed-off-by: Mihai Criveti <[email protected]> * fix: initialize LoggingService._level from settings Critical bug fix: LoggingService.__init__() hardcoded self._level = LogLevel.INFO, which was never updated from settings.log_level. This caused uvicorn.access logger to always log at INFO level regardless of LOG_LEVEL environment variable. This caused massive performance degradation (~75x slower) during high concurrency because every HTTP request was logged at INFO level, creating severe I/O bottleneck. Fix: Read self._level from settings.log_level at start of initialize() method, BEFORE configuring uvicorn loggers. Now uvicorn.access correctly respects LOG_LEVEL. Expected performance improvement: 7 RPS → 500+ RPS with LOG_LEVEL=ERROR. Signed-off-by: Mihai Criveti <[email protected]> * docs: update .env.example with performance-optimized logging defaults - Change LOG_LEVEL default from INFO to ERROR - Add DISABLE_ACCESS_LOG configuration option - Document performance impact of access logging - Add production recommendations for logging settings These changes reflect the 251x performance improvement achieved by optimizing logging configuration (7 RPS → 1810 RPS). Signed-off-by: Mihai Criveti <[email protected]> * fix: enable Ctrl+C (SIGINT) handling in performance test scripts Problem: ^C was not working to interrupt performance tests, forcing users to wait for timeout or manually kill processes. Root cause: 1. Scripts had trap handlers but cleanup functions exited with code 0 2. No signal handling in run-advanced.sh 3. Background processes weren't being killed Changes: - run-configurable.sh: Exit with 130 (SIGINT code), kill background jobs - run-advanced.sh: Add signal trap and cleanup handler - Both: Properly propagate SIGINT to all child processes Now Ctrl+C immediately stops tests and cleans up partial results. Signed-off-by: Mihai Criveti <[email protected]> * Disable some plugins Signed-off-by: Mihai Criveti <[email protected]> * fix: handle team dict objects in JWT token validation The JWT payload's 'teams' field contains full team objects (dicts) with structure {id, name, slug, is_personal, role}, but the token scoping middleware was treating them as simple string IDs. This caused SQLAlchemy/psycopg2 errors when trying to use dict objects in SQL queries: ProgrammingError: (psycopg2.ProgrammingError) can't adapt type 'dict' Changes: - _check_team_membership(): Extract team ID from dict or use string directly for backward compatibility - _check_resource_team_ownership(): Normalize token_teams at start, extracting team IDs from dict objects before using in comparisons This maintains backward compatibility with older tokens that may have simple string team IDs while supporting the current dict format. Fixes internal server error when calling /tools and other team-scoped endpoints with modern JWT tokens. Signed-off-by: Mihai Criveti <[email protected]> * docs: add comprehensive manual API testing guide Add detailed manual testing documentation for MCP Gateway API with: - Prerequisites and setup instructions (curl, jq, hey) - Quick start test script covering all major endpoints - Individual endpoint tests (health, auth, tools, servers, resources, prompts, profile) - Performance testing with hey load testing tool - Benchmarking scripts for measuring throughput - Expected performance baselines (1500-2000 RPS for authenticated endpoints) - Troubleshooting guide (token expiration, validation) - Advanced scenarios (continuous monitoring, deployment verification, load testing) - Integration with existing automated test suite All commands are CLI-ready and tested. Complements automated tests in tests/performance/ with human-readable examples for development and debugging workflows. Location: tests/performance/MANUAL_TESTING.md (458 lines, 12KB) Signed-off-by: Mihai Criveti <[email protected]> * style: fix pylint issues for 10.00/10 rating Fix remaining pylint warnings: - token_scoping.py: Disable too-many-return-statements warning for complex authorization logic - support_bundle_service.py: Convert README string to f-string format (C0209) - support_bundle_service.py: Disable import-outside-toplevel for optional psutil import - admin.py: Disable import-outside-toplevel for support bundle import All fixes maintain existing functionality while improving code style compliance. Pylint rating: 10.00/10 Signed-off-by: Mihai Criveti <[email protected]> * lint Signed-off-by: Mihai Criveti <[email protected]> * Add benchmark for prompts Signed-off-by: Mihai Criveti <[email protected]> * Add benchmark for prompts Signed-off-by: Mihai Criveti <[email protected]> --------- Signed-off-by: Mihai Criveti <[email protected]>
1 parent aa561cb commit 0e84dfa

Some content is hidden

Large Commits have some content hidden by default. Use the searchbox below for content that may be hidden.

44 files changed

+8381
-62
lines changed

.env.example

Lines changed: 11 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -510,13 +510,21 @@ RETRY_JITTER_MAX=0.5
510510
#####################################
511511

512512
# Logging verbosity level
513-
# Options: DEBUG, INFO (default), WARNING, ERROR, CRITICAL
513+
# Options: DEBUG, INFO, WARNING, ERROR (default), CRITICAL
514514
# DEBUG: Detailed diagnostic info (verbose)
515515
# INFO: General operational messages
516516
# WARNING: Warning messages for potential issues
517-
# ERROR: Error messages for failures
517+
# ERROR: Error messages for failures (recommended for production)
518518
# CRITICAL: Only critical failures
519-
LOG_LEVEL=INFO
519+
# PRODUCTION: Use ERROR to minimize I/O overhead and improve performance
520+
LOG_LEVEL=ERROR
521+
522+
# Disable access logging for performance
523+
# Options: true, false (default)
524+
# When true: Disables both gunicorn and uvicorn access logs
525+
# PRODUCTION: Set to true for high-performance deployments
526+
# Access logs create massive I/O overhead under high concurrency
527+
# DISABLE_ACCESS_LOG=true
520528

521529
# Log output format
522530
# Options: json (default), text

docker-compose.yml

Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -76,6 +76,13 @@ services:
7676
# Uncomment to enable catalog
7777
- MCPGATEWAY_CATALOG_ENABLED=true
7878
- MCPGATEWAY_CATALOG_FILE=/app/mcp-catalog.yml
79+
# Authentication configuration
80+
- AUTH_REQUIRED=true
81+
- MCP_CLIENT_AUTH_ENABLED=true
82+
- TRUST_PROXY_AUTH=false
83+
# Logging configuration
84+
- LOG_LEVEL=ERROR # Default to ERROR for production performance
85+
- DISABLE_ACCESS_LOG=true # Disable uvicorn access logs for performance (massive I/O overhead)
7986

8087
# Phoenix Observability Integration (uncomment when using Phoenix)
8188
# - PHOENIX_ENDPOINT=${PHOENIX_ENDPOINT:-http://phoenix:6006}

mcpgateway/admin.py

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -9910,7 +9910,7 @@ async def admin_generate_support_bundle(
99109910
LOGGER.info(f"Support bundle generation requested by user: {user}")
99119911

99129912
# First-Party
9913-
from mcpgateway.services.support_bundle_service import SupportBundleConfig, SupportBundleService
9913+
from mcpgateway.services.support_bundle_service import SupportBundleConfig, SupportBundleService # pylint: disable=import-outside-toplevel
99149914

99159915
# Create configuration
99169916
config = SupportBundleConfig(

mcpgateway/config.py

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -626,7 +626,7 @@ def _parse_allowed_origins(cls, v):
626626
return set(v)
627627

628628
# Logging
629-
log_level: Literal["DEBUG", "INFO", "WARNING", "ERROR", "CRITICAL"] = Field(default="INFO", env="LOG_LEVEL")
629+
log_level: Literal["DEBUG", "INFO", "WARNING", "ERROR", "CRITICAL"] = Field(default="ERROR", env="LOG_LEVEL")
630630
log_format: Literal["json", "text"] = "json" # json or text
631631
log_to_file: bool = False # Enable file logging (default: stdout/stderr only)
632632
log_filemode: str = "a+" # append or overwrite

mcpgateway/main.py

Lines changed: 13 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -3410,11 +3410,19 @@ async def handle_rpc(request: Request, db: Session = Depends(get_db), user=Depen
34103410
request_id = params.get("requestId", None)
34113411
if not uri:
34123412
raise JSONRPCError(-32602, "Missing resource URI in parameters", params)
3413-
result = await resource_service.read_resource(db, uri, request_id=request_id, user=get_user_email(user))
3414-
if hasattr(result, "model_dump"):
3415-
result = {"contents": [result.model_dump(by_alias=True, exclude_none=True)]}
3416-
else:
3417-
result = {"contents": [result]}
3413+
# Get user email for OAuth token selection
3414+
user_email = get_user_email(user)
3415+
try:
3416+
result = await resource_service.read_resource(db, uri, request_id=request_id, user=user_email)
3417+
if hasattr(result, "model_dump"):
3418+
result = {"contents": [result.model_dump(by_alias=True, exclude_none=True)]}
3419+
else:
3420+
result = {"contents": [result]}
3421+
except ValueError:
3422+
# Resource has no local content, forward to upstream MCP server
3423+
result = await gateway_service.forward_request(db, method, params, app_user_email=user_email)
3424+
if hasattr(result, "model_dump"):
3425+
result = result.model_dump(by_alias=True, exclude_none=True)
34183426
elif method == "prompts/list":
34193427
if server_id:
34203428
prompts = await prompt_service.list_server_prompts(db, server_id, cursor=cursor)

mcpgateway/middleware/token_scoping.py

Lines changed: 26 additions & 16 deletions
Original file line numberDiff line numberDiff line change
@@ -370,7 +370,10 @@ def _check_team_membership(self, payload: dict) -> bool:
370370

371371
db = next(get_db())
372372
try:
373-
for team_id in teams:
373+
for team in teams:
374+
# Extract team ID from dict or use string directly (backward compatibility)
375+
team_id = team["id"] if isinstance(team, dict) else team
376+
374377
membership = db.execute(
375378
select(EmailTeamMember).where(and_(EmailTeamMember.team_id == team_id, EmailTeamMember.user_email == user_email, EmailTeamMember.is_active))
376379
).scalar_one_or_none()
@@ -383,7 +386,7 @@ def _check_team_membership(self, payload: dict) -> bool:
383386
finally:
384387
db.close()
385388

386-
def _check_resource_team_ownership(self, request_path: str, token_teams: list) -> bool:
389+
def _check_resource_team_ownership(self, request_path: str, token_teams: list) -> bool: # pylint: disable=too-many-return-statements
387390
"""
388391
Check if the requested resource is accessible by the token.
389392
@@ -412,9 +415,16 @@ def _check_resource_team_ownership(self, request_path: str, token_teams: list) -
412415
Returns:
413416
bool: True if resource access is allowed, False otherwise
414417
"""
418+
# Normalize token_teams: extract team IDs from dict objects (backward compatibility)
419+
token_team_ids = []
420+
for team in token_teams:
421+
if isinstance(team, dict):
422+
token_team_ids.append(team["id"])
423+
else:
424+
token_team_ids.append(team)
415425

416426
# Determine token type
417-
is_public_token = not token_teams or len(token_teams) == 0
427+
is_public_token = not token_team_ids or len(token_team_ids) == 0
418428

419429
if is_public_token:
420430
logger.debug("Processing request with PUBLIC-ONLY token")
@@ -442,7 +452,7 @@ def _check_resource_team_ownership(self, request_path: str, token_teams: list) -
442452

443453
# If no resource ID in path, allow (general endpoints like /health, /tokens, /metrics)
444454
if not resource_id or not resource_type:
445-
logger.info(f"No resource ID found in path {request_path}, allowing access")
455+
logger.debug(f"No resource ID found in path {request_path}, allowing access")
446456
return True
447457

448458
# Import database models
@@ -477,16 +487,16 @@ def _check_resource_team_ownership(self, request_path: str, token_teams: list) -
477487

478488
# TEAM-SCOPED SERVERS: Check if server belongs to token's teams
479489
if server_visibility == "team":
480-
if server.team_id in token_teams:
490+
if server.team_id in token_team_ids:
481491
logger.debug(f"Access granted: Team server {resource_id} belongs to token's team {server.team_id}")
482492
return True
483493

484-
logger.warning(f"Access denied: Server {resource_id} is team-scoped to '{server.team_id}', " f"token is scoped to teams {token_teams}")
494+
logger.warning(f"Access denied: Server {resource_id} is team-scoped to '{server.team_id}', " f"token is scoped to teams {token_team_ids}")
485495
return False
486496

487497
# PRIVATE SERVERS: Check if server belongs to token's teams
488498
if server_visibility == "private":
489-
if server.team_id in token_teams:
499+
if server.team_id in token_team_ids:
490500
logger.debug(f"Access granted: Private server {resource_id} in token's team {server.team_id}")
491501
return True
492502

@@ -521,17 +531,17 @@ def _check_resource_team_ownership(self, request_path: str, token_teams: list) -
521531
# TEAM TOOLS: Check if tool's team matches token's teams
522532
if tool_visibility == "team":
523533
tool_team_id = getattr(tool, "team_id", None)
524-
if tool_team_id and tool_team_id in token_teams:
534+
if tool_team_id and tool_team_id in token_team_ids:
525535
logger.debug(f"Access granted: Team tool {resource_id} belongs to token's team {tool_team_id}")
526536
return True
527537

528-
logger.warning(f"Access denied: Tool {resource_id} is team-scoped to '{tool_team_id}', " f"token is scoped to teams {token_teams}")
538+
logger.warning(f"Access denied: Tool {resource_id} is team-scoped to '{tool_team_id}', " f"token is scoped to teams {token_team_ids}")
529539
return False
530540

531541
# PRIVATE TOOLS: Check if tool is in token's team context
532542
if tool_visibility in ["private", "user"]:
533543
tool_team_id = getattr(tool, "team_id", None)
534-
if tool_team_id and tool_team_id in token_teams:
544+
if tool_team_id and tool_team_id in token_team_ids:
535545
logger.debug(f"Access granted: Private tool {resource_id} in token's team {tool_team_id}")
536546
return True
537547

@@ -566,17 +576,17 @@ def _check_resource_team_ownership(self, request_path: str, token_teams: list) -
566576
# TEAM RESOURCES: Check if resource's team matches token's teams
567577
if resource_visibility == "team":
568578
resource_team_id = getattr(resource, "team_id", None)
569-
if resource_team_id and resource_team_id in token_teams:
579+
if resource_team_id and resource_team_id in token_team_ids:
570580
logger.debug(f"Access granted: Team resource {resource_id} belongs to token's team {resource_team_id}")
571581
return True
572582

573-
logger.warning(f"Access denied: Resource {resource_id} is team-scoped to '{resource_team_id}', " f"token is scoped to teams {token_teams}")
583+
logger.warning(f"Access denied: Resource {resource_id} is team-scoped to '{resource_team_id}', " f"token is scoped to teams {token_team_ids}")
574584
return False
575585

576586
# PRIVATE RESOURCES: Check if resource is in token's team context
577587
if resource_visibility in ["private", "user"]:
578588
resource_team_id = getattr(resource, "team_id", None)
579-
if resource_team_id and resource_team_id in token_teams:
589+
if resource_team_id and resource_team_id in token_team_ids:
580590
logger.debug(f"Access granted: Private resource {resource_id} in token's team {resource_team_id}")
581591
return True
582592

@@ -611,17 +621,17 @@ def _check_resource_team_ownership(self, request_path: str, token_teams: list) -
611621
# TEAM PROMPTS: Check if prompt's team matches token's teams
612622
if prompt_visibility == "team":
613623
prompt_team_id = getattr(prompt, "team_id", None)
614-
if prompt_team_id and prompt_team_id in token_teams:
624+
if prompt_team_id and prompt_team_id in token_team_ids:
615625
logger.debug(f"Access granted: Team prompt {resource_id} belongs to token's team {prompt_team_id}")
616626
return True
617627

618-
logger.warning(f"Access denied: Prompt {resource_id} is team-scoped to '{prompt_team_id}', " f"token is scoped to teams {token_teams}")
628+
logger.warning(f"Access denied: Prompt {resource_id} is team-scoped to '{prompt_team_id}', " f"token is scoped to teams {token_team_ids}")
619629
return False
620630

621631
# PRIVATE PROMPTS: Check if prompt is in token's team context
622632
if prompt_visibility in ["private", "user"]:
623633
prompt_team_id = getattr(prompt, "team_id", None)
624-
if prompt_team_id and prompt_team_id in token_teams:
634+
if prompt_team_id and prompt_team_id in token_team_ids:
625635
logger.debug(f"Access granted: Private prompt {resource_id} in token's team {prompt_team_id}")
626636
return True
627637

mcpgateway/services/logging_service.py

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -191,6 +191,9 @@ async def initialize(self) -> None:
191191
>>> service = LoggingService()
192192
>>> asyncio.run(service.initialize())
193193
"""
194+
# Update service log level from settings BEFORE configuring loggers
195+
self._level = settings.log_level
196+
194197
root_logger = logging.getLogger()
195198
self._loggers[""] = root_logger
196199

mcpgateway/services/support_bundle_service.py

Lines changed: 6 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -244,7 +244,7 @@ def _collect_system_info(self) -> Dict[str, Any]:
244244
# Try to collect psutil metrics if available
245245
try:
246246
# Third-Party
247-
import psutil
247+
import psutil # pylint: disable=import-outside-toplevel
248248

249249
info["system"] = {
250250
"cpu_count": psutil.cpu_count(logical=True),
@@ -448,7 +448,7 @@ def generate_bundle(self, config: Optional[SupportBundleConfig] = None) -> Path:
448448
zf.writestr(f"logs/{log_name}", log_content)
449449

450450
# Add README
451-
readme = """# MCP Gateway Support Bundle
451+
readme = f"""# MCP Gateway Support Bundle
452452
453453
This bundle contains diagnostic information for troubleshooting MCP Gateway issues.
454454
@@ -478,12 +478,10 @@ def generate_bundle(self, config: Optional[SupportBundleConfig] = None) -> Path:
478478
Pay special attention to logs/ for error messages and stack traces.
479479
480480
---
481-
Generated: {timestamp}
482-
Hostname: {hostname}
483-
Version: {version}
484-
""".format(
485-
timestamp=self.timestamp.isoformat(), hostname=self.hostname, version=__version__
486-
)
481+
Generated: {self.timestamp.isoformat()}
482+
Hostname: {self.hostname}
483+
Version: {__version__}
484+
"""
487485

488486
zf.writestr("README.md", readme)
489487

0 commit comments

Comments
 (0)