Coverage for pySDC/core/timings.py: 100%

1import time 

2from pySDC.core.hooks import Hooks 

3 

4 

5class Timings(Hooks): 

6 """ 

7 Abstract base class for hooks timing the setup, run, predictor, steps, iterations, sweeps and communication. 

8 

9 Attributes: 

10 __t0_setup (float): private variable to get starting time of setup 

11 __t0_run (float): private variable to get starting time of the run 

12 __t0_predict (float): private variable to get starting time of the predictor 

13 __t0_step (float): private variable to get starting time of the step 

14 __t0_iteration (float): private variable to get starting time of the iteration 

15 __t0_sweep (float): private variable to get starting time of the sweep 

16 __t0_comm (list): private variable to get starting time of the communication 

17 __t1_run (float): private variable to get end time of the run 

18 __t1_predict (float): private variable to get end time of the predictor 

19 __t1_step (float): private variable to get end time of the step 

20 __t1_iteration (float): private variable to get end time of the iteration 

21 __t1_sweep (float): private variable to get end time of the sweep 

22 __t1_setup (float): private variable to get end time of setup 

23 __t1_comm (list): private variable to hold timing of the communication (!) 

24 """ 

25 

26 prefix = '' 

27 

28 def _compute_time_elapsed(self, event_after, event_before): 

29 raise NotImplementedError 

30 

31 def _get_event(self): 

32 raise NotImplementedError 

33 

34 def __init__(self): 

35 """Start with all start and end times unset.""" 

36 super().__init__() 

37 self.__t0_setup = None 

38 self.__t0_run = None 

39 self.__t0_predict = None 

40 self.__t0_step = None 

41 self.__t0_iteration = None 

42 self.__t0_sweep = None 

43 self.__t0_comm = [] 

44 self.__t1_run = None 

45 self.__t1_predict = None 

46 self.__t1_step = None 

47 self.__t1_iteration = None 

48 self.__t1_sweep = None 

49 self.__t1_setup = None 

50 self.__t1_comm = [] 

51 

52 def pre_setup(self, step, level_number): 

53 """ 

54 Default routine called before setup starts 

55 

56 Args: 

57 step (pySDC.Step.step): the current step 

58 level_number (int): the current level number 

59 """ 

60 super().pre_setup(step, level_number) 

61 self.__t0_setup = self._get_event() 

62 

63 def pre_run(self, step, level_number): 

64 """ 

65 Default routine called before time-loop starts 

66 

67 Args: 

68 step (pySDC.Step.step): the current step 

69 level_number (int): the current level number 

70 """ 

71 super().pre_run(step, level_number) 

72 self.__t0_run = self._get_event() 

73 

74 def pre_predict(self, step, level_number): 

75 """ 

76 Default routine called before predictor starts 

77 

78 Args: 

79 step (pySDC.Step.step): the current step 

80 level_number (int): the current level number 

81 """ 

82 super().pre_predict(step, level_number) 

83 self.__t0_predict = self._get_event() 

84 

85 def pre_step(self, step, level_number): 

86 """ 

87 Hook called before each step 

88 

89 Args: 

90 step (pySDC.Step.step): the current step 

91 level_number (int): the current level number 

92 """ 

93 super().pre_step(step, level_number) 

94 self.__t0_step = self._get_event() 

95 

96 def pre_iteration(self, step, level_number): 

97 """ 

98 Default routine called before iteration starts 

99 

100 Args: 

101 step (pySDC.Step.step): the current step 

102 level_number (int): the current level number 

103 """ 

104 super().pre_iteration(step, level_number) 

105 self.__t0_iteration = self._get_event() 

106 

107 def pre_sweep(self, step, level_number): 

108 """ 

109 Default routine called before sweep starts 

110 

111 Args: 

112 step (pySDC.Step.step): the current step 

113 level_number (int): the current level number 

114 """ 

115 super().pre_sweep(step, level_number) 

116 self.__t0_sweep = self._get_event() 

117 

118 def pre_comm(self, step, level_number): 

119 """ 

120 Default routine called before communication starts 

121 

122 Args: 

123 step (pySDC.Step.step): the current step 

124 level_number (int): the current level number 

125 """ 

126 super().pre_comm(step, level_number) 

127 if len(self.__t0_comm) >= level_number + 1: 

128 self.__t0_comm[level_number] = self._get_event() 

129 else: 

130 while len(self.__t0_comm) < level_number: 

131 self.__t0_comm.append(None) 

132 self.__t0_comm.append(self._get_event()) 

133 while len(self.__t1_comm) <= level_number: 

134 self.__t1_comm.append(0.0) 

135 assert len(self.__t0_comm) == level_number + 1 

136 assert len(self.__t1_comm) == level_number + 1 

137 

138 def post_comm(self, step, level_number, add_to_stats=False): 

139 """ 

140 Default routine called after each communication 

141 

142 Args: 

143 step (pySDC.Step.step): the current step 

144 level_number (int): the current level number 

145 add_to_stats (bool): set if result should go to stats object 

146 """ 

147 super().post_comm(step, level_number) 

148 assert len(self.__t1_comm) >= level_number + 1 

149 self.__t1_comm[level_number] += self._compute_time_elapsed(self._get_event(), self.__t0_comm[level_number]) 

150 

151 if add_to_stats: 

152 L = step.levels[level_number] 

153 

154 self.add_to_stats( 

155 process=step.status.slot, 

156 process_sweeper=L.sweep.rank, 

157 time=L.time, 

158 level=L.level_index, 

159 iter=step.status.iter, 

160 sweep=L.status.sweep, 

161 type=f'{self.prefix}timing_comm', 

162 value=self.__t1_comm[level_number], 

163 ) 

164 self.__t1_comm[level_number] = 0.0 

165 

166 def post_sweep(self, step, level_number): 

167 """ 

168 Default routine called after each sweep 

169 

170 Args: 

171 step (pySDC.Step.step): the current step 

172 level_number (int): the current level number 

173 """ 

174 super().post_sweep(step, level_number) 

175 self.__t1_sweep = self._get_event() 

176 

177 L = step.levels[level_number] 

178 

179 self.add_to_stats( 

180 process=step.status.slot, 

181 process_sweeper=L.sweep.rank, 

182 time=L.time, 

183 level=L.level_index, 

184 iter=step.status.iter, 

185 sweep=L.status.sweep, 

186 type=f'{self.prefix}timing_sweep', 

187 value=self._compute_time_elapsed(self.__t1_sweep, self.__t0_sweep), 

188 ) 

189 

190 def post_iteration(self, step, level_number): 

191 """ 

192 Default routine called after each iteration 

193 

194 Args: 

195 step (pySDC.Step.step): the current step 

196 level_number (int): the current level number 

197 """ 

198 super().post_iteration(step, level_number) 

199 self.__t1_iteration = self._get_event() 

200 

201 L = step.levels[level_number] 

202 

203 self.add_to_stats( 

204 process=step.status.slot, 

205 process_sweeper=L.sweep.rank, 

206 time=L.time, 

207 level=L.level_index, 

208 iter=step.status.iter, 

209 sweep=L.status.sweep, 

210 type=f'{self.prefix}timing_iteration', 

211 value=self._compute_time_elapsed(self.__t1_iteration, self.__t0_iteration), 

212 ) 

213 

214 def post_step(self, step, level_number): 

215 """ 

216 Default routine called after each step or block 

217 

218 Args: 

219 step (pySDC.Step.step): the current step 

220 level_number (int): the current level number 

221 """ 

222 super().post_step(step, level_number) 

223 self.__t1_step = self._get_event() 

224 

225 L = step.levels[level_number] 

226 

227 self.add_to_stats( 

228 process=step.status.slot, 

229 process_sweeper=L.sweep.rank, 

230 time=L.time, 

231 level=L.level_index, 

232 iter=step.status.iter, 

233 sweep=L.status.sweep, 

234 type=f'{self.prefix}timing_step', 

235 value=self._compute_time_elapsed(self.__t1_step, self.__t0_step), 

236 ) 

237 

238 def post_predict(self, step, level_number): 

239 """ 

240 Default routine called after each predictor 

241 

242 Args: 

243 step (pySDC.Step.step): the current step 

244 level_number (int): the current level number 

245 """ 

246 super().post_predict(step, level_number) 

247 self.__t1_predict = self._get_event() 

248 

249 L = step.levels[level_number] 

250 

251 self.add_to_stats( 

252 process=step.status.slot, 

253 process_sweeper=L.sweep.rank, 

254 time=L.time, 

255 level=L.level_index, 

256 iter=step.status.iter, 

257 sweep=L.status.sweep, 

258 type=f'{self.prefix}timing_predictor', 

259 value=self._compute_time_elapsed(self.__t1_predict, self.__t0_predict), 

260 ) 

261 

262 def post_run(self, step, level_number): 

263 """ 

264 Default routine called after each run 

265 

266 Args: 

267 step (pySDC.Step.step): the current step 

268 level_number (int): the current level number 

269 """ 

270 super().post_run(step, level_number) 

271 self.__t1_run = self._get_event() 

272 t_run = self._compute_time_elapsed(self.__t1_run, self.__t0_run) 

273 

274 L = step.levels[level_number] 

275 

276 self.add_to_stats( 

277 process=step.status.slot, 

278 process_sweeper=L.sweep.rank, 

279 time=L.time, 

280 level=L.level_index, 

281 iter=step.status.iter, 

282 sweep=L.status.sweep, 

283 type=f'{self.prefix}timing_run', 

284 value=t_run, 

285 ) 

286 if step.status.first: 

287 self.logger.info(f'Finished run after {t_run:.2e}s') 

288 

289 def post_setup(self, step, level_number): 

290 """ 

291 Default routine called after setup 

292 

293 Args: 

294 step (pySDC.Step.step): the current step 

295 level_number (int): the current level number 

296 """ 

297 super().post_setup(step, level_number) 

298 self.__t1_setup = self._get_event() 

299 

300 self.add_to_stats( 

301 process=-1, 

302 process_sweeper=-1, 

303 time=-1, 

304 level=-1, 

305 iter=-1, 

306 sweep=-1, 

307 type=f'{self.prefix}timing_setup', 

308 value=self._compute_time_elapsed(self.__t1_setup, self.__t0_setup), 

309 ) 

310 

311 

312class CPUTimings(Timings): 

313 """ 

314 Hook for recording CPU timings of important operations during a pySDC run. 

315 """ 

316 

317 def _compute_time_elapsed(self, event_after, event_before): 

318 return event_after - event_before 

319 

320 def _get_event(self): 

321 return time.perf_counter()