Skip to content

Commit 4d3569d

Browse files
ClericPyClericPy
committed
3. add line_profiler decorator to morebuiltins.funcs, to profile function execution time line by line.
1 parent 49bc3d9 commit 4d3569d

File tree

2 files changed

+187
-0
lines changed

2 files changed

+187
-0
lines changed

‎CHANGELOG.md‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
### 1.3.1 (2025-06-19)
22
1. add `check_recursion` to `morebuiltins.funcs`, to check if a function is recursive.
33
2. add `SharedBytes` to `morebuiltins.shared_memory`, a shared memory for bytes, similar to `multiprocessing.shared_memory.SharedMemory` with a header for size.
4+
3. add `line_profiler` decorator to `morebuiltins.funcs`, to profile function execution time line by line.
45

56
### 1.3.0 (2025-03-08)
67
1. **Compatibility Warning**. rename `morebuiltins.functools` to `morebuiltins.funcs` to avoid conflict with `functools` in python standard library.

‎morebuiltins/funcs.py‎

Lines changed: 186 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -7,6 +7,7 @@
77
import logging
88
import os
99
import re
10+
import sys
1011
import time
1112
from collections import deque
1213
from concurrent.futures import ThreadPoolExecutor
@@ -24,9 +25,11 @@
2425
Callable,
2526
Coroutine,
2627
Dict,
28+
List,
2729
Optional,
2830
OrderedDict,
2931
Set,
32+
Tuple,
3033
Union,
3134
)
3235
from weakref import WeakSet
@@ -1243,6 +1246,189 @@ def check_recursion(function: Callable, return_error=False):
12431246
return None
12441247

12451248

1249+
class LineProfiler:
1250+
"""Line-by-line performance profiler."""
1251+
1252+
stdout = sys.stdout
1253+
1254+
def __init__(self):
1255+
self.line_times: List[Tuple[int, float, str]] = []
1256+
self.start_time = 0.0
1257+
self.total_time = 0.0
1258+
self.line_cache: Dict[str, list] = {}
1259+
1260+
def trace_calls(self, frame, event, arg):
1261+
"""Trace each line of function calls"""
1262+
if event == "line":
1263+
current_time = time.perf_counter()
1264+
line_no = frame.f_lineno
1265+
filename = frame.f_code.co_filename
1266+
# Get the code content of current line
1267+
try:
1268+
if filename in self.line_cache:
1269+
lines = self.line_cache[filename]
1270+
else:
1271+
with open(filename, "r", encoding="utf-8", errors="replace") as f:
1272+
lines = f.readlines()
1273+
self.line_cache[filename] = lines
1274+
if lines and line_no <= len(lines):
1275+
line_content = lines[
1276+
line_no - 1
1277+
].rstrip() # Only remove right spaces, keep left indentation
1278+
# Store original code and filename for later base indentation calculation
1279+
if not hasattr(self, "source_lines"):
1280+
self.source_lines = lines
1281+
self.target_filename = filename
1282+
else:
1283+
line_content = "-"
1284+
except Exception:
1285+
line_content = "-"
1286+
self.line_cache.setdefault(filename, [])
1287+
self.line_times.append((line_no, current_time, line_content))
1288+
return self.trace_calls
1289+
1290+
def _get_function_base_indent(self, func_name: str):
1291+
"""Get the base indentation level of function definition"""
1292+
if not hasattr(self, "source_lines"):
1293+
return 0
1294+
# Find function definition line
1295+
for line in self.source_lines:
1296+
if f"def {func_name}(" in line:
1297+
# Calculate indentation level of function definition
1298+
return len(line) - len(line.lstrip())
1299+
return 0
1300+
1301+
def calculate_and_print_stats(self, func_name: str):
1302+
"""Calculate and print statistics for each line"""
1303+
if len(self.line_times) < 2:
1304+
return
1305+
# Calculate base indentation level of function
1306+
base_indent = self._get_function_base_indent(func_name)
1307+
print(f"`{func_name}` profiling report:", file=self.stdout)
1308+
start_time = time.strftime("%Y-%m-%d %H:%M:%S")
1309+
print(
1310+
f"{start_time} | Total: {self.total_time * 1000:.3f} ms",
1311+
file=self.stdout,
1312+
)
1313+
# Calculate execution time for each line
1314+
line_durations = []
1315+
for i in range(1, len(self.line_times)):
1316+
prev_time = self.line_times[i - 1][1]
1317+
curr_time = self.line_times[i][1]
1318+
duration = curr_time - prev_time
1319+
line_durations.append(
1320+
(
1321+
self.line_times[i - 1][0], # line number
1322+
duration, # duration
1323+
self.line_times[i - 1][2], # code content
1324+
)
1325+
)
1326+
# Sort by line number and merge time for same lines
1327+
line_stats: Dict[int, Dict[str, Any]] = {}
1328+
for line_no, duration, code in line_durations:
1329+
if line_no not in line_stats:
1330+
line_stats[line_no] = {
1331+
"total_time": 0,
1332+
"count": 0,
1333+
"code": code,
1334+
"timestamps": [],
1335+
}
1336+
line_stats[line_no]["total_time"] += duration
1337+
line_stats[line_no]["count"] += 1
1338+
# Print detailed information for each line
1339+
print(f"{'=' * 95}", file=self.stdout)
1340+
print(
1341+
f"{'Line':>6} {'%':>4} {'Total(ms)':>12} {'Count':>8} {'Avg(ms)':>12} {'Source Code':<40}",
1342+
file=self.stdout,
1343+
)
1344+
print(f"{'-' * 95}", file=self.stdout)
1345+
sorted_lines = sorted(line_stats.items())
1346+
for line_no, stats in sorted_lines:
1347+
total_time_ms = stats["total_time"] * 1000 # convert to milliseconds
1348+
count = stats["count"]
1349+
avg_time_ms = total_time_ms / count if count > 0 else 0
1350+
percentage = int(
1351+
(stats["total_time"] / self.total_time * 100)
1352+
if self.total_time > 0
1353+
else 0
1354+
) # convert to integer
1355+
# Handle code indentation display
1356+
code = stats["code"]
1357+
# Get current line indentation
1358+
current_indent = len(code) - len(code.lstrip())
1359+
# First level indentation under def (usually 4 spaces)
1360+
first_level_indent = base_indent + 4
1361+
# Only keep spaces relative to first level indentation
1362+
relative_indent = max(0, current_indent - first_level_indent)
1363+
indent_spaces = " " * relative_indent
1364+
code_with_relative_indent = indent_spaces + code.lstrip()
1365+
code_preview = (
1366+
code_with_relative_indent[:38] + ".."
1367+
if len(code_with_relative_indent) > 40
1368+
else code_with_relative_indent
1369+
)
1370+
print(
1371+
f"{line_no:>6} {percentage:>4} {total_time_ms:>12.3f} {count:>8} {avg_time_ms:>12.3f} {code_preview:<40}",
1372+
file=self.stdout,
1373+
)
1374+
print(f"{'=' * 95}", file=self.stdout, flush=True)
1375+
1376+
1377+
def line_profiler(func: Callable) -> Callable:
1378+
"""Decorator to profile a function line-by-line.
1379+
1380+
Demo usage:
1381+
>>> import sys, io
1382+
>>> LineProfiler.stdout = io.StringIO() # Redirect stdout to capture print output
1383+
>>> @line_profiler
1384+
... def example_function():
1385+
... result = 0
1386+
... for i in range(10):
1387+
... result += i # Simulate some work
1388+
... return result
1389+
>>> example_function()
1390+
45
1391+
>>> output = LineProfiler.stdout.getvalue()
1392+
>>> output.splitlines()[0].startswith("`example_function` profiling report:")
1393+
True
1394+
>>> LineProfiler.stdout = sys.stdout # Restore original stdout
1395+
1396+
# `example_function` profiling report:
1397+
# 2025-07-26 17:09:58 | Total: 1.122 ms
1398+
# ===============================================================================================
1399+
# Line % Total(ms) Count Avg(ms) Source Code
1400+
# -----------------------------------------------------------------------------------------------
1401+
# 3 73 0.825 1 0.825 -
1402+
# 4 3 0.040 11 0.004 -
1403+
# 5 4 0.050 10 0.005 -
1404+
# ===============================================================================================
1405+
"""
1406+
1407+
@wraps(func)
1408+
def wrapper(*args, **kwargs):
1409+
profiler = LineProfiler()
1410+
# Record start time
1411+
start_time = time.perf_counter()
1412+
profiler.start_time = start_time
1413+
# Set tracer
1414+
old_trace = sys.gettrace()
1415+
sys.settrace(profiler.trace_calls)
1416+
try:
1417+
# Execute function
1418+
result = func(*args, **kwargs)
1419+
finally:
1420+
# Restore original tracer
1421+
sys.settrace(old_trace)
1422+
# Record end time
1423+
end_time = time.perf_counter()
1424+
profiler.total_time = end_time - start_time
1425+
# Calculate and print statistics
1426+
profiler.calculate_and_print_stats(func.__name__)
1427+
return result
1428+
1429+
return wrapper
1430+
1431+
12461432
def test_bg_task():
12471433
async def _test_bg_task():
12481434
async def coro():

0 commit comments

Comments
 (0)