def profile_with_yappi() -> t.Iterator[None]:
import yappi
yappi.clear_stats()
yappi.start()
yield None
yappi.stop()
def on_event(self, event, payload):
if event == Events.PRINT_STARTED:
if self._profile_print_job():
# Start Profiling
self._logger.info("Profiling started")
yappi.start()
if event == Events.PRINT_DONE or event == Events.PRINT_CANCELLED:
if self._profile_print_job():
# Stop profiling and save statistics to a file for later analysis
now__isoformat = datetime.now().isoformat()
file_name = self._profile_output_folder(
) + 'profiler-func-' + now__isoformat + ".callgrind"
self._logger.info("Saving callgrind data to %s" % file_name)
func_stats = yappi.get_func_stats()
func_stats.save(file_name, 'CALLGRIND')
file_name = self._profile_output_folder(
) + 'profiler-func-' + now__isoformat + ".pstats"
self._logger.info("Saving (functions) pstats data to %s" %
file_name)
func_pstats = yappi.convert2pstats(yappi.get_func_stats())
func_pstats.dump_stats(file_name)
yappi.stop()
yappi.clear_stats()
def stop_profiler(self):
"""
Stop yappi and write the stats to the output directory.
Return the path of the yappi statistics file.
"""
if not self.profiler_running:
raise RuntimeError("Profiler is not running")
if not HAS_YAPPI:
raise RuntimeError(
"Yappi cannot be found. Plase install the yappi library using your preferred package "
"manager and restart Tribler afterwards.")
yappi.stop()
yappi_stats = yappi.get_func_stats()
yappi_stats.sort("tsub")
log_dir = self.session.config.get_state_dir() / 'logs'
file_path = log_dir / (f"yappi_{self.profiler_start_time}.stats")
# Make the log directory if it does not exist
if not log_dir.exists():
os.makedirs(log_dir)
yappi_stats.save(file_path, type='callgrind')
yappi.clear_stats()
self.profiler_running = False
return file_path
def profile_threaded(filename):
import yappi # noqa # yappi is not a dependency
import gil_load # noqa # same
yappi.set_clock_type("cpu")
try:
gil_load.init()
gil_load.start(av_sample_interval=0.1,
output_interval=3,
output=sys.stdout)
monitoring_gil = True
except RuntimeError:
monitoring_gil = False
pass
yappi.start()
yield
yappi.stop()
if monitoring_gil:
gil_load.stop()
print("Gil was held %0.1f %% of the time" % (100 * gil_load.get()[0]))
p = yappi.get_func_stats()
p = yappi.convert2pstats(p)
p.dump_stats(filename)
yappi.clear_stats()
def test_merge_multithreaded_stats(self):
import threading
import _yappi
timings = {"a_1":2, "b_1":1}
_yappi._set_test_timings(timings)
def a(): pass
def b(): pass
yappi.start()
t = threading.Thread(target=a)
t.start()
t.join()
t = threading.Thread(target=b)
t.start()
t.join()
yappi.get_func_stats().save("ystats1.ys")
yappi.clear_stats()
_yappi._set_test_timings(timings)
self.assertEqual(len(yappi.get_func_stats()), 0)
self.assertEqual(len(yappi.get_thread_stats()), 1)
t = threading.Thread(target=a)
t.start()
t.join()
self.assertEqual(_yappi._get_start_flags()["profile_builtins"], 0)
self.assertEqual(_yappi._get_start_flags()["profile_multithread"], 1)
yappi.get_func_stats().save("ystats2.ys")
stats = yappi.YFuncStats(["ystats1.ys", "ystats2.ys",])
fsa = utils.find_stat_by_name(stats, "a")
fsb = utils.find_stat_by_name(stats, "b")
self.assertEqual(fsa.ncall, 2)
self.assertEqual(fsb.ncall, 1)
self.assertEqual(fsa.tsub, fsa.ttot, 4)
self.assertEqual(fsb.tsub, fsb.ttot, 1)
def profile_threaded(filename):
import yappi # noqa # yappi is not a dependency
yappi.set_clock_type("cpu")
try:
import gil_load # noqa # same
gil_load.init()
gil_load.start(av_sample_interval=0.1,
output_interval=10,
output=sys.stdout)
monitoring_gil = True
except (RuntimeError, ImportError):
monitoring_gil = False
pass
yappi.start()
yield
yappi.stop()
if monitoring_gil:
gil_load.stop()
stats = gil_load.get()
print("GIL load information: ", gil_load.format(stats))
p = yappi.get_func_stats()
p = yappi.convert2pstats(p)
p.dump_stats(filename)
yappi.clear_stats()
def test_profile_single_context(self):
def id_callback():
return self.callback_count
def a():
pass
self.callback_count = 1
yappi.set_context_id_callback(id_callback)
yappi.start(profile_threads=False)
a() # context-id:1
self.callback_count = 2
a() # context-id:2
stats = yappi.get_func_stats()
fsa = utils.find_stat_by_name(stats, "a")
self.assertEqual(fsa.ncall, 1)
yappi.stop()
yappi.clear_stats()
self.callback_count = 1
yappi.start() # profile_threads=True
a() # context-id:1
self.callback_count = 2
a() # context-id:2
stats = yappi.get_func_stats()
fsa = utils.find_stat_by_name(stats, "a")
self.assertEqual(fsa.ncall, 2)
def test_profile_single_context(self):
def id_callback():
return self.callback_count
def a():
pass
self.callback_count = 1
yappi.set_context_id_callback(id_callback)
yappi.start(profile_threads=False)
a() # context-id:1
self.callback_count = 2
a() # context-id:2
stats = yappi.get_func_stats()
fsa = utils.find_stat_by_name(stats, "a")
self.assertEqual(fsa.ncall, 1)
yappi.stop()
yappi.clear_stats()
self.callback_count = 1
yappi.start() # profile_threads=True
a() # context-id:1
self.callback_count = 2
a() # context-id:2
stats = yappi.get_func_stats()
fsa = utils.find_stat_by_name(stats, "a")
self.assertEqual(fsa.ncall, 2)
def profile_yappi(label):
import yappi
timestamp = datetime.now()
yappi.start()
_start = time.time()
try:
yield
finally:
_elapsed = time.time() - _start
func_stats = yappi.get_func_stats()
file_prefix = '/tmp/profile-yappi-%s-%s' % (label,
timestamp.isoformat('T'))
with open(file_prefix + '-summary.txt', 'w') as f:
func_stats.print_all(out=f,
columns={
0: ("name", 140),
1: ("ncall", 8),
2: ("tsub", 8),
3: ("ttot", 8),
4: ("tavg", 8)
})
func_stats.save(file_prefix + '.kgrind', 'CALLGRIND')
yappi.stop()
yappi.clear_stats()
profiling_results.append((label, _elapsed))
def wrapped_send(response):
if response['type'] == 'http.response.start':
tracked_stats: Dict[str, YFuncStats] = {
name: yappi.get_func_stats(filter=dict(tag=ctx_tag),
filter_callback=lambda x: yappi.
func_matches(x, tracked_funcs))
for name, tracked_funcs in self.calls_to_track.items()
}
# NOTE (sm15): Might need to be altered to account for various edge-cases
timing_ms = {
name: sum(x.ttot for x in stats) * 1000
for name, stats in tracked_stats.items()
if not stats.empty()
}
server_timing = ','.join([
f"{name};dur={duration_ms:.3f}"
for name, duration_ms in timing_ms.items()
]).encode('ascii')
if server_timing:
# FIXME: Doesn't check if a server-timing header is already set
response['headers'].append(
[b'server-timing', server_timing])
if yappi.get_mem_usage() >= self.max_profiler_mem:
yappi.clear_stats()
return send(response)
def stop_profiler(self):
"""
Stop yappi and write the stats to the output directory.
Return the path of the yappi statistics file.
"""
if not self.profiler_running:
raise RuntimeError("Profiler is not running")
if not HAS_YAPPI:
raise RuntimeError("Yappi cannot be found. Plase install the yappi library using your preferred package "
"manager and restart Tribler afterwards.")
yappi.stop()
yappi_stats = yappi.get_func_stats()
yappi_stats.sort("tsub")
log_dir = os.path.join(self.session.config.get_state_dir(), 'logs')
file_path = os.path.join(log_dir, 'yappi_%s.stats' % self.profiler_start_time)
# Make the log directory if it does not exist
if not os.path.exists(log_dir):
os.makedirs(log_dir)
yappi_stats.save(file_path, type='callgrind')
yappi.clear_stats()
self.profiler_running = False
return file_path
def _stop( self, config, current_time ):
yappi.stop()
global_log.log( scalyr_logging.DEBUG_LEVEL_0, 'Stopping profiling' )
stats = yappi.get_func_stats()
path = os.path.join( config.agent_log_path, config.profile_log_name )
if os.path.exists( path ):
os.remove( path )
stats.save( path, 'callgrind' )
lines = 0
# count the lines
f = open(path)
try:
for line in f:
lines += 1
finally:
f.close()
# write a status message to make it easy to find the end of each profile session
f = open( path, "a" )
try:
f.write( "\n# %s, %s clock, total lines: %d\n" % (path, self._profile_clock, lines) )
finally:
f.close()
yappi.clear_stats()
del stats
def yappi_profile(path: Union[Callable[[], str], str] = None,
wall_clock: bool = True):
try:
import yappi # pylint: disable=import-error
except ImportError:
print("Failed to run profiler, yappi is not installed")
yield
return
yappi.set_clock_type("wall" if wall_clock else "cpu")
yappi.start()
yield
yappi.stop()
# pylint:disable=no-member
if path:
stats = yappi.get_func_stats()
fpath = path() if callable(path) else path
stats.save(fpath, "callgrind")
else:
yappi.get_func_stats().print_all()
yappi.get_thread_stats().print_all()
yappi.clear_stats()
def finish_profile(self):
msg = 'stop profile using interval={0}'.format(self.interval)
log.debug(msg)
fd = StringIO()
out_csv = csv.DictWriter(fd, self.PROF_COLUMNS)
out_csv.writerow(dict([(name, name) for name in self.PROF_COLUMNS]))
stats = yappi.get_func_stats()
for row in stats:
out_csv.writerow(
dict(name=str(row[0]),
n=str(row[1]),
tsub=str(row[2]),
ttot=str(row[3]),
tavg=str(row[4])))
yappi.stop()
yappi.clear_stats()
# save the file
fd.seek(0)
now = datetime.datetime.utcnow()
report_name = 'prof-report-%s.csv' % (now.strftime('%y%m%d.%H%M'))
body = fd.getvalue()
self.write(body)
self.set_header('Content-type', 'text/csv')
self.set_header('Content-disposition',
'attachment;filename=%s' % report_name)
self.finish()
def test_merge_load_different_clock_types(self):
import threading
yappi.start(builtins=True)
def a(): b()
def b(): c()
def c(): pass
t = threading.Thread(target=a)
t.start()
t.join()
yappi.get_func_stats().sort("name", "asc").save("ystats1.ys")
yappi.stop()
yappi.clear_stats()
yappi.start(builtins=False)
t = threading.Thread(target=a)
t.start()
t.join()
yappi.get_func_stats().save("ystats2.ys")
yappi.stop()
self.assertRaises(_yappi.error, yappi.set_clock_type, "wall")
yappi.clear_stats()
yappi.set_clock_type("wall")
yappi.start()
t = threading.Thread(target=a)
t.start()
t.join()
yappi.get_func_stats().save("ystats3.ys")
self.assertRaises(yappi.YappiError, yappi.YFuncStats().add("ystats1.ys").add, "ystats3.ys")
stats = yappi.YFuncStats(["ystats1.ys", "ystats2.ys"]).sort("name")
fsa = utils.find_stat_by_name(stats, "a")
fsb = utils.find_stat_by_name(stats, "b")
fsc = utils.find_stat_by_name(stats, "c")
self.assertEqual(fsa.ncall, 2)
self.assertEqual(fsa.ncall, fsb.ncall, fsc.ncall)
def test_builtin_profiling(self):
import threading
def a():
import time
time.sleep(0.4) # is a builtin function
yappi.set_clock_type('wall')
yappi.start(builtins=True)
a()
stats = yappi.get_func_stats()
fsa = utils.find_stat_by_name(stats, 'sleep')
self.assertTrue(fsa is not None)
self.assertTrue(fsa.ttot > 0.3)
yappi.stop()
yappi.clear_stats()
def a():
pass
yappi.start()
t = threading.Thread(target=a)
t.start()
t.join()
stats = yappi.get_func_stats()
def setUp(self):
# reset everything back to default
yappi.stop()
yappi.clear_stats()
yappi.set_clock_type('cpu') # reset to default clock type
yappi.set_context_id_callback(None)
yappi.set_context_name_callback(None)
def setUp(self):
# reset everything back to default
yappi.stop()
yappi.clear_stats()
yappi.set_clock_type('cpu') # reset to default clock type
yappi.set_context_id_callback(None)
yappi.set_context_name_callback(None)
def wrapped(*args, **kwargs):
import yappi
yappi.start()
try:
return f(*args, **kwargs)
finally:
result = list(yappi.get_func_stats())
yappi.stop()
yappi.clear_stats()
result = [
l for l in result
if all([s not in l.full_name for s in skipped_lines])
]
entries = result[:lines]
prefix = LOCALSTACK_ROOT_FOLDER
result = []
result.append('ncall\tttot\ttsub\ttavg\tname')
def c(num):
return str(num)[:7]
for e in entries:
name = e.full_name.replace(prefix, '')
result.append(
'%s\t%s\t%s\t%s\t%s' %
(c(e.ncall), c(e.ttot), c(e.tsub), c(e.tavg), name))
result = '\n'.join(result)
print(result)
def _stop_profiling(filename, format):
logging.debug("Stopping CPU profiling")
with _lock:
if yappi.is_running():
yappi.stop()
stats = yappi.get_func_stats()
stats.save(filename, format)
yappi.clear_stats()
def _stop_profiling(filename, format):
logging.debug("Stopping profiling")
with _lock:
if yappi.is_running():
yappi.stop()
stats = yappi.get_func_stats()
stats.save(filename, format)
yappi.clear_stats()
def stop(self):
if not yappi.is_running():
raise UsageError("CPU profiler is not running")
logging.info("Stopping CPU profiling")
yappi.stop()
stats = yappi.get_func_stats()
stats.save(self.filename, self.format)
yappi.clear_stats()
def stop(self):
if not yappi.is_running():
raise UsageError("CPU profiler is not running")
logging.info("Stopping CPU profiling")
yappi.stop()
stats = yappi.get_func_stats()
stats.save(self.filename, self.format)
yappi.clear_stats()
def _start( self, config, current_time ):
yappi.clear_stats()
clock = self._get_clock_type( config.profile_clock, self._allowed_clocks, self._profile_clock )
if clock != self._profile_clock:
self._profile_clock = clock
yappi.set_clock_type( self._profile_clock )
global_log.log( scalyr_logging.DEBUG_LEVEL_0, "Starting profiling using '%s' clock. Duration: %d seconds" % (self._profile_clock, self._profile_end - self._profile_start) )
yappi.start()
def _stop_profiling(self):
with lock:
if not yappi.is_running():
raise HTTPBadRequest("profile is not running")
log.info("Stopping profiling, writing profile to %r",
self.config.profile.filename)
yappi.stop()
stats = yappi.get_func_stats()
stats.save(self.config.profile.filename, type="pstat")
yappi.clear_stats()
def stopProfiling(self):
if self._is_profiling:
yappi.stop()
self._is_profiling = False
func_stats = yappi.get_func_stats()
func_stats.save("curaProfile.out", "CALLGRIND")
yappi.clear_stats()
self._profiling_started_message.hide()
self._profiling_stopped_message.show()
def test_clear_stats_while_running(self):
def a():
pass
yappi.start()
a()
yappi.clear_stats()
a()
stats = yappi.get_func_stats()
fsa = utils.find_stat_by_name(stats, 'a')
self.assertEqual(fsa.ncall, 1)
def test_basic_old_style(self):
def a():
burn_io_gevent(0.1)
burn_io(0.1)
burn_io_gevent(0.1)
burn_io(0.1)
burn_io_gevent(0.1)
burn_cpu(0.3)
yappi.set_clock_type("wall")
yappi.start(builtins=True)
g1 = self.spawn_greenlet("a_1", a)
g1.get()
g2 = self.spawn_greenlet("a_2", a)
g2.get()
yappi.stop()
r1 = '''
..p/yappi/tests/test_asyncio.py:43 a 2 0.000118 1.604049 0.802024
burn_io_gevent 6 0.000000 0.603239 0.100540
../yappi/tests/utils.py:126 burn_cpu 2 0.000000 0.600026 0.300013
..p/yappi/tests/utils.py:135 burn_io 4 0.000025 0.400666 0.100166
'''
stats = yappi.get_func_stats()
self.assert_traces_almost_equal(r1, stats)
gstats = yappi.get_greenlet_stats()
r2 = '''
Main 1 1.623057 3
Main/a_1 3 0.812399 1
Main/a_2 4 0.810234 1
'''
self.assert_ctx_stats_almost_equal(r2, gstats)
yappi.clear_stats()
yappi.set_clock_type("cpu")
yappi.start(builtins=True)
g1 = self.spawn_greenlet("a_1", a)
g1.get()
g2 = self.spawn_greenlet("a_2", a)
g2.get()
yappi.stop()
stats = yappi.get_func_stats()
r1 = '''
..p/yappi/tests/test_asyncio.py:43 a 2 0.000117 0.601170 0.300585
../yappi/tests/utils.py:126 burn_cpu 2 0.000000 0.600047 0.300024
burn_io_gevent 6 0.000159 0.000801 0.000134
'''
self.assert_traces_almost_equal(r1, stats)
gstats = yappi.get_greenlet_stats()
r2 = '''
Main/a_2 6 0.301190 1
Main/a_1 5 0.300960 1
Main 1 0.000447 3
'''
self.assert_ctx_stats_almost_equal(r2, gstats)
def do_action(self):
action = self.cleaned_data['action']
if action == 'start':
yappi.start()
elif action == 'start_with_builtins':
yappi.start(builtins=True)
elif action == 'stop':
yappi.stop()
elif action == 'reset':
yappi.clear_stats()
return action
def do_action(self):
action = self.cleaned_data['action']
if action == 'start':
yappi.start()
elif action == 'start_with_builtins':
yappi.start(builtins=True)
elif action == 'stop':
yappi.stop()
elif action == 'reset':
yappi.clear_stats()
return action
def _stop_profiling(self):
with lock:
if not yappi.is_running():
raise http.Error(http.BAD_REQUEST, "profile is not running")
log.info("Stopping profiling, writing profile to %r",
self.config.profile.filename)
yappi.stop()
stats = yappi.get_func_stats()
stats.save(self.config.profile.filename, type="pstat")
yappi.clear_stats()
def _stop_profiling(self):
with lock:
if not yappi.is_running():
raise http.Error(http.BAD_REQUEST, "profile is not running")
log.info("Stopping profiling, writing profile to %r",
self.config.profile.filename)
yappi.stop()
stats = yappi.get_func_stats()
stats.save(self.config.profile.filename, type="pstat")
yappi.clear_stats()
def test_subsequent_profile(self):
import threading
WORKER_COUNT = 5
def a(): pass
def b(): pass
def c(): pass
_timings = {"a_1":3,"b_1":2,"c_1":1,}
yappi.start()
def g(): pass
g()
yappi.stop()
yappi.clear_stats()
_yappi._set_test_timings(_timings)
yappi.start()
_dummy = []
for i in range(WORKER_COUNT):
t = threading.Thread(target=a)
t.start()
t.join()
for i in range(WORKER_COUNT):
t = threading.Thread(target=b)
t.start()
_dummy.append(t)
t.join()
for i in range(WORKER_COUNT):
t = threading.Thread(target=a)
t.start()
t.join()
for i in range(WORKER_COUNT):
t = threading.Thread(target=c)
t.start()
t.join()
yappi.stop()
yappi.start()
def f():
pass
f()
stats = yappi.get_func_stats()
fsa = utils.find_stat_by_name(stats, 'a')
fsb = utils.find_stat_by_name(stats, 'b')
fsc = utils.find_stat_by_name(stats, 'c')
self.assertEqual(fsa.ncall, 10)
self.assertEqual(fsb.ncall, 5)
self.assertEqual(fsc.ncall, 5)
self.assertEqual(fsa.ttot, fsa.tsub, 30)
self.assertEqual(fsb.ttot, fsb.tsub, 10)
self.assertEqual(fsc.ttot, fsc.tsub, 5)
# MACOSx optimizes by only creating one worker thread
self.assertTrue(len(yappi.get_thread_stats()) >= 2)
def process(fn):
"""Iteratively process an file object.
Arguments:
fn - file name
"""
if args.profile:
if args.verbose:
print("\x1b[6;30;43m[i]\x1b[0m profiling is on...")
yappi.clear_stats()
yappi.set_clock_type('cpu')
yappi.start(builtins=True)
db = initdb(fn)
with open(os.path.join(args.input, fn), 'r') as fileobj:
parser = ijson.common.items(ijson.parse(fileobj, multiple_values=True),
'')
if args.trace == 'camflow':
if args.verbose:
print(
"\x1b[6;30;42m[+]\x1b[0m parsing file {} in CAMFLOW mode..."
.format(fn))
ptj.parsecf(parser, db, fn)
elif args.trace == 'darpa':
if args.verbose:
print(
"\x1b[6;30;42m[+]\x1b[0m parsing file {} in DARPA mode...".
format(fn))
ptj.parsedp(parser, db, fn)
elif args.trace == 'cadets2' or args.trace == 'fivedirections':
if args.verbose:
print(
"\x1b[6;30;42m[+]\x1b[0m parsing file {} in CADETS2/FIVEDIRECTIONS mode..."
.format(fn))
ptj.parsecd(parser, db, fn)
else:
raise NotImplementedError(
"cannot run traces from an unknown system")
if args.profile:
yappi.stop()
if args.verbose:
print("\x1b[6;30;43m[i]\x1b[0m profiling is done...")
stat = yappi.get_func_stats()
stat.save(fn + '.prof', type='callgrind')
fileobj.close()
return
def test_no_stats_different_clock_type_load(self):
def a(): pass
yappi.start()
a()
yappi.stop()
yappi.get_func_stats().save("ystats1.ys")
yappi.clear_stats()
yappi.set_clock_type("WALL")
yappi.start()
yappi.stop()
stats = yappi.get_func_stats().add("ystats1.ys")
fsa = utils.find_stat_by_name(stats, 'a')
self.assertTrue(fsa is not None)
def performance(func, isPlot):
yappi.clear_stats()
yappi.set_clock_type('cpu')
yappi.start(builtins=True)
func()
yappi.stop()
stats = yappi.convert2pstats(yappi.get_func_stats())
stats.sort_stats("cumulative")
stats.print_stats()
if isPlot:
yappi.get_func_stats().save('callgrind.foo.prof', type='callgrind')
os.system("cat callgrind.foo.prof | python gprof2dot.py -f callgrind | dot -Tpng -o output.png")
os.system("rm -f callgrind.foo.prof")
def profile_cpu_bound_program():
real_dog = DogStatsApi()
real_dog.reporter = NullReporter()
fake_dog = NullDogStatsApi()
for type_, dog in [('real', real_dog), ('fake', fake_dog)]:
print('\n\n\nTESTING %s\n\n' % type_)
dog.start()
program = CPUBoundProgram(dog)
yappi.start()
program.run()
yappi.print_stats(sort_type=yappi.SORTTYPE_TSUB, sort_order=yappi.SORTORDER_DESC)
yappi.stop()
yappi.clear_stats()
def profile_threaded(filename):
import yappi # noqa # yappi is not a dependency
if filename is None:
yield
return
yappi.start()
yield
yappi.stop()
p = yappi.get_func_stats()
p = yappi.convert2pstats(p)
p.dump_stats(filename)
yappi.clear_stats()
def test_run(self):
def profiled():
pass
yappi.clear_stats()
try:
with yappi.run():
profiled()
stats = yappi.get_func_stats()
finally:
yappi.clear_stats()
self.assertIsNotNone(utils.find_stat_by_name(stats, 'profiled'))
def profile_yappi(label):
import yappi
timestamp = datetime.now()
yappi.start()
_start = time.time()
try:
yield
finally:
_elapsed = time.time() - _start
func_stats = yappi.get_func_stats()
file_prefix = '/tmp/profile-yappi-%s-%s' % (label, timestamp.isoformat('T'))
with open(file_prefix + '-summary.txt', 'w') as f:
func_stats.print_all(out=f, columns={0:("name",140), 1:("ncall", 8), 2:("tsub", 8), 3:("ttot", 8), 4:("tavg",8)})
func_stats.save(file_prefix + '.kgrind', 'CALLGRIND')
yappi.stop()
yappi.clear_stats()
profiling_results.append((label, _elapsed))
def _handle_sigusr2(sig, stack):
'''
Signal handler for SIGUSR2, only available on Unix-like systems
'''
try:
import yappi
except ImportError:
return
if yappi.is_running():
yappi.stop()
filename = 'callgrind.salt-{0}-{1}'.format(int(time.time()), os.getpid())
destfile = os.path.join(tempfile.gettempdir(), filename)
yappi.get_func_stats().save(destfile, type='CALLGRIND')
if sys.stderr.isatty():
sys.stderr.write('Saved profiling data to: {0}\n'.format(destfile))
yappi.clear_stats()
else:
if sys.stderr.isatty():
sys.stderr.write('Profiling started\n')
yappi.start()
def test_builtin_profiling(self):
def a():
time.sleep(0.4) # is a builtin function
yappi.set_clock_type('wall')
yappi.start(builtins=True)
a()
stats = yappi.get_func_stats()
fsa = utils.find_stat_by_name(stats, 'sleep')
self.assertTrue(fsa is not None)
self.assertTrue(fsa.ttot > 0.3)
yappi.stop()
yappi.clear_stats()
def a():
pass
yappi.start()
t = threading.Thread(target=a)
t.start()
t.join()
stats = yappi.get_func_stats()
def test_run_recursive(self):
def profiled():
pass
def not_profiled():
pass
yappi.clear_stats()
try:
with yappi.run():
with yappi.run():
profiled()
# Profiling stopped here
not_profiled()
stats = yappi.get_func_stats()
finally:
yappi.clear_stats()
self.assertIsNotNone(utils.find_stat_by_name(stats, 'profiled'))
self.assertIsNone(utils.find_stat_by_name(stats, 'not_profiled'))
def test_module_stress(self):
self.assertEqual(yappi.is_running(), False)
yappi.start()
yappi.clear_stats()
self.assertRaises(_yappi.error, yappi.set_clock_type, "wall")
yappi.stop()
yappi.clear_stats()
yappi.set_clock_type("cpu")
self.assertRaises(yappi.YappiError, yappi.set_clock_type, "dummy")
self.assertEqual(yappi.is_running(), False)
yappi.clear_stats()
yappi.clear_stats()
def test_pstats_conversion(self):
def pstat_id(fs):
return (fs.module, fs.lineno, fs.name)
def a():
d()
def b():
d()
def c():
pass
def d():
pass
_timings = {"a_1":12,"b_1":7,"c_1":5,"d_1":2}
_yappi._set_test_timings(_timings)
stats = utils.run_and_get_func_stats(a,)
stats.strip_dirs()
stats.save("a1.pstats", type="pstat")
fsa_pid = pstat_id(utils.find_stat_by_name(stats, "a"))
fsd_pid = pstat_id(utils.find_stat_by_name(stats, "d"))
yappi.clear_stats()
_yappi._set_test_timings(_timings)
stats = utils.run_and_get_func_stats(a,)
stats.strip_dirs()
stats.save("a2.pstats", type="pstat")
yappi.clear_stats()
_yappi._set_test_timings(_timings)
stats = utils.run_and_get_func_stats(b,)
stats.strip_dirs()
stats.save("b1.pstats", type="pstat")
fsb_pid = pstat_id(utils.find_stat_by_name(stats, "b"))
yappi.clear_stats()
_yappi._set_test_timings(_timings)
stats = utils.run_and_get_func_stats(c,)
stats.strip_dirs()
stats.save("c1.pstats", type="pstat")
fsc_pid = pstat_id(utils.find_stat_by_name(stats, "c"))
# merge saved stats and check pstats values are correct
import pstats
p = pstats.Stats('a1.pstats', 'a2.pstats', 'b1.pstats', 'c1.pstats')
p.strip_dirs()
# ct = ttot, tt = tsub
(cc, nc, tt, ct, callers) = p.stats[fsa_pid]
self.assertEqual(cc, nc, 2)
self.assertEqual(tt, 20)
self.assertEqual(ct, 24)
(cc, nc, tt, ct, callers) = p.stats[fsd_pid]
self.assertEqual(cc, nc, 3)
self.assertEqual(tt, 6)
self.assertEqual(ct, 6)
self.assertEqual(len(callers), 2)
(cc, nc, tt, ct) = callers[fsa_pid]
self.assertEqual(cc, nc, 2)
self.assertEqual(tt, 4)
self.assertEqual(ct, 4)
(cc, nc, tt, ct) = callers[fsb_pid]
self.assertEqual(cc, nc, 1)
self.assertEqual(tt, 2)
self.assertEqual(ct, 2)
def _capture_profile(fname=''):
if not fname:
yappi.set_clock_type('cpu')
# We need to set context to greenlet to profile greenlets
# https://bitbucket.org/sumerc/yappi/pull-requests/3
yappi.set_context_id_callback(
lambda: id(greenlet.getcurrent()))
yappi.set_context_name_callback(
lambda: greenlet.getcurrent().__class__.__name__)
yappi.start()
else:
yappi.stop()
stats = yappi.get_func_stats()
# User should provide filename. This file with a suffix .prof
# will be created in temp directory.
try:
stats_file = os.path.join(tempfile.gettempdir(), fname + '.prof')
stats.save(stats_file, "pstat")
except Exception as e:
print("Error while saving the trace stats ", str(e))
finally:
yappi.clear_stats()
def finish_profile(self):
msg = 'stop profile using interval={0}'.format(self.interval)
log.debug(msg)
fd = StringIO()
out_csv = csv.DictWriter(fd, self.PROF_COLUMNS)
out_csv.writerow(dict([(name, name) for name in self.PROF_COLUMNS]))
stats = yappi.get_func_stats()
for row in stats:
out_csv.writerow(dict(name=str(row[0]), n=str(row[1]),
tsub=str(row[2]), ttot=str(row[3]),
tavg=str(row[4])))
yappi.stop()
yappi.clear_stats()
# save the file
fd.seek(0)
now = datetime.datetime.utcnow()
report_name = 'prof-report-%s.csv' % (now.strftime('%y%m%d.%H%M'))
body = fd.getvalue()
self.write(body)
self.set_header('Content-type', 'text/csv')
self.set_header('Content-disposition',
'attachment;filename=%s' % report_name)
self.finish()
def clear_stats(self):
yappi.clear_stats()
def setUp(self):
if yappi.is_running():
yappi.stop()
yappi.clear_stats()
yappi.set_clock_type('cpu') # reset to default clock type
def __exit__(self,*args): import yappi yappi.stop() yappi.print_stats() yappi.clear_stats()
def clear():
pages.require("/admin/settings.edit", noautoreturn=True)
pages.postOnly()
import yappi
yappi.clear_stats()
raise cherrypy.HTTPRedirect("/settings/profiler/")
def test_ctx_stats(self):
from threading import Thread
DUMMY_WORKER_COUNT = 5
yappi.start()
class DummyThread(Thread): pass
def dummy_worker():
pass
for i in range(DUMMY_WORKER_COUNT):
t = DummyThread(target=dummy_worker)
t.start()
t.join()
yappi.stop()
stats = yappi.get_thread_stats()
tsa = utils.find_stat_by_name(stats, "DummyThread")
self.assertTrue(tsa is not None)
yappi.clear_stats()
import time
time.sleep(1.0)
_timings = {"a_1":6,"b_1":5,"c_1":3, "d_1":1, "a_2":4,"b_2":3,"c_2":2, "d_2":1}
_yappi._set_test_timings(_timings)
class Thread1(Thread): pass
class Thread2(Thread): pass
def a():
b()
def b():
c()
def c():
d()
def d():
time.sleep(0.6)
yappi.set_clock_type("wall")
yappi.start()
t1 = Thread1(target=a)
t1.start()
t2 = Thread2(target=a)
t2.start()
t1.join()
t2.join()
stats = yappi.get_thread_stats()
# the fist clear_stats clears the context table?
tsa = utils.find_stat_by_name(stats, "DummyThread")
self.assertTrue(tsa is None)
tst1 = utils.find_stat_by_name(stats, "Thread1")
tst2 = utils.find_stat_by_name(stats, "Thread2")
tsmain = utils.find_stat_by_name(stats, "_MainThread")
#stats.print_all()
self.assertTrue(len(stats) == 3)
self.assertTrue(tst1 is not None)
self.assertTrue(tst2 is not None)
self.assertTrue(tsmain is not None) # I see this fails sometimes, probably
# because Py_ImportNoBlock() fails to import and get the thread class name
# sometimes.
self.assertTrue(1.0 > tst2.ttot >= 0.5)
self.assertTrue(1.0 > tst1.ttot >= 0.5)
# test sorting of the ctx stats
stats = stats.sort("totaltime", "desc")
prev_stat = None
for stat in stats:
if prev_stat:
self.assertTrue(prev_stat.ttot >= stat.ttot)
prev_stat = stat
stats = stats.sort("totaltime", "asc")
prev_stat = None
for stat in stats:
if prev_stat:
self.assertTrue(prev_stat.ttot <= stat.ttot)
prev_stat = stat
stats = stats.sort("schedcount", "desc")
prev_stat = None
for stat in stats:
if prev_stat:
self.assertTrue(prev_stat.sched_count >= stat.sched_count)
prev_stat = stat
stats = stats.sort("name", "desc")
prev_stat = None
for stat in stats:
if prev_stat:
self.assertTrue(prev_stat.name >= stat.name)
prev_stat = stat
self.assertRaises(yappi.YappiError, stats.sort, "invalid_thread_sorttype_arg")
self.assertRaises(yappi.YappiError, stats.sort, "invalid_thread_sortorder_arg")
# in ipython or similar import yappi import os from totalimpact import backend rootdir = "." logfile = '/tmp/total-impact.log' yappi.clear_stats() yappi.start() backend.main(logfile) ### Now, in another window run # ./services/api start # ./services/proxy start # ./extras/functional_test.py -i 6 -n 6 # then when it is done, in python do a Cntl C to stop the backend and return to python prompt yappi.stop() yappi.print_stats(sort_type=yappi.SORTTYPE_TTOT, limit=30, thread_stats_on=False)
def test_merge_aabab_aabbc(self):
_timings = {"a_1":15,"a_2":14,"b_1":12,"a_3":10,"b_2":9, "c_1":4}
_yappi._set_test_timings(_timings)
def a():
if self._ncall == 1:
self._ncall += 1
a()
elif self._ncall == 5:
self._ncall += 1
a()
else:
b()
def b():
if self._ncall == 2:
self._ncall += 1
a()
elif self._ncall == 6:
self._ncall += 1
b()
elif self._ncall == 7:
c()
else:
return
def c():
pass
self._ncall = 1
stats = utils.run_and_get_func_stats(a,)
stats.save("ystats1.ys")
yappi.clear_stats()
_yappi._set_test_timings(_timings)
#stats.print_all()
self._ncall = 5
stats = utils.run_and_get_func_stats(a,)
stats.save("ystats2.ys")
#stats.print_all()
def a(): # same name but another function(code object)
pass
yappi.start()
a()
stats = yappi.get_func_stats().add(["ystats1.ys", "ystats2.ys"])
#stats.print_all()
self.assertEqual(len(stats), 4)
fsa = None
for stat in stats:
if stat.name == "a" and stat.ttot == 45:
fsa = stat
break
self.assertTrue(fsa is not None)
self.assertEqual(fsa.ncall, 7)
self.assertEqual(fsa.nactualcall, 3)
self.assertEqual(fsa.ttot, 45)
self.assertEqual(fsa.tsub, 10)
fsb = utils.find_stat_by_name(stats, "b")
fsc = utils.find_stat_by_name(stats, "c")
self.assertEqual(fsb.ncall, 6)
self.assertEqual(fsb.nactualcall, 3)
self.assertEqual(fsb.ttot, 36)
self.assertEqual(fsb.tsub, 27)
self.assertEqual(fsb.tavg, 6)
self.assertEqual(fsc.ttot, 8)
self.assertEqual(fsc.tsub, 8)
self.assertEqual(fsc.tavg, 4)
self.assertEqual(fsc.nactualcall, fsc.ncall, 2)
def test_merge_stats(self):
_timings = {"a_1":15,"b_1":14,"c_1":12,"d_1":10,"e_1":9,"f_1":7,"g_1":6,"h_1":5,"i_1":1}
_yappi._set_test_timings(_timings)
def a():
b()
def b():
c()
def c():
d()
def d():
e()
def e():
f()
def f():
g()
def g():
h()
def h():
i()
def i():
pass
yappi.start()
a()
a()
yappi.stop()
stats = yappi.get_func_stats()
self.assertRaises(NotImplementedError, stats.save, "", "INVALID_SAVE_TYPE")
stats.save("ystats2.ys")
yappi.clear_stats()
_yappi._set_test_timings(_timings)
yappi.start()
a()
stats = yappi.get_func_stats().add("ystats2.ys")
fsa = utils.find_stat_by_name(stats, "a")
fsb = utils.find_stat_by_name(stats, "b")
fsc = utils.find_stat_by_name(stats, "c")
fsd = utils.find_stat_by_name(stats, "d")
fse = utils.find_stat_by_name(stats, "e")
fsf = utils.find_stat_by_name(stats, "f")
fsg = utils.find_stat_by_name(stats, "g")
fsh = utils.find_stat_by_name(stats, "h")
fsi = utils.find_stat_by_name(stats, "i")
self.assertEqual(fsa.ttot, 45)
self.assertEqual(fsa.ncall, 3)
self.assertEqual(fsa.nactualcall, 3)
self.assertEqual(fsa.tsub, 3)
self.assertEqual(fsa.children[fsb].ttot, fsb.ttot)
self.assertEqual(fsa.children[fsb].tsub, fsb.tsub)
self.assertEqual(fsb.children[fsc].ttot, fsc.ttot)
self.assertEqual(fsb.children[fsc].tsub, fsc.tsub)
self.assertEqual(fsc.tsub, 6)
self.assertEqual(fsc.children[fsd].ttot, fsd.ttot)
self.assertEqual(fsc.children[fsd].tsub, fsd.tsub)
self.assertEqual(fsd.children[fse].ttot, fse.ttot)
self.assertEqual(fsd.children[fse].tsub, fse.tsub)
self.assertEqual(fse.children[fsf].ttot, fsf.ttot)
self.assertEqual(fse.children[fsf].tsub, fsf.tsub)
self.assertEqual(fsf.children[fsg].ttot, fsg.ttot)
self.assertEqual(fsf.children[fsg].tsub, fsg.tsub)
self.assertEqual(fsg.ttot, 18)
self.assertEqual(fsg.tsub, 3)
self.assertEqual(fsg.children[fsh].ttot, fsh.ttot)
self.assertEqual(fsg.children[fsh].tsub, fsh.tsub)
self.assertEqual(fsh.ttot, 15)
self.assertEqual(fsh.tsub, 12)
self.assertEqual(fsh.tavg, 5)
self.assertEqual(fsh.children[fsi].ttot, fsi.ttot)
self.assertEqual(fsh.children[fsi].tsub, fsi.tsub)
