comparison piecrust/commands/builtin/baking.py @ 687:61d606fbc313

bake: Change `show-timers` to `show-stats`, add stats.
author Ludovic Chabant <ludovic@chabant.com>
date Mon, 14 Mar 2016 08:26:14 -0700
parents 81d9c3a3a0b5
children c11a4339fccb
comparison
equal deleted inserted replaced
686:1a6c4c2683fd 687:61d606fbc313
9 from piecrust.baking.baker import Baker 9 from piecrust.baking.baker import Baker
10 from piecrust.baking.records import ( 10 from piecrust.baking.records import (
11 BakeRecord, BakeRecordEntry, SubPageBakeInfo) 11 BakeRecord, BakeRecordEntry, SubPageBakeInfo)
12 from piecrust.chefutil import format_timed 12 from piecrust.chefutil import format_timed
13 from piecrust.commands.base import ChefCommand 13 from piecrust.commands.base import ChefCommand
14 from piecrust.environment import ExecutionStats
14 from piecrust.processing.pipeline import ProcessorPipeline 15 from piecrust.processing.pipeline import ProcessorPipeline
15 from piecrust.processing.records import ( 16 from piecrust.processing.records import (
16 ProcessorPipelineRecord, 17 ProcessorPipelineRecord,
17 FLAG_PREPARED, FLAG_PROCESSED, 18 FLAG_PREPARED, FLAG_PROCESSED,
18 FLAG_BYPASSED_STRUCTURED_PROCESSING) 19 FLAG_BYPASSED_STRUCTURED_PROCESSING)
53 parser.add_argument( 54 parser.add_argument(
54 '--html-only', 55 '--html-only',
55 help="Only bake the pages (don't run the asset pipeline).", 56 help="Only bake the pages (don't run the asset pipeline).",
56 action='store_true') 57 action='store_true')
57 parser.add_argument( 58 parser.add_argument(
58 '--show-timers', 59 '--show-stats',
59 help="Show detailed timing information.", 60 help="Show detailed information about the bake.",
60 action='store_true') 61 action='store_true')
61 62
62 def run(self, ctx): 63 def run(self, ctx):
63 out_dir = (ctx.args.output or 64 out_dir = (ctx.args.output or
64 os.path.join(ctx.app.root_dir, '_counter')) 65 os.path.join(ctx.app.root_dir, '_counter'))
65 66
66 success = True 67 success = True
67 ctx.timers = {} 68 ctx.stats = {}
68 start_time = time.perf_counter() 69 start_time = time.perf_counter()
69 try: 70 try:
70 # Bake the site sources. 71 # Bake the site sources.
71 if not ctx.args.assets_only: 72 if not ctx.args.assets_only:
72 success = success & self._bakeSources(ctx, out_dir) 73 success = success & self._bakeSources(ctx, out_dir)
73 74
74 # Bake the assets. 75 # Bake the assets.
75 if not ctx.args.html_only: 76 if not ctx.args.html_only:
76 success = success & self._bakeAssets(ctx, out_dir) 77 success = success & self._bakeAssets(ctx, out_dir)
77 78
78 # Show merged timers. 79 # Show merged stats.
79 if ctx.args.show_timers: 80 if ctx.args.show_stats:
80 logger.info("-------------------") 81 logger.info("-------------------")
81 logger.info("Timing information:") 82 logger.info("Timing information:")
82 _show_timers(ctx.timers) 83 _show_stats(ctx.stats)
83 84
84 # All done. 85 # All done.
85 logger.info('-------------------------') 86 logger.info('-------------------------')
86 logger.info(format_timed(start_time, 'done baking')) 87 logger.info(format_timed(start_time, 'done baking'))
87 return 0 if success else 1 88 return 0 if success else 1
101 ctx.app, out_dir, 102 ctx.app, out_dir,
102 force=ctx.args.force, 103 force=ctx.args.force,
103 applied_config_variant=ctx.config_variant, 104 applied_config_variant=ctx.config_variant,
104 applied_config_values=ctx.config_values) 105 applied_config_values=ctx.config_values)
105 record = baker.bake() 106 record = baker.bake()
106 _merge_timers(record.timers, ctx.timers) 107 _merge_stats(record.stats, ctx.stats)
107 return record.success 108 return record.success
108 109
109 def _bakeAssets(self, ctx, out_dir): 110 def _bakeAssets(self, ctx, out_dir):
110 proc = ProcessorPipeline( 111 proc = ProcessorPipeline(
111 ctx.app, out_dir, 112 ctx.app, out_dir,
112 force=ctx.args.force, 113 force=ctx.args.force,
113 applied_config_variant=ctx.config_variant, 114 applied_config_variant=ctx.config_variant,
114 applied_config_values=ctx.config_values) 115 applied_config_values=ctx.config_values)
115 record = proc.run() 116 record = proc.run()
116 _merge_timers(record.timers, ctx.timers) 117 _merge_stats(record.stats, ctx.stats)
117 return record.success 118 return record.success
118 119
119 120
120 def _merge_timers(source, target): 121 def _merge_stats(source, target):
121 if source is None: 122 if source is None:
122 return 123 return
123 124
124 for name, val in source.items(): 125 for name, val in source.items():
125 if isinstance(val, float): 126 if name not in target:
126 if name not in target: 127 target[name] = ExecutionStats()
127 target[name] = 0 128 target[name].mergeStats(val)
128 target[name] += val 129
129 elif isinstance(val, dict): 130
130 if name not in target: 131 def _show_stats(stats, full=False):
131 target[name] = {} 132 indent = ' '
132 _merge_timers(val, target[name]) 133 for name in sorted(stats.keys()):
133 134 logger.info('%s:' % name)
134 135 s = stats[name]
135 def _show_timers(timers, indent=''): 136
136 sub_timer_names = [] 137 logger.info(' Timers:')
137 for name in sorted(timers.keys()): 138 for name, val in s.timers.items():
138 if isinstance(timers[name], float): 139 val_str = '%8.1f s' % val
139 val_str = '%8.1f s' % timers[name]
140 logger.info( 140 logger.info(
141 "%s[%s%s%s] %s" % 141 "%s[%s%s%s] %s" %
142 (indent, Fore.GREEN, val_str, Fore.RESET, name)) 142 (indent, Fore.GREEN, val_str, Fore.RESET, name))
143 else: 143
144 sub_timer_names.append(name) 144 logger.info(' Counters:')
145 145 for name, val in s.counters.items():
146 for name in sub_timer_names: 146 val_str = '%8d ' % val
147 logger.info('%s:' % name) 147 logger.info(
148 _show_timers(timers[name], indent + ' ') 148 "%s[%s%s%s] %s" %
149 (indent, Fore.GREEN, val_str, Fore.RESET, name))
150
151 logger.info(' Manifests:')
152 for name, val in s.manifests.items():
153 logger.info(
154 "%s[%s%s%s] [%d entries]" %
155 (indent, Fore.CYAN, name, Fore.RESET, len(val)))
156 if full:
157 for v in val:
158 logger.info("%s - %s" % (indent, v))
149 159
150 160
151 class ShowRecordCommand(ChefCommand): 161 class ShowRecordCommand(ChefCommand):
152 def __init__(self): 162 def __init__(self):
153 super(ShowRecordCommand, self).__init__() 163 super(ShowRecordCommand, self).__init__()
276 if sub.render_info: 286 if sub.render_info:
277 pass_names = { 287 pass_names = {
278 PASS_FORMATTING: 'formatting pass', 288 PASS_FORMATTING: 'formatting pass',
279 PASS_RENDERING: 'rendering pass'} 289 PASS_RENDERING: 'rendering pass'}
280 for p, ri in sub.render_info.items(): 290 for p, ri in sub.render_info.items():
281 logging.info(" - %s" % pass_names[p]) 291 logging.info(" - %s" % p)
282 logging.info(" used sources: %s" % 292 logging.info(" used sources: %s" %
283 _join(ri.used_source_names)) 293 _join(ri.used_source_names))
284 pgn_info = 'no' 294 pgn_info = 'no'
285 if ri.used_pagination: 295 if ri.used_pagination:
286 pgn_info = 'yes' 296 pgn_info = 'yes'