starpu_trace_state_stats.py 12 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369
  1. #!/usr/bin/python2.7
  2. ##
  3. # StarPU --- Runtime system for heterogeneous multicore architectures.
  4. #
  5. # Copyright (C) 2016 INRIA
  6. #
  7. # StarPU is free software; you can redistribute it and/or modify
  8. # it under the terms of the GNU Lesser General Public License as published by
  9. # the Free Software Foundation; either version 2.1 of the License, or (at
  10. # your option) any later version.
  11. #
  12. # StarPU is distributed in the hope that it will be useful, but
  13. # WITHOUT ANY WARRANTY; without even the implied warranty of
  14. # MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.
  15. #
  16. # See the GNU Lesser General Public License in COPYING.LGPL for more details.
  17. ##
  18. ##
  19. # This script parses the generated trace.rec file and reports statistics about
  20. # the number of different events/tasks and their durations. The report is
  21. # similar to the starpu_paje_state_stats.in script, except that this one
  22. # doesn't need R and pj_dump (from the pajeng repository), and it is also much
  23. # faster.
  24. ##
  25. import getopt
  26. import os
  27. import sys
  28. class Event():
  29. def __init__(self, type, name, category, start_time):
  30. self._type = type
  31. self._name = name
  32. self._category = category
  33. self._start_time = start_time
  34. class EventStats():
  35. def __init__(self, name, duration_time, category, count = 1):
  36. self._name = name
  37. self._duration_time = duration_time
  38. self._category = category
  39. self._count = count
  40. def aggregate(self, duration_time):
  41. self._duration_time += duration_time
  42. self._count += 1
  43. def show(self):
  44. if not self._name == None and not self._category == None:
  45. print "\"" + self._name + "\"," + str(self._count) + ",\"" + self._category + "\"," + str(round(self._duration_time, 6))
  46. class Worker():
  47. def __init__(self, id):
  48. self._id = id
  49. self._events = []
  50. self._stats = []
  51. self._stack = []
  52. def get_event_stats(self, name):
  53. for stat in self._stats:
  54. if stat._name == name:
  55. return stat
  56. return None
  57. def add_event(self, type, name, category, start_time):
  58. self._events.append(Event(type, name, category, start_time))
  59. def add_event_to_stats(self, event, duration):
  60. for i in xrange(len(self._stats)):
  61. if self._stats[i]._name == event._name:
  62. self._stats[i].aggregate(duration)
  63. return
  64. self._stats.append(EventStats(event._name, duration, event._category))
  65. def calc_stats(self, start_profiling_times, stop_profiling_times):
  66. num_events = len(self._events) - 1
  67. for i in xrange(0, num_events):
  68. curr_event = self._events[i]
  69. next_event = self._events[i+1]
  70. is_allowed = not len(start_profiling_times)
  71. # Check if the event is inbetween start/stop profiling events
  72. for t in xrange(len(start_profiling_times)):
  73. if (curr_event._start_time > start_profiling_times[t] and
  74. curr_event._start_time < stop_profiling_times[t]):
  75. is_allowed = True
  76. break
  77. if not is_allowed:
  78. continue
  79. if curr_event._type == "PushState":
  80. self._stack.append(curr_event)
  81. continue # Will look later to find a PopState event.
  82. elif curr_event._type == "PopState":
  83. if len(self._stack) == 0:
  84. sys.exit("ERROR: The trace is most likely corrupted "
  85. "because a PopState event has been found without "
  86. "a PushState!")
  87. next_event = curr_event
  88. curr_event = self._stack.pop()
  89. else:
  90. if curr_event._type != "SetState":
  91. sys.exit("ERROR: Invalid event type!")
  92. # Compute duration with the next event.
  93. a = curr_event._start_time
  94. b = next_event._start_time
  95. # Add the event to the list of stats.
  96. self.add_event_to_stats(curr_event, b - a)
  97. def read_blocks(input_file):
  98. empty_lines = 0
  99. first_line = 1
  100. blocks = []
  101. for line in open(input_file):
  102. if first_line:
  103. blocks.append([])
  104. blocks[-1].append(line)
  105. first_line = 0
  106. # Check for empty lines
  107. if not line or line[0] == '\n':
  108. # If 1st one: new block
  109. if empty_lines == 0:
  110. blocks.append([])
  111. empty_lines += 1
  112. else:
  113. # Non empty line: add line in current(last) block
  114. empty_lines = 0
  115. blocks[-1].append(line)
  116. return blocks
  117. def read_field(field, index):
  118. return field[index+1:-1]
  119. def insert_worker_event(workers, prog_events, block):
  120. worker_id = -1
  121. name = None
  122. start_time = 0.0
  123. category = None
  124. for line in block:
  125. key = line[:2]
  126. value = read_field(line, 2)
  127. if key == "E:": # EventType
  128. event_type = value
  129. elif key == "C:": # Category
  130. category = value
  131. elif key == "W:": # WorkerId
  132. worker_id = int(value)
  133. elif key == "N:": # Name
  134. name = value
  135. elif key == "S:": # StartTime
  136. start_time = float(value)
  137. # Program events don't belong to workers, they are globals.
  138. if category == "Program":
  139. prog_events.append(Event(event_type, name, category, start_time))
  140. return
  141. for worker in workers:
  142. if worker._id == worker_id:
  143. worker.add_event(event_type, name, category, start_time)
  144. return
  145. worker = Worker(worker_id)
  146. worker.add_event(event_type, name, category, start_time)
  147. workers.append(worker)
  148. def calc_times(stats):
  149. tr = 0.0 # Runtime
  150. tt = 0.0 # Task
  151. ti = 0.0 # Idle
  152. ts = 0.0 # Scheduling
  153. for stat in stats:
  154. if stat._category == None:
  155. continue
  156. if stat._category == "Runtime":
  157. if stat._name == "Scheduling":
  158. # Scheduling time is part of runtime but we want to have
  159. # it separately.
  160. ts += stat._duration_time
  161. else:
  162. tr += stat._duration_time
  163. elif stat._category == "Task":
  164. tt += stat._duration_time
  165. elif stat._category == "Other":
  166. ti += stat._duration_time
  167. else:
  168. print "WARNING: Unknown category '" + stat._category + "'!"
  169. return (ti, tr, tt, ts)
  170. def save_times(ti, tr, tt, ts):
  171. f = open("times.csv", "w+")
  172. f.write("\"Time\",\"Duration\"\n")
  173. f.write("\"Runtime\"," + str(tr) + "\n")
  174. f.write("\"Task\"," + str(tt) + "\n")
  175. f.write("\"Idle\"," + str(ti) + "\n")
  176. f.write("\"Scheduling\"," + str(ts) + "\n")
  177. f.close()
  178. def calc_et(tt_1, tt_p):
  179. """ Compute the task efficiency (et). This measures the exploitation of
  180. data locality. """
  181. return tt_1 / tt_p
  182. def calc_es(tt_p, ts_p):
  183. """ Compute the scheduling efficiency (es). This measures time spent in
  184. the runtime scheduler. """
  185. return tt_p / (tt_p + ts_p)
  186. def calc_er(tt_p, tr_p, ts_p):
  187. """ Compute the runtime efficiency (er). This measures how the runtime
  188. overhead affects performance."""
  189. return (tt_p + ts_p) / (tt_p + tr_p + ts_p)
  190. def calc_ep(tt_p, tr_p, ti_p, ts_p):
  191. """ Compute the pipeline efficiency (et). This measures how much
  192. concurrency is available and how well it's exploited. """
  193. return (tt_p + tr_p + ts_p) / (tt_p + tr_p + ti_p + ts_p)
  194. def calc_e(et, er, ep, es):
  195. """ Compute the parallel efficiency. """
  196. return et * er * ep * es
  197. def save_efficiencies(e, ep, er, et, es):
  198. f = open("efficiencies.csv", "w+")
  199. f.write("\"Efficiency\",\"Value\"\n")
  200. f.write("\"Parallel\"," + str(e) + "\n")
  201. f.write("\"Task\"," + str(et) + "\n")
  202. f.write("\"Runtime\"," + str(er) + "\n")
  203. f.write("\"Scheduling\"," + str(es) + "\n")
  204. f.write("\"Pipeline\"," + str(ep) + "\n")
  205. f.close()
  206. def usage():
  207. print "USAGE:"
  208. print "starpu_trace_state_stats.py [ -te -s=<time> ] <trace.rec>"
  209. print
  210. print "OPTIONS:"
  211. print " -t or --time Compute and dump times to times.csv"
  212. print
  213. print " -e or --efficiency Compute and dump efficiencies to efficiencies.csv"
  214. print
  215. print " -s or --seq_task_time Used to compute task efficiency between sequential and parallel times"
  216. print " (if not set, task efficiency will be 1.0)"
  217. print
  218. print "EXAMPLES:"
  219. print "# Compute event statistics and report them to stdout:"
  220. print "python starpu_trace_state_stats.py trace.rec"
  221. print
  222. print "# Compute event stats, times and efficiencies:"
  223. print "python starpu_trace_state_stats.py -te trace.rec"
  224. print
  225. print "# Compute correct task efficiency with the sequential task time:"
  226. print "python starpu_trace_state_stats.py -s=60093.950614 trace.rec"
  227. def main():
  228. try:
  229. opts, args = getopt.getopt(sys.argv[1:], "hets:",
  230. ["help", "time", "efficiency", "seq_task_time="])
  231. except getopt.GetoptError as err:
  232. usage()
  233. sys.exit(1)
  234. dump_time = False
  235. dump_efficiency = False
  236. tt_1 = 0.0
  237. for o, a in opts:
  238. if o in ("-h", "--help"):
  239. usage()
  240. sys.exit()
  241. elif o in ("-t", "--time"):
  242. dump_time = True
  243. elif o in ("-e", "--efficiency"):
  244. dump_efficiency = True
  245. elif o in ("-s", "--seq_task_time"):
  246. tt_1 = float(a)
  247. if len(args) < 1:
  248. usage()
  249. sys.exit()
  250. recfile = args[0]
  251. if not os.path.isfile(recfile):
  252. sys.exit("File does not exist!")
  253. # Declare a list for all workers.
  254. workers = []
  255. # Declare a list for program events
  256. prog_events = []
  257. # Read the recutils file format per blocks.
  258. blocks = read_blocks(recfile)
  259. for block in blocks:
  260. if not len(block) == 0:
  261. first_line = block[0]
  262. if first_line[:2] == "E:":
  263. insert_worker_event(workers, prog_events, block)
  264. # Find allowed range times between start/stop profiling events.
  265. start_profiling_times = []
  266. stop_profiling_times = []
  267. for prog_event in prog_events:
  268. if prog_event._name == "start_profiling":
  269. start_profiling_times.append(prog_event._start_time)
  270. if prog_event._name == "stop_profiling":
  271. stop_profiling_times.append(prog_event._start_time)
  272. if len(start_profiling_times) != len(stop_profiling_times):
  273. sys.exit("Mismatch number of start/stop profiling events!")
  274. # Compute worker statistics.
  275. stats = []
  276. for worker in workers:
  277. worker.calc_stats(start_profiling_times, stop_profiling_times)
  278. for stat in worker._stats:
  279. found = False
  280. for s in stats:
  281. if stat._name == s._name:
  282. found = True
  283. break
  284. if not found == True:
  285. stats.append(EventStats(stat._name, 0.0, stat._category, 0))
  286. # Compute global statistics for all workers.
  287. for i in xrange(0, len(workers)):
  288. for stat in stats:
  289. s = workers[i].get_event_stats(stat._name)
  290. if not s == None:
  291. # A task might not be executed on all workers.
  292. stat._duration_time += s._duration_time
  293. stat._count += s._count
  294. # Output statistics.
  295. print "\"Name\",\"Count\",\"Type\",\"Duration\""
  296. for stat in stats:
  297. stat.show()
  298. # Compute runtime, task, idle, scheduling times and dump them to times.csv
  299. ti_p = tr_p = tt_p = ts_p = 0.0
  300. if dump_time == True:
  301. ti_p, tr_p, tt_p, ts_p = calc_times(stats)
  302. save_times(ti_p, tr_p, tt_p, ts_p)
  303. # Compute runtime, task, idle efficiencies and dump them to
  304. # efficiencies.csv.
  305. if dump_efficiency == True or not tt_1 == 0.0:
  306. if dump_time == False:
  307. ti_p, tr_p, tt_p = ts_p = calc_times(stats)
  308. if tt_1 == 0.0:
  309. sys.stderr.write("WARNING: Task efficiency will be 1.0 because -s is not set!\n")
  310. tt_1 = tt_p
  311. # Compute efficiencies.
  312. et = round(calc_et(tt_1, tt_p), 6)
  313. es = round(calc_es(tt_p, ts_p), 6)
  314. er = round(calc_er(tt_p, tr_p, ts_p), 6)
  315. ep = round(calc_ep(tt_p, tr_p, ti_p, ts_p), 6)
  316. e = round(calc_e(et, er, ep, es), 6)
  317. save_efficiencies(e, ep, er, et, es)
  318. if __name__ == "__main__":
  319. main()