reivilibre/per4m-synapse
1
0
Fork 0
Code Issues Pull Requests Projects Releases Wiki Activity

feat: perf 4 support

Browse Source
This commit is contained in:
Maarten A. Breddels 2020-12-15 13:08:33 +00:00
parent e13a3ada21
commit e08c18dd36
1 changed files with 35 additions and 14 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

49
per4m/perf2trace.py
View File

@ -118,10 +118,17 @@ def main(argv=sys.argv):
gil_event = None gil_event = None
if event == "sched:sched_switch": if event == "sched:sched_switch":
# e.g. python 393320 [040] 3498299.441431: sched:sched_switch: prev_comm=python prev_pid=393320 prev_prio=120 prev_state=S ==> next_comm=swapper/40 next_pid=0 next_prio=120 # e.g. python 393320 [040] 3498299.441431: sched:sched_switch: prev_comm=python prev_pid=393320 prev_prio=120 prev_state=S ==> next_comm=swapper/40 next_pid=0 next_prio=120
values = parse_values(parts, prev_pid=int) try:
values = parse_values(parts, prev_pid=int)
pid = values['prev_pid']
prev_state = values['prev_state']
except ValueError:
# perf 4
comm, pid = other[0].rsplit(':', 1)
pid = int(pid)
prev_state = other[2]
# we are going to sleep? # we are going to sleep?
pid = values['prev_pid'] if prev_state == 'R':
if values['prev_state'] == 'R':
# this happens when a process just started, so we just set the start time # this happens when a process just started, so we just set the start time
last_sleep_time[pid] = time last_sleep_time[pid] = time
continue continue
@ -134,7 +141,7 @@ def main(argv=sys.argv):
continue continue
dur = time - last_run_time[pid] dur = time - last_run_time[pid]
if verbose >= 2: if verbose >= 2:
log(f'{name} will switch to state={values["prev_state"]}, ran for {dur}') log(f'{name} will switch to state={prev_state}, ran for {dur}')
if store_runing: if store_runing:
event = {"pid": parent_pid.get(pid, pid), "tid": pid, "ts": last_run_time[pid], "dur": dur, "name": 'R', "ph": "X", "cat": "process state"} event = {"pid": parent_pid.get(pid, pid), "tid": pid, "ts": last_run_time[pid], "dur": dur, "name": 'R', "ph": "X", "cat": "process state"}
trace_events.append(event) trace_events.append(event)
@ -145,9 +152,15 @@ def main(argv=sys.argv):
elif event == "sched:sched_wakeup": elif event == "sched:sched_wakeup":
# e.g: swapper 0 [040] 3498299.642199: sched:sched_waking: comm=python pid=393320 prio=120 target_cpu=040 # e.g: swapper 0 [040] 3498299.642199: sched:sched_waking: comm=python pid=393320 prio=120 target_cpu=040
prev_state = None prev_state = None
values = parse_values(parts, pid=int) try:
pid = values['pid'] values = parse_values(parts, pid=int)
comm = values['comm'] pid = values['pid']
comm = values['comm']
except ValueError:
# perf 4
comm, pid = other[0].rsplit(':', 1)
pid = int(pid)
# if comm != "python": # if comm != "python":
# if verbose >= 2: # if verbose >= 2:
# log(f'Skip waking event for {comm}') # log(f'Skip waking event for {comm}')
@ -158,18 +171,21 @@ def main(argv=sys.argv):
# q # q
last_run_time[pid] = time last_run_time[pid] = time
continue continue
recover_from_gil = takes_gil(last_sleep_stacktrace[pid])
duration = time - last_sleep_time[pid]
if verbose >= 2: if verbose >= 2:
name = pid_names.get(pid, pid) name = pid_names.get(pid, pid)
log(f'Waking up {name}') log(f'Waking up {name}', '(recovering from GIL)' if recover_from_gil else '', f', slept for {duration} msec')
if verbose >= 3:
print("Stack trace when we went to sleep:\n\t", "\t".join(last_sleep_stacktrace[pid]))
if store_sleeping: if store_sleeping:
dur = time - last_sleep_time[pid] if recover_from_gil:
if takes_gil(last_sleep_stacktrace[pid]):
name = 'S(GIL)' name = 'S(GIL)'
cname = 'terrible' cname = 'terrible'
else: else:
name = 'S' name = 'S'
cname = 'bad' cname = 'bad'
event = {"pid": parent_pid.get(pid, pid), "tid": pid, "ts": last_sleep_time[pid], "dur": dur, "name": name, "ph": "X", "cat": "process state", 'cname': cname} event = {"pid": parent_pid.get(pid, pid), "tid": pid, "ts": last_sleep_time[pid], "dur": duration, "name": name, "ph": "X", "cat": "process state", 'cname': cname}
trace_events.append(event) trace_events.append(event)
last_run_time[pid] = time last_run_time[pid] = time
del last_sleep_time[pid] del last_sleep_time[pid]
@ -179,8 +195,13 @@ def main(argv=sys.argv):
log(f'Starting (exec) {name}') log(f'Starting (exec) {name}')
elif event == "sched:sched_wakeup_new": elif event == "sched:sched_wakeup_new":
# e.g: swapper 0 [040] 3498299.642199: sched:sched_waking: comm=python pid=393320 prio=120 target_cpu=040 # e.g: swapper 0 [040] 3498299.642199: sched:sched_waking: comm=python pid=393320 prio=120 target_cpu=040
values = parse_values(parts, pid=int) try:
pid = values['pid'] values = parse_values(parts, pid=int)
pid = values['pid']
except ValueError:
# perf 4
comm, pid = other[0].rsplit(':', 1)
pid = int(pid)
if verbose >= 2: if verbose >= 2:
name = pid_names.get(pid, pid) name = pid_names.get(pid, pid)
log(f'Starting (new) {name}') log(f'Starting (new) {name}')
@ -202,7 +223,7 @@ def main(argv=sys.argv):
except BrokenPipeError: except BrokenPipeError:
break break
except: except:
print("error on line", header) print("error on line", header, other)
raise raise
with open(args.output, 'w') as f: with open(args.output, 'w') as f: