Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

✨ Add profiling middleware to simcore services #5749

Merged
Show file tree
Hide file tree
Changes from 26 commits
Commits
Show all changes
38 commits
Select commit Hold shift + click to select a range
5fe8d3f
generalize api-server profiling middleware
bisgaard-itis Apr 26, 2024
b74bd07
change check
bisgaard-itis Apr 26, 2024
e72dbf3
first iteration aiohttp profiling middleware
bisgaard-itis Apr 26, 2024
328321d
further improvements
bisgaard-itis Apr 26, 2024
3ea824e
setup profiling middleware for storage
bisgaard-itis Apr 26, 2024
f7e8385
enable profiling middleware in storage
bisgaard-itis Apr 26, 2024
2495117
enable profiling middleware on local deployment
bisgaard-itis Apr 26, 2024
7c3a6b1
merge master into 5729-add-profiling-middleware-to-storage
bisgaard-itis Apr 26, 2024
0f2b8a8
return exceptions in profiling middleware as 500 status codes
bisgaard-itis Apr 26, 2024
b0f9aa3
add profiling middleware to webserver
bisgaard-itis Apr 26, 2024
8d9bdae
add profiling middleware to webserver
bisgaard-itis Apr 26, 2024
88cc187
add profiling middleware to catalog, directorv2 etc
bisgaard-itis Apr 27, 2024
96aeadf
add profiling middleware to dynamic scheduler
bisgaard-itis Apr 27, 2024
97cf22b
allign api-server env var with the rest
bisgaard-itis Apr 27, 2024
1811284
add env vars to docker compose
bisgaard-itis Apr 27, 2024
02a199a
merge master into 5729-add-profiling-middleware-to-storage
bisgaard-itis Apr 29, 2024
6df33a9
remove pyinstrument from api-server reqs
bisgaard-itis Apr 29, 2024
6d3c2c3
@pcrespov use servicelib.mimetype_constants
bisgaard-itis Apr 29, 2024
0a0a6cb
@pcrespov @sanderegg use HTTPInternalServerError
bisgaard-itis Apr 29, 2024
afc2203
@sanderegg shorten env vars to enable profiling tool
bisgaard-itis Apr 29, 2024
62aeb81
avoid internal import
bisgaard-itis Apr 29, 2024
565487c
@pcrespov use a single header key
bisgaard-itis Apr 29, 2024
0de0e30
merge master into 5729-add-profiling-middleware-to-storage
bisgaard-itis Apr 29, 2024
9cc00a6
ensure next json object occurs on new line
bisgaard-itis Apr 29, 2024
e43c384
dont upgrade dependencies because of incompatible pytest-pytest_async…
bisgaard-itis Apr 29, 2024
9b803f8
make pylint happy
bisgaard-itis Apr 29, 2024
666a308
merge master into 5729-add-profiling-middleware-to-storage
bisgaard-itis Apr 30, 2024
ed0979b
merge master into 5729-add-profiling-middleware-to-storage
bisgaard-itis Apr 30, 2024
9e70b10
merge master into 5729-add-profiling-middleware-to-storage
bisgaard-itis Apr 30, 2024
81d98e4
dont use default in env vars
bisgaard-itis Apr 30, 2024
e0ce94b
make setting compulsary
bisgaard-itis Apr 30, 2024
7e295be
minor fix
bisgaard-itis Apr 30, 2024
6ef6c38
add envvar to webserver
bisgaard-itis Apr 30, 2024
433c62a
resolve merge conflicts
bisgaard-itis Apr 30, 2024
6c214d3
merge master into 5729-add-profiling-middleware-to-storage
bisgaard-itis Apr 30, 2024
f71c545
merge master into 5729-add-profiling-middleware-to-storage
bisgaard-itis May 2, 2024
af63987
set default values for profiling setting
bisgaard-itis May 2, 2024
5b33d02
reset test profiling setting
bisgaard-itis May 2, 2024
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
6 changes: 6 additions & 0 deletions .env-devel
Original file line number Diff line number Diff line change
Expand Up @@ -18,6 +18,7 @@ AGENT_VOLUMES_CLEANUP_S3_BUCKET=simcore-volume-backups
AGENT_VOLUMES_CLEANUP_S3_PROVIDER=MINIO

API_SERVER_DEV_FEATURES_ENABLED=0
API_SERVER_PROFILING=1

AUTOSCALING_DASK=null
AUTOSCALING_DRAIN_NODES_WITH_LABELS=False
Expand All @@ -34,6 +35,7 @@ BF_API_SECRET=none
CATALOG_DEV_FEATURES_ENABLED=0
CATALOG_SERVICES_DEFAULT_RESOURCES='{"CPU": {"limit": 0.1, "reservation": 0.1}, "RAM": {"limit": 2147483648, "reservation": 2147483648}}'
CATALOG_SERVICES_DEFAULT_SPECIFICATIONS='{}'
CATALOG_PROFILING=1

CLUSTERS_KEEPER_COMPUTATIONAL_BACKEND_DOCKER_IMAGE_TAG=master-github-latest
CLUSTERS_KEEPER_DASK_NTHREADS=0
Expand Down Expand Up @@ -63,6 +65,7 @@ COMPUTATIONAL_BACKEND_DEFAULT_CLUSTER_FILE_LINK_TYPE=S3
COMPUTATIONAL_BACKEND_DEFAULT_FILE_LINK_TYPE=PRESIGNED
COMPUTATIONAL_BACKEND_ON_DEMAND_CLUSTERS_FILE_LINK_TYPE=PRESIGNED
DIRECTOR_V2_DEV_FEATURES_ENABLED=0
DIRECTOR_V2_PROFILING=1

DYNAMIC_SIDECAR_ENDPOINT_SPECS_MODE_DNSRR_ENABLED=0
DYNAMIC_SIDECAR_IMAGE=${DOCKER_REGISTRY:-itisfoundation}/dynamic-sidecar:${DOCKER_IMAGE_TAG:-latest}
Expand Down Expand Up @@ -163,6 +166,7 @@ SIMCORE_SERVICES_NETWORK_NAME=interactive_services_subnet
STORAGE_ENDPOINT=storage:8080
STORAGE_HOST=storage
STORAGE_PORT=8080
STORAGE_PROFILING=1

SWARM_STACK_NAME=master-simcore

Expand All @@ -184,6 +188,7 @@ PROJECTS_INACTIVITY_INTERVAL=20
WEBSERVER_ANNOUNCEMENTS=1

WEBSERVER_DEV_FEATURES_ENABLED=0
WEBSERVER_PROFILING=1

WEBSERVER_HOST=webserver
WEBSERVER_PORT=8080
Expand Down Expand Up @@ -228,6 +233,7 @@ DIRECTOR_V2_PUBLIC_API_BASE_URL=http://127.0.0.1:8006
DYNAMIC_SIDECAR_ENABLE_VOLUME_LIMITS=False

DYNAMIC_SCHEDULER_STOP_SERVICE_TIMEOUT=3600
DYNAMIC_SCHEDULER_PROFILING=1

WEBSERVER_DIAGNOSTICS={}
DIAGNOSTICS_MAX_AVG_LATENCY=10
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,29 @@
import json

from servicelib.mimetype_constants import (
MIMETYPE_APPLICATION_JSON,
MIMETYPE_APPLICATION_ND_JSON,
)


def append_profile(body: str, profile: str) -> str:
try:
json.loads(body)
body += "\n" if not body.endswith("\n") else ""
bisgaard-itis marked this conversation as resolved.
Show resolved Hide resolved
except json.decoder.JSONDecodeError:
pass
body += json.dumps({"profile": profile})
return body


def check_response_headers(
response_headers: dict[bytes, bytes]
) -> list[tuple[bytes, bytes]]:
original_content_type: str = response_headers[b"content-type"].decode()
assert original_content_type in {
MIMETYPE_APPLICATION_ND_JSON.encode(),
MIMETYPE_APPLICATION_JSON.encode(),
} # nosec
headers: dict = {}
headers[b"content-type"] = MIMETYPE_APPLICATION_ND_JSON.encode()
return list(headers.items())
Original file line number Diff line number Diff line change
@@ -0,0 +1,41 @@
from aiohttp.web import HTTPInternalServerError, Request, StreamResponse, middleware
from pyinstrument import Profiler
from servicelib.mimetype_constants import (
MIMETYPE_APPLICATION_JSON,
MIMETYPE_APPLICATION_ND_JSON,
)

from .._utils_profiling_middleware import append_profile


@middleware
async def profiling_middleware(request: Request, handler):
profiler: Profiler | None = None
if request.headers.get("x-profile") is not None:
profiler = Profiler(async_mode="enabled")
profiler.start()

response = await handler(request)

if profiler is None:
return response
if response.content_type != MIMETYPE_APPLICATION_JSON:
raise HTTPInternalServerError(
reason=f"Profiling middleware is not compatible with {response.content_type=}",
bisgaard-itis marked this conversation as resolved.
Show resolved Hide resolved
headers={},
)

stream_response = StreamResponse(
status=response.status,
reason=response.reason,
headers=response.headers,
)
stream_response.content_type = MIMETYPE_APPLICATION_ND_JSON
await stream_response.prepare(request)
await stream_response.write(response.body)
profiler.stop()
await stream_response.write(
append_profile("\n", profiler.output_text(unicode=True, color=True)).encode()
)
await stream_response.write_eof()
return stream_response
Original file line number Diff line number Diff line change
@@ -1,46 +1,25 @@
import json
from typing import Any

from fastapi import FastAPI
from pyinstrument import Profiler
from servicelib.mimetype_constants import MIMETYPE_APPLICATION_JSON
from starlette.requests import Request


def _check_response_headers(
response_headers: dict[bytes, bytes]
) -> list[tuple[bytes, bytes]]:
original_content_type: str = response_headers[b"content-type"].decode()
assert original_content_type in {
"application/x-ndjson",
"application/json",
} # nosec
headers: dict = {}
headers[b"content-type"] = b"application/x-ndjson"
return list(headers.items())


def _append_profile(body: str, profile: str) -> str:
try:
json.loads(body)
body += "\n" if not body.endswith("\n") else ""
except json.decoder.JSONDecodeError:
pass
body += json.dumps({"profile": profile})
return body
from .._utils_profiling_middleware import append_profile, check_response_headers


def is_last_response(response_headers: dict[bytes, bytes], message: dict[str, Any]):
if (
content_type := response_headers.get(b"content-type")
) and content_type == b"application/json":
) and content_type == MIMETYPE_APPLICATION_JSON.encode():
return True
if (more_body := message.get("more_body")) is not None:
return not more_body
msg = "Could not determine if last response"
raise RuntimeError(msg)


class ApiServerProfilerMiddleware:
class ProfilerMiddleware:
"""Following
https://www.starlette.io/middleware/#cleanup-and-error-handling
https://www.starlette.io/middleware/#reusing-starlette-components
Expand All @@ -49,7 +28,7 @@ class ApiServerProfilerMiddleware:

def __init__(self, app: FastAPI):
self._app: FastAPI = app
self._profile_header_trigger: str = "x-profile-api-server"
self._profile_header_trigger: str = "x-profile"

async def __call__(self, scope, receive, send):
if scope["type"] != "http":
Expand All @@ -61,7 +40,7 @@ async def __call__(self, scope, receive, send):
request_headers = dict(request.headers)
response_headers: dict[bytes, bytes] = {}

if request_headers.get(self._profile_header_trigger) == "true":
if request_headers.get(self._profile_header_trigger) is not None:
request_headers.pop(self._profile_header_trigger)
scope["headers"] = [
(k.encode("utf8"), v.encode("utf8")) for k, v in request_headers.items()
Expand All @@ -74,11 +53,11 @@ async def _send_wrapper(message):
nonlocal response_headers
if message["type"] == "http.response.start":
response_headers = dict(message.get("headers"))
message["headers"] = _check_response_headers(response_headers)
message["headers"] = check_response_headers(response_headers)
elif message["type"] == "http.response.body":
if is_last_response(response_headers, message):
profiler.stop()
message["body"] = _append_profile(
message["body"] = append_profile(
message["body"].decode(),
profiler.output_text(unicode=True, color=True),
).encode()
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -12,6 +12,7 @@
# NOTE: mimetypes (https://docs.python.org/3/library/mimetypes.html) is already a module in python

MIMETYPE_APPLICATION_JSON: Final[str] = "application/json"
MIMETYPE_APPLICATION_ND_JSON: Final[str] = "application/x-ndjson"
bisgaard-itis marked this conversation as resolved.
Show resolved Hide resolved
MIMETYPE_APPLICATION_ZIP: Final[str] = "application/zip"
MIMETYPE_TEXT_HTML: Final[str] = "text/html"
MIMETYPE_TEXT_PLAIN: Final[str] = "text/plain"
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@
from fastapi_pagination import add_pagination
from httpx import HTTPError as HttpxException
from models_library.basic_types import BootModeEnum
from servicelib.fastapi.profiler_middleware import ProfilerMiddleware
from servicelib.logging_utils import config_all_loggers
from starlette import status
from starlette.exceptions import HTTPException
Expand Down Expand Up @@ -120,10 +121,8 @@ def init_app(settings: ApplicationSettings | None = None) -> FastAPI:
add_oec_to_message=True,
),
)
if settings.API_SERVER_DEV_FEATURES_ENABLED:
from ._profiler_middleware import ApiServerProfilerMiddleware

app.add_middleware(ApiServerProfilerMiddleware)
if settings.API_SERVER_PROFILING:
app.add_middleware(ProfilerMiddleware)

if app.state.settings.API_SERVER_PROMETHEUS_INSTRUMENTATION_ENABLED:
setup_prometheus_instrumentation(app)
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -88,6 +88,7 @@ class ApplicationSettings(BasicSettings):
API_SERVER_HEALTH_CHECK_TASK_TIMEOUT_SECONDS: PositiveInt = 10
API_SERVER_ALLOWED_HEALTH_CHECK_FAILURES: PositiveInt = 5
API_SERVER_PROMETHEUS_INSTRUMENTATION_COLLECT_SECONDS: PositiveInt = 5
API_SERVER_PROFILING: bool = False
# DEV-TOOLS
API_SERVER_DEV_HTTP_CALLS_LOGS_PATH: Path | None = Field(
default=None,
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@
from fastapi.middleware.gzip import GZipMiddleware
from models_library.basic_types import BootModeEnum
from servicelib.fastapi.openapi import override_fastapi_openapi_method
from servicelib.fastapi.profiler_middleware import ProfilerMiddleware
from servicelib.fastapi.prometheus_instrumentation import (
setup_prometheus_instrumentation,
)
Expand Down Expand Up @@ -67,6 +68,9 @@ def init_app(settings: ApplicationSettings | None = None) -> FastAPI:
if app.state.settings.CATALOG_PROMETHEUS_INSTRUMENTATION_ENABLED:
setup_prometheus_instrumentation(app)

if app.state.settings.CATALOG_PROFILING:
app.add_middleware(ProfilerMiddleware)

# EVENTS
async def _on_startup() -> None:
print(APP_STARTED_BANNER_MSG, flush=True)
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -71,6 +71,8 @@ class ApplicationSettings(BaseCustomSettings, MixinLoggingSettings):

CATALOG_PROMETHEUS_INSTRUMENTATION_ENABLED: bool = True

CATALOG_PROFILING: bool = False

# BACKGROUND TASK
CATALOG_BACKGROUND_TASK_REST_TIME: PositiveInt = 60
CATALOG_BACKGROUND_TASK_WAIT_AFTER_FAILURE: PositiveInt = 5 # secs
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@
get_common_oas_options,
override_fastapi_openapi_method,
)
from servicelib.fastapi.profiler_middleware import ProfilerMiddleware
from servicelib.fastapi.prometheus_instrumentation import (
setup_prometheus_instrumentation,
)
Expand Down Expand Up @@ -185,6 +186,9 @@ def init_app(settings: AppSettings | None = None) -> FastAPI:
if settings.DIRECTOR_V2_PROMETHEUS_INSTRUMENTATION_ENABLED:
setup_prometheus_instrumentation(app)

if settings.DIRECTOR_V2_PROFILING:
app.add_middleware(ProfilerMiddleware)

# setup app --
app.add_event_handler("startup", on_startup)
app.add_event_handler("shutdown", on_shutdown)
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -154,6 +154,7 @@ class AppSettings(BaseCustomSettings, MixinLoggingSettings):
description="Filepath to self-signed osparc.crt file *as mounted inside the container*, empty strings disables it",
)
DIRECTOR_V2_PROMETHEUS_INSTRUMENTATION_ENABLED: bool = True
DIRECTOR_V2_PROFILING: bool = False

DIRECTOR_V2_REMOTE_DEBUGGING_PORT: PortInt | None

Expand Down
7 changes: 7 additions & 0 deletions services/docker-compose.devel.yml
Original file line number Diff line number Diff line change
Expand Up @@ -11,6 +11,7 @@ services:
- SC_BOOT_MODE=debug
- LOG_LEVEL=DEBUG
- DEBUG=true
- API_SERVER_PROFILING=${API_SERVER_PROFILING:-0}
bisgaard-itis marked this conversation as resolved.
Show resolved Hide resolved
volumes:
- ./api-server:/devel/services/api-server
- ../packages:/devel/packages
Expand Down Expand Up @@ -47,6 +48,7 @@ services:
- SC_BOOT_MODE=debug
- DYNAMIC_SCHEDULER_LOGLEVEL=DEBUG
- DEBUG=true
- DYNAMIC_SCHEDULER_PROFILING=${DYNAMIC_SCHEDULER_PROFILING:-0}
volumes:
- ./dynamic-scheduler:/devel/services/dynamic-scheduler
- ../packages:/devel/packages
Expand All @@ -59,6 +61,7 @@ services:
- LOG_LEVEL=DEBUG
- DEBUG=true
- DYNAMIC_SIDECAR_MOUNT_PATH_DEV=${PWD}/services/dynamic-sidecar
- CATALOG_PROFILING=${CATALOG_PROFILING:-0}
volumes:
- ./catalog:/devel/services/catalog
- ../packages:/devel/packages
Expand Down Expand Up @@ -95,6 +98,7 @@ services:
- LOG_LEVEL=debug
- DEBUG=true
- DYNAMIC_SIDECAR_MOUNT_PATH_DEV=${PWD}/services/dynamic-sidecar
- DIRECTOR_V2_PROFILING=${DIRECTOR_V2_PROFILING:-0}
volumes:
- ./director-v2:/devel/services/director-v2
- ../packages:/devel/packages
Expand All @@ -115,6 +119,8 @@ services:
WEBSERVER_REMOTE_DEBUGGING_PORT: 3000
SC_BOOT_MODE: debug
WEBSERVER_LOGLEVEL: ${LOG_LEVEL:-DEBUG}
WEBSERVER_PROFILING: ${WEBSERVER_PROFILING:-0}


wb-db-event-listener:
volumes: *webserver-volumes-dev
Expand Down Expand Up @@ -186,6 +192,7 @@ services:
environment:
- SC_BOOT_MODE=debug
- STORAGE_LOGLEVEL=DEBUG
- STORAGE_PROFILING=${STORAGE_PROFILING:-0}

agent:
environment:
Expand Down
6 changes: 6 additions & 0 deletions services/docker-compose.yml
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,7 @@ services:
- API_SERVER_DEV_FEATURES_ENABLED=${API_SERVER_DEV_FEATURES_ENABLED}
- API_SERVER_DEV_HTTP_CALLS_LOGS_PATH=${API_SERVER_DEV_HTTP_CALLS_LOGS_PATH}
- API_SERVER_LOG_FORMAT_LOCAL_DEV_ENABLED=${LOG_FORMAT_LOCAL_DEV_ENABLED}
- API_SERVER_PROFILING=${API_SERVER_PROFILING:-0}

- CATALOG_HOST=${CATALOG_HOST}
- CATALOG_PORT=${CATALOG_PORT}
Expand Down Expand Up @@ -133,6 +134,7 @@ services:
- CATALOG_DEV_FEATURES_ENABLED=${CATALOG_DEV_FEATURES_ENABLED}
- CATALOG_SERVICES_DEFAULT_RESOURCES=${CATALOG_SERVICES_DEFAULT_RESOURCES}
- CATALOG_SERVICES_DEFAULT_SPECIFICATIONS=${CATALOG_SERVICES_DEFAULT_SPECIFICATIONS}
- CATALOG_PROFILING=${CATALOG_PROFILING:-0}
- DIRECTOR_HOST=${DIRECTOR_HOST:-director}
- DIRECTOR_PORT=${DIRECTOR_PORT:-8080}
- LOG_LEVEL=${LOG_LEVEL:-WARNING}
Expand Down Expand Up @@ -271,6 +273,7 @@ services:
- DIRECTOR_V2_DYNAMIC_SCHEDULER_CLOSE_SERVICES_VIA_FRONTEND_WHEN_CREDITS_LIMIT_REACHED=${DIRECTOR_V2_DYNAMIC_SCHEDULER_CLOSE_SERVICES_VIA_FRONTEND_WHEN_CREDITS_LIMIT_REACHED}
- DIRECTOR_V2_PUBLIC_API_BASE_URL=${DIRECTOR_V2_PUBLIC_API_BASE_URL}
- DIRECTOR_V2_SERVICES_CUSTOM_CONSTRAINTS=${DIRECTOR_V2_SERVICES_CUSTOM_CONSTRAINTS}
- DIRECTOR_V2_PROFILING=${DIRECTOR_V2_PROFILING:-0}

- DYNAMIC_SIDECAR_ENDPOINT_SPECS_MODE_DNSRR_ENABLED=${DYNAMIC_SIDECAR_ENDPOINT_SPECS_MODE_DNSRR_ENABLED}
- DYNAMIC_SIDECAR_ENABLE_VOLUME_LIMITS=${DYNAMIC_SIDECAR_ENABLE_VOLUME_LIMITS}
Expand Down Expand Up @@ -442,6 +445,7 @@ services:
- DIRECTOR_V2_HOST=${DIRECTOR_V2_HOST}
- DIRECTOR_V2_PORT=${DIRECTOR_V2_PORT}
- DYNAMIC_SCHEDULER_STOP_SERVICE_TIMEOUT=${DYNAMIC_SCHEDULER_STOP_SERVICE_TIMEOUT}
- DYNAMIC_SCHEDULER_PROFILING=${DYNAMIC_SCHEDULER_PROFILING:-0}

static-webserver:
image: ${DOCKER_REGISTRY:-itisfoundation}/static-webserver:${DOCKER_IMAGE_TAG:-latest}
Expand Down Expand Up @@ -507,6 +511,7 @@ services:
WEBSERVER_DEV_FEATURES_ENABLED: ${WEBSERVER_DEV_FEATURES_ENABLED}

WEBSERVER_LOGLEVEL: ${WEBSERVER_LOGLEVEL}
WEBSERVER_PROFILING: ${WEBSERVER_PROFILING:-0}

WEBSERVER_LOG_FORMAT_LOCAL_DEV_ENABLED: ${LOG_FORMAT_LOCAL_DEV_ENABLED}

Expand Down Expand Up @@ -968,6 +973,7 @@ services:
- STORAGE_LOGLEVEL=${LOG_LEVEL:-WARNING}
- STORAGE_MONITORING_ENABLED=1
- TRACING_ZIPKIN_ENDPOINT=${TRACING_ZIPKIN_ENDPOINT:-http://jaeger:9411}
- STORAGE_PROFILING=${STORAGE_PROFILING:-0}
networks:
- default
- interactive_services_subnet
Expand Down
Loading
Loading