def process_request(self, request):
request_model = None
if _should_intercept(request):
Logger.debug('process_request')
request.silk_is_intercepted = True
self._apply_dynamic_mappings()
if not hasattr(SQLCompiler, '_execute_sql'):
SQLCompiler._execute_sql = SQLCompiler.execute_sql
SQLCompiler.execute_sql = execute_sql
request_model = RequestModelFactory(
request).construct_request_model()
DataCollector().configure(request_model)
def process_request(self, request):
DataCollector().clear()
if not _should_intercept(request):
return
Logger.debug('process_request')
request.silk_is_intercepted = True
self._apply_dynamic_mappings()
if not hasattr(SQLCompiler, '_execute_sql'):
SQLCompiler._execute_sql = SQLCompiler.execute_sql
SQLCompiler.execute_sql = execute_sql
silky_config = SilkyConfig()
should_profile = silky_config.SILKY_PYTHON_PROFILER
if silky_config.SILKY_PYTHON_PROFILER_FUNC:
should_profile = silky_config.SILKY_PYTHON_PROFILER_FUNC(request)
request_model = RequestModelFactory(request).construct_request_model()
DataCollector().configure(request_model, should_profile=should_profile)
def wrapped_target(*args, **kwargs):
request = DataCollector().request
if request:
start_time = timezone.now()
result = target(*args, **kwargs)
end_time = timezone.now()
curr = request.meta_time or 0
request.meta_time = curr + _time_taken(
start_time, end_time)
else:
result = target(*args, **kwargs)
return result
def call_execute_sql(cls, request):
DataCollector().configure(request=request)
delete_all_models(SQLQuery)
cls.mock_sql, cls.query_string = mock_sql()
kwargs = {
'one': 1,
'two': 2
}
cls.args = [1, 2]
cls.kwargs = kwargs
with patch('silk.sql.connection'):
execute_sql(cls.mock_sql, *cls.args, **cls.kwargs)
def _process_response(self, request, response):
with silk_meta_profiler():
collector = DataCollector()
collector.stop_python_profiler()
silk_request = collector.request
if silk_request:
silk_request.end_time = timezone.now()
collector.finalise()
if response.accepted_media_type == 'application/json':
response['num_sql_queries'] = silk_request.num_sql_queries
response[
'time_spent_on_sql_queries'] = silk_request.time_spent_on_sql_queries
response['time_taken'] = silk_request.time_taken
def wrapped_target(*args, **kwargs):
request = DataCollector().request
if request:
start_time = timezone.now()
result = target(*args, **kwargs)
end_time = timezone.now()
curr = request.meta_time or 0
request.meta_time = curr + _time_taken(start_time, end_time)
else:
Logger.error('Cant perform meta profile due to no request model in DataCollector. '
'Has Silk middleware been installed properly?')
result = target(*args, **kwargs)
return result
def execute_sql(self, *args, **kwargs):
"""wrapper around real execute_sql in order to extract information"""
try:
q, params = self.as_sql()
if not q:
raise EmptyResultSet
except EmptyResultSet:
try:
result_type = args[0]
except IndexError:
result_type = kwargs.get('result_type', 'multi')
if result_type == 'multi':
return iter([])
else:
return
tb = ''.join(reversed(traceback.format_stack()))
sql_query = q % params
if _should_wrap(sql_query):
query_dict = {
'query': sql_query,
'start_time': timezone.now(),
'traceback': tb
}
try:
return self._execute_sql(*args, **kwargs)
finally:
query_dict['end_time'] = timezone.now()
request = DataCollector().request
if request:
query_dict['request'] = request
if self.query.model.__module__ != 'silk.models':
query_dict['analysis'] = _explain_query(
self.connection, q, params)
DataCollector().register_query(query_dict)
else:
DataCollector().register_silk_query(query_dict)
return self._execute_sql(*args, **kwargs)
def __exit__(self, exc_type, exc_val, exc_tb):
if self._should_meta_profile:
end_time = timezone.now()
exception_raised = exc_type is not None
if exception_raised:
Logger.error(
'Exception when performing meta profiling, dumping trace below'
)
traceback.print_exception(exc_type, exc_val, exc_tb)
request = getattr(DataCollector().local, 'request', None)
if request:
curr = request.meta_time or 0
request.meta_time = curr + _time_taken(self.start_time,
end_time)
def _process_response(self, response):
with silk_meta_profiler():
collector = DataCollector()
collector.stop_python_profiler()
silk_request = collector.request
if silk_request:
silk_response = ResponseModelFactory(
response).construct_response_model()
silk_response.save()
silk_request.end_time = timezone.now()
collector.finalise()
silk_request.save()
else:
Logger.error(
'No request model was available when processing response. Did something go wrong in process_request/process_view?'
)
def __exit__(self, exc_type, exc_val, exc_tb):
if self._should_meta_profile:
end_time = timezone.now()
exception_raised = exc_type is not None
if exception_raised:
Logger.error(
'Exception when performing meta profiling, dumping trace below'
)
traceback.print_exception(exc_type, exc_val, exc_tb)
request = DataCollector().request
if request:
curr = request.meta_time or 0
request.meta_time = curr + _time_taken(self.start_time,
end_time)
else:
Logger.error(
'Cant perform meta profile due to no request model in DataCollector. '
'Has Silk middleware been installed properly?')
def _get_query_timing(self, request):
try:
from silk.collector import DataCollector
from silk.profiling.profiler import silk_meta_profiler, silk_profile
except ModuleNotFoundError:
return
if not hasattr(request, 'silk_is_intercepted'):
return
with silk_meta_profiler():
collector = DataCollector()
silk_request = collector.request
if silk_request:
TimedService(
name="sql",
description="DB Queries",
duration=sum(
[s.time_taken for s in silk_request.queries.all()]),
)
def test_queries_before(self):
"""test that any queries registered before profiling begins are ignored"""
DataCollector().configure(Request.objects.create())
DataCollector().register_query(*MockSuite().mock_sql_queries(n=2, as_dict=True))
before = [x for x in DataCollector().queries]
with silk_profile(name='test_no_queries_before_profile'):
mock_queries = MockSuite().mock_sql_queries(n=5, as_dict=True)
DataCollector().register_query(*mock_queries)
profile = list(DataCollector().profiles.values())[0]
self.assertEqual(profile['name'], 'test_no_queries_before_profile')
queries = profile['queries']
self.assertEqual(len(queries), 5)
for query in set(DataCollector().queries).difference(before):
self.assertIn(query, queries)
def _process_response(self, response):
Logger.debug('Process response')
with silk_meta_profiler():
collector = DataCollector()
collector.stop_python_profiler()
silk_request = collector.request
if silk_request:
silk_response = ResponseModelFactory(
response).construct_response_model()
silk_response.save()
else:
Logger.error(
'No request model was available when processing response. Did something go wrong in process_request/process_view?'
)
# Need to save the data outside the silk_meta_profiler
# Otherwise the meta time collected in the context manager
# is not taken in account
if silk_request:
silk_request.save()
Logger.debug('Process response done.')
def execute(self, sql, params=()):
tb = ''.join(reversed(traceback.format_stack()))
try:
sql_query = sql % tuple(params)
except UnicodeDecodeError as ex:
# TODO: investigate error.
Logger.error(
'Exception while applying query parameters to record a query.')
sql_query = 'UnicodeDecodeError while applying parameters to query: %s' % ex
if not _should_wrap(sql_query):
return self.cursor.execute(sql, params)
query_dict = {
'query': sql_query,
'start_time': timezone.now(),
'traceback': tb
}
try:
return self.cursor.execute(sql, params)
finally:
query_dict['end_time'] = timezone.now()
DataCollector().register_query(query_dict)
def __enter__(self):
if self._silk_installed() and self._should_profile():
with silk_meta_profiler():
self._start_queries()
if not self.name:
raise ValueError('silk_profile used as a context manager must have a name')
frame = inspect.currentframe()
frames = inspect.getouterframes(frame)
outer_frame = frames[1]
path = outer_frame[1]
line_num = outer_frame[2]
request = DataCollector().request
self.profile = {
'name': self.name,
'file_path': path,
'line_num': line_num,
'dynamic': self._dynamic,
'request': request,
'start_time': timezone.now(),
}
else:
Logger.warn('Cannot execute silk_profile as silk is not installed correctly.')
def process_response(self, request, response):
if _should_intercept(request):
meta_start_time = None
if SilkyConfig().SILKY_META:
meta_start_time = timezone.now()
collector = DataCollector()
silk_request = collector.request
if silk_request:
silk_response = ResponseModelFactory(
response).construct_response_model()
silk_response.save()
silk_request.end_time = timezone.now()
collector.finalise()
if SilkyConfig().SILKY_META:
meta_end_time = timezone.now()
silk_request.meta_start_time = meta_start_time
silk_request.meta_end_time = meta_end_time
silk_request.save()
else:
Logger.error(
'No request model was available when processing response. Did something go wrong in process_request/process_view?'
)
return response
def test_clear(self):
self.test_query_registration()
DataCollector().clear()
self.assertFalse(DataCollector().queries)
def _should_profile(self):
return DataCollector().request is not None
def _query(self):
try:
query = list(DataCollector().queries)[0]
except IndexError:
self.fail('No queries created')
return query
def _get_query(self):
query = list(DataCollector().queries)[0]
return query
def test_count(self):
self.assertEqual(1, len(DataCollector().queries))
def __init__(self, response):
super(ResponseModelFactory, self).__init__()
self.response = response
self.request = DataCollector().request
def setUp(self):
DataCollector().request = Request.objects.create()
def setUpClass(cls):
super(TestProfilertContextManager, cls).setUpClass()
r = Request.objects.create()
DataCollector().configure(r)
with silk_profile(name='test_profile'):
sleep(0.1)
def _query_identifiers_from_collector(self):
return [x for x in DataCollector().queries]
def test_time_taken(self):
profile = list(DataCollector().profiles.values())[0]
time_taken = _time_taken(start_time=profile['start_time'],
end_time=profile['end_time'])
self.assertGreaterEqual(time_taken, 100)
self.assertLess(time_taken, 110)
def test_name(self):
profile = list(DataCollector().profiles.values())[0]
self.assertEqual(profile['name'], 'func')
def test_one_object(self):
self.assertTrue(len(DataCollector().profiles), 1)
def test_query_registration(self):
mock_query = {}
DataCollector().register_query(mock_query)
self.assertIn(mock_query, list(DataCollector().queries.values()))
def test_singleton(self):
a = DataCollector()
b = DataCollector()
c = DataCollector()
self.assertTrue(a == b == c)
