Skip to content

Commit 0184335

Browse files
committed
feat(profiling): Add request profiling middleware
This commit introduces `ProfileRequestMiddleware` to provide performance insights for API requests, migrating and generalizing functionality from AWX's `TimingMiddleware` and `AWXProfiler`. This makes the functionality available to any consumer of `django-ansible-base`. The middleware always adds an `X-API-Time` header to the response, indicating the total time taken to process the request. To help locate profiling data, it also adds an `X-API-Node` header with the cluster host ID if one is not already present in the response. When the `ANSIBLE_BASE_CPROFILE_REQUESTS` setting is enabled, the middleware will also perform a cProfile analysis for each request. The resulting `.prof` file is saved to a temporary directory on the node that served the request, and its path is returned in the `X-API-CProfile-File` response header. For the most accurate and reliable timing, it is recommended to add this middleware to the top of the `MIDDLEWARE` list in your settings. The core profiling logic is encapsulated in the `DABProfiler` class, which can be imported and used directly for profiling non-HTTP contexts, such as background tasks. This commit also includes a `README.md` file with documentation for the new middleware and profiler, including usage examples and tests in the test_app.
1 parent f674f41 commit 0184335

File tree

3 files changed

+237
-0
lines changed

3 files changed

+237
-0
lines changed
Lines changed: 88 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,88 @@
1+
# Request Profiling
2+
3+
The `ProfileRequestMiddleware` and `DABProfiler` class provide a way to profile requests and other code in your Django application. This functionality is a generalization of the profiling tools found in AWX and can be used by any `django-ansible-base` consumer.
4+
5+
## `ProfileRequestMiddleware`
6+
7+
This middleware provides performance insights for API requests. To use it, add it to your `MIDDLEWARE` list in your Django settings. For the most accurate and reliable timing, it is recommended to add this middleware to the top of the `MIDDLEWARE` list.
8+
9+
```python
10+
# settings.py
11+
MIDDLEWARE = [
12+
'ansible_base.lib.middleware.profiling.profile_request.ProfileRequestMiddleware',
13+
...
14+
]
15+
```
16+
17+
The middleware always adds the following headers to the response:
18+
19+
* `X-API-Time`: The total time taken to process the request, in seconds.
20+
* `X-API-Node`: The cluster host ID of the node that served the request. This header is only added if it is not already present in the response.
21+
22+
### cProfile Support
23+
24+
When the `ANSIBLE_BASE_CPROFILE_REQUESTS` setting is enabled, the middleware will also perform a cProfile analysis for each request. The resulting `.prof` file is saved to a temporary directory on the node that served the request, and its path is returned in the `X-API-CProfile-File` response header.
25+
26+
To enable cProfile support, set the following in your Django settings:
27+
28+
```python
29+
# settings.py
30+
ANSIBLE_BASE_CPROFILE_REQUESTS = True
31+
```
32+
33+
## `DABProfiler`
34+
35+
The core profiling logic is encapsulated in the `DABProfiler` class. This class can be imported and used directly for profiling non-HTTP contexts, such as background tasks or gRPC services.
36+
37+
The profiler's cProfile functionality is controlled by the `ANSIBLE_BASE_CPROFILE_REQUESTS` setting.
38+
39+
- When the setting is `True`, `profiler.stop()` returns a tuple of `(elapsed_time, cprofile_filename)`.
40+
- When the setting is `False`, `profiler.stop()` returns `(elapsed_time, None)`.
41+
42+
### Example Usage
43+
44+
```python
45+
from ansible_base.lib.middleware.profiling.profile_request import DABProfiler
46+
47+
def my_background_task():
48+
profiler = DABProfiler()
49+
profiler.start()
50+
51+
# Your code here
52+
53+
elapsed, cprofile_filename = profiler.stop()
54+
55+
if cprofile_filename:
56+
print(f"cProfile data saved to: {cprofile_filename}")
57+
58+
print(f"Task took {elapsed:.3f}s to complete.")
59+
```
60+
61+
## Visualizing Profile Data
62+
63+
The `.prof` files generated by the cProfile support can be analyzed with a variety of tools.
64+
65+
### SnakeViz
66+
67+
[SnakeViz](https://jiffyclub.github.io/snakeviz/) is a browser-based graphical viewer for the output of Python profilers.
68+
69+
You can install it with pip:
70+
```bash
71+
pip install snakeviz
72+
```
73+
74+
To visualize a profile file, run:
75+
```bash
76+
snakeviz /path/to/your/profile.prof
77+
```
78+
79+
### pstats
80+
81+
The standard library `pstats` module can also be used to read and manipulate profile data.
82+
83+
```python
84+
import pstats
85+
86+
p = pstats.Stats('/path/to/your/profile.prof')
87+
p.sort_stats('cumulative').print_stats(10)
88+
```
Lines changed: 82 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,82 @@
1+
import cProfile
2+
import logging
3+
import os
4+
import tempfile
5+
import threading
6+
import time
7+
import uuid
8+
from typing import Optional, Union
9+
10+
from django.utils.translation import gettext_lazy as _
11+
12+
from ansible_base.lib.utils.settings import get_function_from_setting, get_setting
13+
14+
logger = logging.getLogger(__name__)
15+
16+
17+
class DABProfiler:
18+
def __init__(self, *args, **kwargs):
19+
self.cprofiling = bool(get_setting('ANSIBLE_BASE_CPROFILE_REQUESTS', False))
20+
self.prof = None
21+
self.start_time = None
22+
23+
def start(self):
24+
self.start_time = time.time()
25+
if self.cprofiling:
26+
self.prof = cProfile.Profile()
27+
self.prof.enable()
28+
29+
def stop(self, profile_id: Optional[Union[str, uuid.UUID]] = None):
30+
if self.start_time is None:
31+
logger.debug("Attempting to stop profiling without having started...")
32+
return None, None
33+
34+
elapsed = time.time() - self.start_time
35+
36+
if not profile_id:
37+
profile_id = uuid.uuid4()
38+
39+
cprofile_filename = None
40+
41+
if self.cprofiling and self.prof:
42+
self.prof.disable()
43+
temp_dir = tempfile.gettempdir()
44+
filename = f"cprofile-{profile_id}.prof"
45+
cprofile_filename = os.path.join(temp_dir, filename)
46+
self.prof.dump_stats(cprofile_filename)
47+
48+
return elapsed, cprofile_filename
49+
50+
51+
class ProfileRequestMiddleware(threading.local):
52+
def __init__(self, get_response=None):
53+
self.get_response = get_response
54+
self.profiler = DABProfiler()
55+
56+
def __call__(self, request):
57+
# Logic before the view (formerly process_request)
58+
self.profiler.start()
59+
request_id = request.headers.get('X-Request-ID')
60+
61+
# Call the next middleware or the view
62+
response = self.get_response(request)
63+
64+
# Logic after the view (formerly process_response)
65+
if getattr(self.profiler, 'start_time', None) is None:
66+
return response
67+
68+
elapsed, cprofile_filename = self.profiler.stop(profile_id=request_id)
69+
70+
if elapsed is not None:
71+
response['X-API-Time'] = f'{elapsed:.3f}s'
72+
if 'X-API-Node' not in response:
73+
response['X-API-Node'] = get_setting('CLUSTER_HOST_ID', _('Unknown'))
74+
75+
if cprofile_filename:
76+
response['X-API-CProfile-File'] = cprofile_filename
77+
logger.debug(
78+
f'request: {request}, cprofile_file: {response["X-API-CProfile-File"]}',
79+
extra=dict(python_objects=dict(request=request, response=response, X_API_CPROFILE_FILE=response["X-API-CProfile-File"])),
80+
)
81+
82+
return response
Lines changed: 67 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,67 @@
1+
2+
import os
3+
import tempfile
4+
from unittest.mock import patch
5+
6+
from django.http import HttpResponse
7+
from django.test import TestCase, override_settings
8+
from django.urls import path
9+
10+
from ansible_base.lib.middleware.profiling.profile_request import ProfileRequestMiddleware
11+
12+
# A simple view for testing middleware
13+
def simple_view(request):
14+
return HttpResponse("OK")
15+
16+
# Define URL patterns for the test
17+
urlpatterns = [
18+
path('test/', simple_view),
19+
]
20+
21+
@override_settings(ROOT_URLCONF=__name__)
22+
class ProfileRequestMiddlewareTest(TestCase):
23+
@override_settings(CLUSTER_HOST_ID='test-node')
24+
def test_profile_request_middleware_headers(self):
25+
"""
26+
Test that the ProfileRequestMiddleware adds sensible headers.
27+
"""
28+
middleware = ProfileRequestMiddleware(simple_view)
29+
response = middleware(self.client.get('/test/').wsgi_request)
30+
31+
# Test X-API-Time
32+
self.assertIn('X-API-Time', response)
33+
self.assertTrue(response['X-API-Time'].endswith('s'))
34+
try:
35+
float(response['X-API-Time'][:-1])
36+
except ValueError:
37+
self.fail("X-API-Time value is not a valid float")
38+
39+
# Test X-API-Node
40+
self.assertIn('X-API-Node', response)
41+
self.assertEqual(response['X-API-Node'], 'test-node')
42+
43+
@override_settings(ANSIBLE_BASE_CPROFILE_REQUESTS=True)
44+
def test_profile_request_middleware_cprofile_enabled(self):
45+
"""
46+
Test that the ProfileRequestMiddleware adds the X-API-CProfile-File
47+
header and creates a profile file when enabled.
48+
"""
49+
with tempfile.TemporaryDirectory() as tmpdir:
50+
with patch('tempfile.gettempdir', return_value=tmpdir):
51+
middleware = ProfileRequestMiddleware(simple_view)
52+
response = middleware(self.client.get('/test/').wsgi_request)
53+
self.assertIn('X-API-CProfile-File', response)
54+
profile_file = response['X-API-CProfile-File']
55+
self.assertTrue(profile_file.endswith('.prof'))
56+
self.assertTrue(os.path.exists(profile_file))
57+
58+
def test_profile_request_middleware_cprofile_disabled(self):
59+
"""
60+
Test that the ProfileRequestMiddleware does not add the
61+
X-API-CProfile-File header when disabled.
62+
"""
63+
middleware = ProfileRequestMiddleware(simple_view)
64+
response = middleware(self.client.get('/test/').wsgi_request)
65+
self.assertNotIn('X-API-CProfile-File', response)
66+
67+

0 commit comments

Comments
 (0)