def sql_debug_total_time():
try:
log = get_current_request().iommi_sql_debug_log
except AttributeError:
return None
return sum(x['duration'] for x in log)
def sql_debug_last_call(response):
request = get_current_request()
if get_sql_debug() == SQL_DEBUG_LEVEL_WORST and hasattr(
request, 'iommi_sql_debug_log'
): # hasattr check because process_request might not be called in case of an early redirect
stacks = defaultdict(list)
fill_stacks(request.iommi_sql_debug_log)
for x in request.iommi_sql_debug_log:
stacks[x['sql']].append(x)
highscore = sorted([(len(logs), stack_trace, logs)
for stack_trace, logs in stacks.items()])
# Print the worst offenders
number_of_offenders = getattr(settings,
'SQL_DEBUG_WORST_NUMBER_OF_OFFENDERS', 3)
query_cutoff = getattr(settings, 'SQL_DEBUG_WORST_QUERY_CUTOFF', 4)
num_suspicious = getattr(settings, 'SQL_DEBUG_WORST_SUSPICIOUS_CUTOFF',
3)
for count, _, logs in highscore[-number_of_offenders:]:
if count > num_suspicious: # 3 times is ok-ish, more is suspicious
sql_debug(f'------ {count} times: -------', bold=True)
if hasattr(response, 'iommi_part'):
from iommi.debug import filename_and_line_num_from_part
filename, lineno = filename_and_line_num_from_part(
response.iommi_part)
sql_debug('From source:')
sql_debug(format_clickable_filename(
filename, lineno, str(response.iommi_part._name)),
sql_trace=True)
sql_debug('With Stack:')
sql_debug(logs[0]['stack'], sql_trace=True)
for x in logs[:query_cutoff]:
sql_debug_trace_sql(**x)
if len(logs) > query_cutoff:
sql_debug(
f'... and {len(logs) - query_cutoff:d} more unique statements\n'
)
queries_per_using = defaultdict(int)
for x in request.iommi_sql_debug_log:
queries_per_using[x['using']] += 1
sql_debug(
f'Total number of SQL statements: {sum(queries_per_using.values())}\n'
)
if settings.DEBUG:
total_sql_time = f" (sql time: {sql_debug_total_time():.3f}s)"
duration = f' ({(datetime.now() - request.iommi_start_time).total_seconds():.3f}s)'
sql_debug(
msg=
f'{request.META["REQUEST_METHOD"]} {request.get_full_path()} -> {response.status_code} {duration}{total_sql_time}'
)
sql_debug(
f'{request.get_full_path()} -> {response.status_code}{duration}',
fg='magenta')
set_sql_debug(None)
def sql_debug_log_to_request(**data):
request = get_current_request()
if request is not None:
try:
request.iommi_sql_debug_log.append(data)
except AttributeError:
request.iommi_sql_debug_log = [data]
level = get_sql_debug()
if level is False or level == SQL_DEBUG_LEVEL_WORST:
return
sql_debug_trace_sql(**data)
def sql_debug_last_call(response):
request = get_current_request()
if get_sql_debug() == SQL_DEBUG_LEVEL_WORST and hasattr(
request, 'iommi_sql_debug_log'
): # hasattr check because process_request might not be called in case of an early redirect
stacks = defaultdict(list)
fill_stacks(request.iommi_sql_debug_log)
for x in request.iommi_sql_debug_log:
stacks[x['sql']].append(x)
highscore = sorted([(len(logs), stack_trace, logs)
for stack_trace, logs in stacks.items()])
# Print the worst offenders
number_of_offenders = getattr(settings,
'SQL_DEBUG_WORST_NUMBER_OF_OFFENDERS', 3)
query_cutoff = getattr(settings, 'SQL_DEBUG_WORST_QUERY_CUTOFF', 4)
num_suspicious = getattr(settings, 'SQL_DEBUG_WORST_SUSPICIOUS_CUTOFF',
3)
for count, _, logs in highscore[-number_of_offenders:]:
if count > num_suspicious: # 3 times is ok-ish, more is suspicious
sql_debug(f'------ {count} times: -------', bold=True)
sql_debug(logs[0]['stack'], sql_trace=True)
for x in logs[:query_cutoff]:
sql_debug_trace_sql(**x)
if len(logs) > query_cutoff:
sql_debug(
f'... and {len(logs) - query_cutoff:d} more unique statements\n'
)
queries_per_using = defaultdict(int)
for x in request.iommi_sql_debug_log:
queries_per_using[x['using']] += 1
sql_debug(
f'Total number of SQL statements: {sum(queries_per_using.values())}, {queries_per_using.get("read-only")} read-only, {queries_per_using.get("summary")} summary\n'
)
if settings.DEBUG:
total_sql_time = sql_debug_total_time()
if total_sql_time is not None:
total_time = f"total sql time: {total_sql_time:.3f}"
sql_debug(
msg=
f'{request.META["REQUEST_METHOD"]} {request.get_full_path()} {total_time}'
)
duration = '-'
if hasattr(request, '_start_time'):
duration = f'{(datetime.now() - request._start_time).total_seconds():.3f}s'
sql_debug(f'{request.get_full_path()} -> {response.status_code}',
fg='magenta',
duration=duration)
set_sql_debug(None)