Mercurial > piecrust2
diff piecrust/commands/builtin/baking.py @ 989:8adc27285d93
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 |
line wrap: on
line diff
--- a/piecrust/commands/builtin/baking.py Fri Nov 03 23:14:56 2017 -0700 +++ b/piecrust/commands/builtin/baking.py Sun Nov 19 14:29:17 2017 -0800 @@ -48,33 +48,60 @@ '--show-stats', help="Show detailed information about the bake.", action='store_true') + parser.add_argument( + '--profile', + help="Run the bake several times, for profiling.", + type=int, default=-1) def run(self, ctx): from piecrust.chefutil import format_timed + from piecrust.environment import ExecutionStats out_dir = (ctx.args.output or os.path.join(ctx.app.root_dir, '_counter')) + success = True + avg_stats = ExecutionStats() + avg_stats.registerTimer('Total') start_time = time.perf_counter() - try: - records = self._doBake(ctx, out_dir) - # Show merged stats. - if ctx.args.show_stats: - logger.info("-------------------") - logger.info("Timing information:") - _show_stats(records.stats) + num_iter = 1 + if ctx.args.profile > 0: + num_iter = ctx.args.profile + + for i in range(num_iter): + iter_start_time = time.perf_counter() + if num_iter > 1: + import gc + gc.collect() + logger.info("---- %d/%d ----" % (i + 1, num_iter)) - # All done. - logger.info('-------------------------') - logger.info(format_timed(start_time, 'done baking')) - return 0 if records.success else 1 - except Exception as ex: - if ctx.app.debug: - logger.exception(ex) - else: - logger.error(str(ex)) - return 1 + try: + records = self._doBake(ctx, out_dir) + except Exception as ex: + if ctx.app.debug: + logger.exception(ex) + else: + logger.error(str(ex)) + return 1 + + success = success and records.success + avg_stats.mergeStats(records.stats) + avg_stats.stepTimerSince('Total', iter_start_time) + + # Show merged stats. + if ctx.args.show_stats: + if num_iter > 1: + _average_stats(avg_stats, num_iter) + + logger.info("-------------------") + logger.info("Timing information:") + _show_stats(avg_stats) + + # All done. + logger.info('-------------------------') + logger.info(format_timed(start_time, 'done baking')) + return 0 if success else 1 def _doBake(self, ctx, out_dir): from piecrust.baking.baker import Baker @@ -251,6 +278,13 @@ logger.info("Record: %s" % rec.name) logger.info("Status: %s" % ('SUCCESS' if rec.success else 'FAILURE')) + logger.info("User Data:") + if not rec.user_data: + logger.info(" <empty>") + else: + for k, v in rec.user_data.items(): + logger.info(" %s: %s" % (k, v)) + for e in entries_to_show: _print_record_entry(e) logger.info("") @@ -270,6 +304,13 @@ logger.info(" - %s" % v) +def _average_stats(stats, cnt): + for name in stats.timers: + stats.timers[name] /= cnt + for name in stats.counters: + stats.counters[name] /= cnt + + def _show_stats(stats, *, full=False): indent = ' '