def run(self, func, key, *args, **kwargs):
"""Profile a function and store its information."""
start_time = datetime.now()
value = func(*args, **kwargs)
end_time = datetime.now()
this_time = ms_from_timedelta(end_time - start_time)
values = {
'args': args,
'kwargs': kwargs,
'count': 0,
'hits': 0,
'time': 0.0
}
row = self.grouped.setdefault(key, {}).setdefault(func.__name__, values)
row['count'] += 1
row['time'] += this_time
if value is not None:
row['hits'] += 1
self.calls.setdefault(key, []).append({
'func': func,
'args': args,
'kwargs': kwargs,
'time': this_time,
'hit': value is not None,
#'stack': [s[1:] for s in inspect.stack()[2:]],
})
row = self.summary.setdefault(key, {'count': 0, 'time': 0.0, 'hits': 0})
row['count'] += 1
row['time'] += this_time
if value is not None:
row['hits'] += 1
return value
def executemany(self, sql, param_list):
start = datetime.now()
try:
return self.cursor.executemany(sql, param_list)
finally:
stop = datetime.now()
duration = ms_from_timedelta(stop - start)
if self.logger:
message = sql
message = 'Executed %s times\n%s' % message
self.logger.debug(message, extra= {'duration':duration})
self.logger.debug('Found %s matching rows' % self.cursor.rowcount, extra = {'duration':duration, 'id':'query'})
self.db.queries.append({
'sql': '%s times: %s' % (len(param_list), sql),
'time': duration,
})
def execute(self, sql, params=()):
start = datetime.now()
try:
return self.cursor.execute(sql, params)
finally:
stop = datetime.now()
duration = ms_from_timedelta(stop - start)
# stacktrace = tidy_stacktrace(traceback.extract_stack())
# template_info = None
# # TODO: can probably move this into utils
# cur_frame = sys._getframe().f_back
# try:
# while cur_frame is not None:
# if cur_frame.f_code.co_name == 'render':
# node = cur_frame.f_locals['self']
# if isinstance(node, Node):
# template_info = get_template_info(node.source)
# break
# cur_frame = cur_frame.f_back
# except:
# pass
# del cur_frame
try:
# XXX: It might just be more sane to not bother relying on this per #12923
sql = self.db.ops.last_executed_query(self.cursor, sql, params)
except:
sql = sql % params
if self.logger:
self.logger.debug(sql, extra = {'duration':duration})
if self.cursor.rowcount >= 0:
self.logger.debug('Found %s matching rows', self.cursor.rowcount, extra={'duration':duration})
self.db.queries.append({
'sql': sql,
'time': duration,
})
def process_response(self, request, response):
duration = datetime.now() - self.start
self.logger.info('Total time to render was %.2fs', ms_from_timedelta(duration) / 1000)
return response
