Skip to content
New issue

Have a question about this project? # for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “#”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? # to your account

Updates to properly handle @profile decorators for CPU time attribution #637

Merged
merged 7 commits into from
Jul 14, 2023
Merged
Show file tree
Hide file tree
Changes from 5 commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
3 changes: 3 additions & 0 deletions .github/workflows/test-smoketests.yml
Original file line number Diff line number Diff line change
Expand Up @@ -47,3 +47,6 @@ jobs:
# Note: test/smoketest.py only handles single JSON, rather than multiple in sequence.
- name: profile-interval smoke test
run: python -m scalene --cli --profile-interval=2 test/testme.py

- name: decorator smoke test
run: python test/smoketest_profile_decorator.py
27 changes: 24 additions & 3 deletions scalene/scalene_json.py
Original file line number Diff line number Diff line change
Expand Up @@ -107,7 +107,27 @@ def output_profile_line(
"""Print at most one line of the profile (true == printed one)."""

if not force_print and not profile_this_code(fname, line_no):
return {}
return {
"lineno": line_no,
"line": line,
"n_core_utilization" : 0,
"n_cpu_percent_c": 0,
"n_cpu_percent_python": 0,
"n_sys_percent": 0,
"n_gpu_percent": 0,
"n_gpu_avg_memory_mb": 0,
"n_gpu_peak_memory_mb": 0,
"n_peak_mb": 0,
"n_growth_mb": 0,
"n_avg_mb": 0,
"n_mallocs": 0,
"n_malloc_mb": 0,
"n_usage_fraction": 0,
"n_python_fraction": 0,
"n_copy_mb_s": 0,
"memory_samples": [],
}

# Prepare output values.
n_cpu_samples_c = stats.cpu_samples_c[fname][line_no]
# Correct for negative CPU sample counts. This can happen
Expand Down Expand Up @@ -219,7 +239,7 @@ def output_profiles(
python_alias_dir: Path,
program_path: Path,
profile_memory: bool = True,
reduced_profile: bool = False,
reduced_profile: bool = False
) -> Dict[str, Any]:
"""Write the profile out."""
# Get the children's stats, if any.
Expand Down Expand Up @@ -302,7 +322,8 @@ def output_profiles(
fname = Filename(fname)
try:
percent_cpu_time = (
100 * stats.cpu_samples[fname] / stats.total_cpu_samples
100 * stats.cpu_samples[fname] / stats.elapsed_time
# 100 * stats.cpu_samples[fname] / stats.total_cpu_samples
)
except ZeroDivisionError:
percent_cpu_time = 0
Expand Down
31 changes: 23 additions & 8 deletions scalene/scalene_profiler.py
Original file line number Diff line number Diff line change
Expand Up @@ -480,6 +480,14 @@ def profile(func: Any) -> Any:
Scalene.__files_to_profile.add(func.__code__.co_filename)
Scalene.__functions_to_profile[func.__code__.co_filename].add(func)

if Scalene.__args.memory:
from scalene import pywhere # type: ignore
pywhere.register_files_to_profile(
list(Scalene.__files_to_profile),
Scalene.__program_path,
Scalene.__args.profile_all,
)

return func

@staticmethod
Expand Down Expand Up @@ -584,8 +592,7 @@ def malloc_signal_handler(
found_frame = False
f = this_frame
while f:
if Scalene.should_trace(f.f_code.co_filename):
found_frame = True
if found_frame := Scalene.should_trace(f.f_code.co_filename, f.f_code.co_name):
break
f = cast(FrameType, f.f_back)
if not found_frame:
Expand Down Expand Up @@ -934,7 +941,7 @@ def output_profile() -> bool:
Scalene.__program_being_profiled,
Scalene.__stats,
Scalene.__pid,
lambda x,y: True if Scalene.__args.web else Scalene.profile_this_code,
Scalene.profile_this_code,
Scalene.__python_alias_dir,
Scalene.__program_path,
profile_memory=Scalene.__args.memory,
Expand Down Expand Up @@ -972,7 +979,7 @@ def output_profile() -> bool:
column_width,
Scalene.__stats,
Scalene.__pid,
lambda x,y: True if Scalene.__args.web else Scalene.profile_this_code,
Scalene.profile_this_code,
Scalene.__python_alias_dir,
Scalene.__program_path,
profile_memory=Scalene.__args.memory,
Expand Down Expand Up @@ -1005,7 +1012,7 @@ def add_stack(frame: FrameType) -> None:
stk = HashableList()
f = frame
while f:
if Scalene.should_trace(f.f_code.co_filename):
if Scalene.should_trace(f.f_code.co_filename, f.f_code.co_name):
stk.insert(0, (f.f_code.co_filename, f.f_lineno))
f = f.f_back
Scalene.__stats.stacks[stk] += 1
Expand Down Expand Up @@ -1227,14 +1234,16 @@ def compute_frames_to_record() -> List[Tuple[FrameType, int, FrameType]]:
if not frame:
continue
fname = frame.f_code.co_filename
func = frame.f_code.co_name
# Record samples only for files we care about.
if not fname:
# 'eval/compile' gives no f_code.co_filename. We have
# to look back into the outer frame in order to check
# the co_filename.
back = cast(FrameType, frame.f_back)
fname = Filename(back.f_code.co_filename)
while not Scalene.should_trace(fname):
func = back.f_code.co_name
while not Scalene.should_trace(fname, func):
# Walk the stack backwards until we hit a frame that
# IS one we should trace (if there is one). i.e., if
# it's in the code being profiled, and it is just
Expand All @@ -1245,6 +1254,7 @@ def compute_frames_to_record() -> List[Tuple[FrameType, int, FrameType]]:
break
if frame:
fname = frame.f_code.co_filename
func = frame.f_code.co_name
if frame:
new_frames.append((frame, tident, orig_frame))
del frames[:]
Expand All @@ -1267,7 +1277,7 @@ def enter_function_meta(
return
except Exception:
return
if not Scalene.should_trace(f.f_code.co_filename):
if not Scalene.should_trace(f.f_code.co_filename, f.f_code.co_name):
return

fn_name = Filename(f.f_code.co_name)
Expand Down Expand Up @@ -1595,13 +1605,18 @@ def memcpy_sigqueue_processor(

@staticmethod
@functools.lru_cache(None)
def should_trace(filename: str) -> bool:
def should_trace(filename: str, func : str) -> bool:
"""Return true if the filename is one we should trace."""
if not filename:
return False
if os.path.join("scalene", "scalene") in filename:
# Don't profile the profiler.
return False
if Scalene.__functions_to_profile:
if filename in Scalene.__functions_to_profile:
if func in { fn.__code__.co_name for fn in Scalene.__functions_to_profile[filename] }:
return True
return False
# Don't profile the Python libraries, unless overridden by --profile-all
if not Scalene.__args.profile_all:
try:
Expand Down
65 changes: 65 additions & 0 deletions test/profile_annotation_test.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,65 @@
#!/usr/bin/env python3
import numpy as np

Check notice

Code scanning / CodeQL

Unused import

Import of 'np' is not used.

#import math

# from numpy import linalg as LA

arr = [i for i in range(1,1000)]

@profile
def doit1(x):
# x = [i*i for i in range(1,1000)][0]
y = 1
# w, v = LA.eig(np.diag(arr)) # (1, 2, 3, 4, 5, 6, 7, 8, 9, 10)))
x = [i*i for i in range(0,100000)][99999]
y1 = [i*i for i in range(0,200000)][199999]

Check notice

Code scanning / CodeQL

Unused local variable

Variable y1 is not used.
z1 = [i for i in range(0,300000)][299999]

Check notice

Code scanning / CodeQL

Unused local variable

Variable z1 is not used.
z = x * y
# z = np.multiply(x, y)
return z

def doit2(x):
i = 0
# zarr = [math.cos(13) for i in range(1,100000)]
# z = zarr[0]
z = 0.1
while i < 100000:
# z = math.cos(13)
# z = np.multiply(x,x)
# z = np.multiply(z,z)
# z = np.multiply(z,z)
z = z * z

Check warning

Code scanning / CodeQL

Variable defined multiple times

This assignment to 'z' is unnecessary as it is [redefined](1) before this value is used.
z = x * x
z = z * z
z = z * z
i += 1
return z

@profile
def doit3(x):
z = x + 1
z = x + 1
z = x + 1
z = x + z
z = x + z
# z = np.cos(x)
return z

def stuff():
# y = np.random.randint(1, 100, size=50000000)[49999999]
x = 1.01
for i in range(1,3):
print(i)
for j in range(1,3):
x = doit1(x)
x = doit2(x)
x = doit3(x)

Check warning

Code scanning / CodeQL

Variable defined multiple times

This assignment to 'x' is unnecessary as it is [redefined](1) before this value is used.
x = 1.01
return x

import sys

Check notice

Code scanning / CodeQL

Unused import

Import of 'sys' is not used.
print("TESTME")
print(sys.argv)
stuff()

48 changes: 48 additions & 0 deletions test/smoketest_profile_decorator.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,48 @@
#!/usr/bin/env python3
import subprocess
import sys
import json

def smoketest(fname):
proc = subprocess.run( [sys.executable, "-m", "scalene", "--cli", "--json", "--outfile", "/dev/stderr", fname] ,capture_output=True)
if proc.returncode != 0:
print("Exited with a non-zero code:", proc.returncode)
print("Stdout:", proc.stdout.decode('utf-8'))
print("Stderr:", proc.stderr.decode('utf-8'))

exit(proc.returncode)
# stdout = proc.stdout.decode('utf-8')
stderr = proc.stderr.decode('utf-8')
# print("STDOUT", stdout)
# print("\nSTDERR", stderr)
try:
scalene_json = json.loads(stderr)
except json.JSONDecodeError:
print("Invalid JSON", stderr)
exit(1)
if len(scalene_json) == 0:
print("No JSON output")
exit(1)
files = scalene_json['files']
if not len(files) > 0:
print("No files found in output")
exit(1)
_fname = list(files.keys())[0]
function_list = files[_fname]['functions']
exit_code = 0

# if 'doit1' not in function_dict:
if not any('doit1' in f['line'] for f in function_list):
print("Expected function 'doit1' not returned")
exit_code = 1

if not any('doit2' in f['line'] for f in function_list):
print("Expected function 'doit2' not returned")
exit_code = 1
if exit_code != 0:
# print(files)
print(function_list)
exit(exit_code)

if __name__ == '__main__':
smoketest('test/profile_annotation_test.py')