159 lines
5.2 KiB
Python
159 lines
5.2 KiB
Python
"""This optional pass adds logging of various executed operations.
|
|
|
|
Some subset of the executed operations are logged to the mypyc_trace.txt file.
|
|
|
|
This is useful for performance analysis. For example, it's possible
|
|
to identify how frequently various primitive functions are called,
|
|
and in which code locations they are called.
|
|
"""
|
|
|
|
from __future__ import annotations
|
|
|
|
from typing import Final
|
|
|
|
from mypyc.ir.func_ir import FuncIR
|
|
from mypyc.ir.ops import (
|
|
Box,
|
|
Call,
|
|
CallC,
|
|
Cast,
|
|
CString,
|
|
DecRef,
|
|
GetAttr,
|
|
IncRef,
|
|
LoadLiteral,
|
|
LoadStatic,
|
|
Op,
|
|
PrimitiveOp,
|
|
SetAttr,
|
|
Unbox,
|
|
Value,
|
|
)
|
|
from mypyc.ir.rtypes import none_rprimitive
|
|
from mypyc.irbuild.ll_builder import LowLevelIRBuilder
|
|
from mypyc.options import CompilerOptions
|
|
from mypyc.primitives.misc_ops import log_trace_event
|
|
from mypyc.transform.ir_transform import IRTransform
|
|
|
|
|
|
def insert_event_trace_logging(fn: FuncIR, options: CompilerOptions) -> None:
|
|
builder = LowLevelIRBuilder(None, options)
|
|
transform = LogTraceEventTransform(builder, fn.decl.fullname)
|
|
transform.transform_blocks(fn.blocks)
|
|
fn.blocks = builder.blocks
|
|
|
|
|
|
def get_load_global_name(op: CallC) -> str | None:
|
|
name = op.function_name
|
|
if name == "CPyDict_GetItem":
|
|
arg = op.args[0]
|
|
if (
|
|
isinstance(arg, LoadStatic)
|
|
and arg.namespace == "static"
|
|
and arg.identifier == "globals"
|
|
and isinstance(op.args[1], LoadLiteral)
|
|
):
|
|
return str(op.args[1].value)
|
|
return None
|
|
|
|
|
|
# These primitives perform an implicit IncRef for the return value. Only some of the most common ones
|
|
# are included, and mostly ops that could be switched to use borrowing in some contexts.
|
|
primitives_that_inc_ref: Final = {
|
|
"list_get_item_unsafe",
|
|
"CPyList_GetItemShort",
|
|
"CPyDict_GetWithNone",
|
|
"CPyList_GetItem",
|
|
"CPyDict_GetItem",
|
|
"CPyList_PopLast",
|
|
}
|
|
|
|
|
|
class LogTraceEventTransform(IRTransform):
|
|
def __init__(self, builder: LowLevelIRBuilder, fullname: str) -> None:
|
|
super().__init__(builder)
|
|
self.fullname = fullname.encode("utf-8")
|
|
|
|
def visit_call(self, op: Call) -> Value:
|
|
# TODO: Use different op name when constructing an instance
|
|
return self.log(op, "call", op.fn.fullname)
|
|
|
|
def visit_primitive_op(self, op: PrimitiveOp) -> Value:
|
|
value = self.log(op, "primitive_op", op.desc.name)
|
|
if op.desc.name in primitives_that_inc_ref:
|
|
self.log_inc_ref(value)
|
|
return value
|
|
|
|
def visit_call_c(self, op: CallC) -> Value:
|
|
if global_name := get_load_global_name(op):
|
|
return self.log(op, "globals_dict_get_item", global_name)
|
|
|
|
func_name = op.function_name
|
|
if func_name == "PyObject_Vectorcall" and isinstance(op.args[0], CallC):
|
|
if global_name := get_load_global_name(op.args[0]):
|
|
return self.log(op, "python_call_global", global_name)
|
|
elif func_name == "CPyObject_GetAttr" and isinstance(op.args[1], LoadLiteral):
|
|
return self.log(op, "python_get_attr", str(op.args[1].value))
|
|
elif func_name == "PyObject_VectorcallMethod" and isinstance(op.args[0], LoadLiteral):
|
|
return self.log(op, "python_call_method", str(op.args[0].value))
|
|
|
|
value = self.log(op, "call_c", func_name)
|
|
if func_name in primitives_that_inc_ref:
|
|
self.log_inc_ref(value)
|
|
return value
|
|
|
|
def visit_get_attr(self, op: GetAttr) -> Value:
|
|
value = self.log(op, "get_attr", f"{op.class_type.name}.{op.attr}")
|
|
if not op.is_borrowed and op.type.is_refcounted:
|
|
self.log_inc_ref(op)
|
|
return value
|
|
|
|
def visit_set_attr(self, op: SetAttr) -> Value:
|
|
name = "set_attr" if not op.is_init else "set_attr_init"
|
|
return self.log(op, name, f"{op.class_type.name}.{op.attr}")
|
|
|
|
def visit_box(self, op: Box) -> Value:
|
|
if op.src.type is none_rprimitive:
|
|
# Boxing 'None' is a very quick operation, so we don't log it.
|
|
return self.add(op)
|
|
else:
|
|
return self.log(op, "box", str(op.src.type))
|
|
|
|
def visit_unbox(self, op: Unbox) -> Value:
|
|
return self.log(op, "unbox", str(op.type))
|
|
|
|
def visit_cast(self, op: Cast) -> Value | None:
|
|
value = self.log(op, "cast", str(op.type))
|
|
if not op.is_borrowed:
|
|
self.log_inc_ref(value)
|
|
return value
|
|
|
|
def visit_inc_ref(self, op: IncRef) -> Value:
|
|
return self.log(op, "inc_ref", str(op.src.type))
|
|
|
|
def visit_dec_ref(self, op: DecRef) -> Value:
|
|
return self.log(op, "dec_ref", str(op.src.type))
|
|
|
|
def log_inc_ref(self, value: Value) -> None:
|
|
self.log_event("inc_ref", str(value.type), value.line)
|
|
|
|
def log(self, op: Op, name: str, details: str) -> Value:
|
|
self.log_event(name, details, op.line)
|
|
return self.add(op)
|
|
|
|
def log_event(self, name: str, details: str, line: int) -> None:
|
|
if line >= 0:
|
|
line_str = str(line)
|
|
else:
|
|
line_str = ""
|
|
self.builder.primitive_op(
|
|
log_trace_event,
|
|
[
|
|
CString(self.fullname),
|
|
CString(line_str.encode("ascii")),
|
|
CString(name.encode("utf-8")),
|
|
CString(details.encode("utf-8")),
|
|
],
|
|
line,
|
|
)
|