Mercurial > piecrust2

comparison piecrust/commands/builtin/baking.py @ 989:8adc27285d93

Find changesets by keywords (author, files, the commit message), revision number or hash, or revset expression.
bake: Big pass on bake performance. - Reduce the amount of data passed between processes. - Make inter-process data simple objects to make it easier to test with alternatives to pickle. - Make sources have the basic requirement to be able to find a content item from an item spec (path). - Make Hoedown the default Markdown formatter.
author Ludovic Chabant <ludovic@chabant.com>
date Sun, 19 Nov 2017 14:29:17 -0800
parents f83ae0a5d793
children 3c669bb9498e
comparison
equal deleted inserted replaced
988:f83ae0a5d793 989:8adc27285d93
46 action='store_true') 46 action='store_true')
47 parser.add_argument( 47 parser.add_argument(
48 '--show-stats', 48 '--show-stats',
49 help="Show detailed information about the bake.", 49 help="Show detailed information about the bake.",
50 action='store_true') 50 action='store_true')
51 parser.add_argument(
52 '--profile',
53 help="Run the bake several times, for profiling.",
54 type=int, default=-1)
51 55
52 def run(self, ctx): 56 def run(self, ctx):
53 from piecrust.chefutil import format_timed 57 from piecrust.chefutil import format_timed
58 from piecrust.environment import ExecutionStats
54 59
55 out_dir = (ctx.args.output or 60 out_dir = (ctx.args.output or
56 os.path.join(ctx.app.root_dir, '_counter')) 61 os.path.join(ctx.app.root_dir, '_counter'))
57 62
63 success = True
64 avg_stats = ExecutionStats()
65 avg_stats.registerTimer('Total')
58 start_time = time.perf_counter() 66 start_time = time.perf_counter()
59 try: 67
60 records = self._doBake(ctx, out_dir) 68 num_iter = 1
61 69 if ctx.args.profile > 0:
62 # Show merged stats. 70 num_iter = ctx.args.profile
63 if ctx.args.show_stats: 71
64 logger.info("-------------------") 72 for i in range(num_iter):
65 logger.info("Timing information:") 73 iter_start_time = time.perf_counter()
66 _show_stats(records.stats) 74 if num_iter > 1:
67 75 import gc
68 # All done. 76 gc.collect()
69 logger.info('-------------------------') 77 logger.info("---- %d/%d ----" % (i + 1, num_iter))
70 logger.info(format_timed(start_time, 'done baking')) 78
71 return 0 if records.success else 1 79 try:
72 except Exception as ex: 80 records = self._doBake(ctx, out_dir)
73 if ctx.app.debug: 81 except Exception as ex:
74 logger.exception(ex) 82 if ctx.app.debug:
75 else: 83 logger.exception(ex)
76 logger.error(str(ex)) 84 else:
77 return 1 85 logger.error(str(ex))
86 return 1
87
88 success = success and records.success
89 avg_stats.mergeStats(records.stats)
90 avg_stats.stepTimerSince('Total', iter_start_time)
91
92 # Show merged stats.
93 if ctx.args.show_stats:
94 if num_iter > 1:
95 _average_stats(avg_stats, num_iter)
96
97 logger.info("-------------------")
98 logger.info("Timing information:")
99 _show_stats(avg_stats)
100
101 # All done.
102 logger.info('-------------------------')
103 logger.info(format_timed(start_time, 'done baking'))
104 return 0 if success else 1
78 105
79 def _doBake(self, ctx, out_dir): 106 def _doBake(self, ctx, out_dir):
80 from piecrust.baking.baker import Baker 107 from piecrust.baking.baker import Baker
81 108
82 if ctx.args.workers > 0: 109 if ctx.args.workers > 0:
249 276
250 if entries_to_show: 277 if entries_to_show:
251 logger.info("Record: %s" % rec.name) 278 logger.info("Record: %s" % rec.name)
252 logger.info("Status: %s" % ('SUCCESS' if rec.success 279 logger.info("Status: %s" % ('SUCCESS' if rec.success
253 else 'FAILURE')) 280 else 'FAILURE'))
281 logger.info("User Data:")
282 if not rec.user_data:
283 logger.info(" <empty>")
284 else:
285 for k, v in rec.user_data.items():
286 logger.info(" %s: %s" % (k, v))
287
254 for e in entries_to_show: 288 for e in entries_to_show:
255 _print_record_entry(e) 289 _print_record_entry(e)
256 logger.info("") 290 logger.info("")
257 291
258 stats = records.stats 292 stats = records.stats
268 (Fore.CYAN, name, Fore.RESET, len(val))) 302 (Fore.CYAN, name, Fore.RESET, len(val)))
269 for v in val: 303 for v in val:
270 logger.info(" - %s" % v) 304 logger.info(" - %s" % v)
271 305
272 306
307 def _average_stats(stats, cnt):
308 for name in stats.timers:
309 stats.timers[name] /= cnt
310 for name in stats.counters:
311 stats.counters[name] /= cnt
312
313
273 def _show_stats(stats, *, full=False): 314 def _show_stats(stats, *, full=False):
274 indent = ' ' 315 indent = ' '
275 316
276 logger.info(' Timers:') 317 logger.info(' Timers:')
277 for name, val in sorted(stats.timers.items(), key=lambda i: i[1], 318 for name, val in sorted(stats.timers.items(), key=lambda i: i[1],