analyse_runtime.py 9.62 KiB
#!/usr/bin/env python
################################################################################
# This file is part of SWIFT.
# Copyright (c) 2018 Matthieu Schaller (matthieu.schaller@durham.ac.uk)
#
# This program is free software: you can redistribute it and/or modify
# it under the terms of the GNU Lesser General Public License as published
# by the Free Software Foundation, either version 3 of the License, or
# (at your option) any later version.
#
# This program is distributed in the hope that it will be useful,
# but WITHOUT ANY WARRANTY; without even the implied warranty of
# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
# GNU General Public License for more details.
#
# You should have received a copy of the GNU Lesser General Public License
# along with this program. If not, see <http://www.gnu.org/licenses/>.
#
################################################################################
import re
import sys
import matplotlib
matplotlib.use("Agg")
from pylab import *
# Plot parameters
params = {
"axes.labelsize": 10,
"axes.titlesize": 10,
"font.size": 12,
"legend.fontsize": 12,
"xtick.labelsize": 10,
"ytick.labelsize": 10,
"text.usetex": True,
"figure.figsize": (12.45, 6.45),
"figure.subplot.left": 0.06,
"figure.subplot.right": 0.99,
"figure.subplot.bottom": 0.06,
"figure.subplot.top": 0.99,
"figure.subplot.wspace": 0.0,
"figure.subplot.hspace": 0.0,
"lines.markersize": 6,
"lines.linewidth": 3.0,
"text.latex.unicode": True,
"hatch.linewidth": 4,
}
rcParams.update(params)
threshold = 0.008
num_files = len(sys.argv) - 1
labels = [
["engine_split_gas_particles:", 1],
["Gpart assignment", 1],
["Mesh communication", 1],
["Forward Fourier transform", 1],
["Green function", 1],
["Backwards Fourier transform", 1],
["engine_recompute_displacement_constraint:", 1],
["engine_exchange_top_multipoles:", 1],
["updating particle counts", 1],
["engine_estimate_nr_tasks:", 1],
["Making gravity tasks", 1],
["Making hydro tasks", 1],
["Splitting tasks", 1],
["Counting and linking tasks", 1],
["Setting super-pointers", 1],
["Making extra hydroloop tasks", 1],
["Linking gravity tasks", 1],
["Creating send tasks", 1],
["Exchanging cell tags", 1],
["Creating recv tasks", 1],
["Counting number of foreign particles", 1],
["Recursively linking foreign arrays", 1],
["Setting unlocks", 1],
["Ranking the tasks", 1],
["scheduler_reweight:", 1],
["space_list_useful_top_level_cells:", 1],
["space_rebuild:", 1],
["scheduler_report_task_times:", 1],
["engine_drift_all:", 0],
["engine_unskip:", 0],
["engine_unskip_timestep_communications:", 0],
["engine_collect_end_of_step:", 0],
["engine_launch: \(tasks\)", 0],
["engine_launch: \(timesteps\)", 0],
["writing particle properties", 0],
["engine_repartition:", 0],
["engine_exchange_cells:", 1],
["Dumping restart files", 0],
["engine_print_stats:", 0],
["engine_marktasks:", 1],
["Reading initial conditions", 0],
["engine_print_task_counts:", 0],
["engine_drift_top_multipoles:", 0],
["Communicating rebuild flag", 0],
["Writing step info to files", 0],
["Updating general quantities", 0],
["task_dump_all:", 0],
["task_dump_stats:", 0],
["task_dump_active:", 0],
["restart_read:", 0],
["engine_split:", 0],
["space_init", 0],
["engine_init", 0],
["engine_repartition_trigger:", 0],
["VR Collecting top-level cell info", 3],
["VR Collecting particle info", 3],
["VR Invocation of velociraptor", 3],
["VR Copying group information back", 3],
["fof_allocate:", 2],
["engine_make_fof_tasks:", 2],
["engine_activate_fof_tasks:", 2],
["fof_search_tree:", 2],
["engine_launch: \(fof\)", 2],
["engine_launch: \(fof comms\)", 2],
["do_line_of_sight:", 0],
]
times = np.zeros(len(labels))
counts = np.zeros(len(labels))
cols = [
"0.5",
"#332288",
"#88CCEE",
"#44AA99",
"#117733",
"#999933",
"#DDCC77",
"#CC6677",
"#882255",
"#AA4499",
"#661100",
"#6699CC",
"#AA4466",
"#4477AA",
]
tasks = [
"dead time",
"drift",
"sort",
"hydro",
"gravity",
"feedback",
"black holes",
"cooling",
"star formation",
"limiter",
"time integration",
"mpi",
"fof",
"others",
"total",
]
times_tasks = np.zeros(len(tasks))
counts_tasks = np.zeros(len(tasks))
total_time = 0
lastline = ""
for i in range(num_files):
# First analyse the code sections
filename = sys.argv[i + 1]
print("Analysing %s" % filename)
# Open stdout file
file = open(filename, "r")
# Search the different phrases
for line in file:
# Loop over the possbile labels
for i in range(len(labels)):
# Extract the different blocks
if re.search("%s took" % labels[i][0], line):
counts[i] += 1.0
times[i] += float(
re.findall(r"[+-]?((\d+\.?\d*)|(\.\d+))", line)[-1][0]
)
# Find the last line with meaningful output (avoid crash report, batch system stuff....)
if re.findall(r"\[[0-9]{4}\][ ]\[*", line) or re.findall(
r"^\[[0-9]*[.][0-9]+\][ ]", line
):
lastline = line
# Total run time
total_time += float(
re.findall(r"[+-]?(\[[0-9]\])?(\[[0-9]*[.][0-9]*\])+", lastline)[0][1][1:-1]
)
file.close()
# Now analyse the task times
file = open(filename, "r")
# Search the different phrases
for line in file:
# Loop over the possbile labels
for i in range(len(tasks)):
# Extract the different blocks
if re.search("scheduler_report_task_times: \*\*\* ", line):
if re.search("%s" % tasks[i], line):
counts_tasks[i] += 1.0
times_tasks[i] += float(
re.findall(r":[ ]*[-+]?\d*\.\d+|\d+ ms", line)[0][1:]
)
file.close()
# Conver to seconds
times /= 1000.0
times_tasks /= 1000.0
# Total time
total_measured_time = np.sum(times)
print("\nTotal measured time: %.3f s" % total_measured_time)
print("Total time: %f s\n" % total_time)
# Ratios
time_ratios = times / total_time
# Better looking labels
for i in range(len(labels)):
labels[i][0] = labels[i][0].replace("_", " ")
labels[i][0] = labels[i][0].replace(":", "")
labels[i][0] = labels[i][0].title()
times = np.array(times)
time_ratios = np.array(time_ratios)
times_tasks = np.array(times_tasks)
times_tasks_ratios = times_tasks / times_tasks[-1]
times_tasks_ratios = np.array(times_tasks_ratios)
# Sort in order of importance
order = np.argsort(-times)
times = times[order]
counts = counts[order]
time_ratios = time_ratios[order]
labels = [labels[i] for i in order]
# Remove the regexp escapes to make the labels prettier
for i in range(len(labels)):
labels[i][0] = labels[i][0].replace("\\", "")
# Keep only the important components
important_times = [0.0]
important_ratios = [0.0]
important_is_rebuild = [0]
important_is_fof = [0]
important_is_VR = [0]
important_labels = ["Others (all below %.1f\%%)" % (threshold * 100)]
need_print = True
print("Time spent in the different code sections:")
for i in range(len(labels)):
if time_ratios[i] > threshold:
important_times.append(times[i])
important_ratios.append(time_ratios[i])
important_is_rebuild.append(labels[i][1] == 1)
important_is_fof.append(labels[i][1] == 2)
important_is_VR.append(labels[i][1] == 3)
important_labels.append(labels[i][0])
else:
if need_print:
print("Elements in 'Other' category (<%.1f%%):" % (threshold * 100))
need_print = False
important_times[0] += times[i]
important_ratios[0] += time_ratios[i]
print(
" - '%-40s' (%5d calls, time: %.4fs): %.4f%%"
% (labels[i][0], counts[i], times[i], time_ratios[i] * 100)
)
# Anything unaccounted for?
print(
"\nUnaccounted for: %.4f%%\n"
% (100 * (total_time - total_measured_time) / total_time)
)
important_ratios = np.array(important_ratios)
important_is_rebuild = np.array(important_is_rebuild)
print("Time spent in the different task categories (i.e. inside engine_launch()):")
for i in range(len(tasks) - 1):
print(
" - '%-40s' (%5d calls): %.4f%%"
% (tasks[i], counts_tasks[i], 100.0 * times_tasks_ratios[i])
)
print("")
figure()
# Main code sections
subplot(121)
def func(pct):
return "$%4.2f\\%%$" % pct
code_pie, _, _ = pie(
important_ratios,
explode=important_is_rebuild * 0.2,
autopct=lambda pct: func(pct),
textprops=dict(color="0.1", fontsize=14),
labeldistance=0.7,
pctdistance=0.85,
startangle=-15,
colors=cols,
)
# Use hashing for the FOF and VR wedges
for i in range(len(code_pie)):
if important_is_fof[i]:
code_pie[i].set_hatch("o")
code_pie[i].set_edgecolor(code_pie[i].get_facecolor())
code_pie[i].set_fill(False)
for i in range(len(code_pie)):
if important_is_VR[i]:
code_pie[i].set_hatch("+")
code_pie[i].set_edgecolor(code_pie[i].get_facecolor())
code_pie[i].set_fill(False)
legend(code_pie, important_labels, title="SWIFT operations", loc="upper left")
# Tasks
subplot(122)
tasks_pie, _, _ = pie(
times_tasks_ratios[:-1],
autopct=lambda pct: func(pct),
textprops=dict(color="0.1", fontsize=14),
labeldistance=0.7,
pctdistance=0.85,
startangle=-15,
colors=cols,
)
legend(tasks_pie, tasks, title="SWIFT task categories", loc="upper left")
savefig("time_pie.pdf", dpi=150)