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