# HG changeset patch # User Ludovic Chabant # Date 1408685302 25200 # Node ID 2f717f9619960abf6e98c74dd30e97e14ae88bd4 # Parent 091f99bfbe4410ee920fbdff4e5185edad7dd061 Better error reporting and cache validation. Fix the processor pipeline in the preview server. Move the `pages` route to first position. diff -r 091f99bfbe44 -r 2f717f961996 piecrust/app.py --- a/piecrust/app.py Thu Aug 21 10:56:17 2014 -0700 +++ b/piecrust/app.py Thu Aug 21 22:28:22 2014 -0700 @@ -24,7 +24,7 @@ logger = logging.getLogger(__name__) -CACHE_VERSION = 12 +CACHE_VERSION = 13 class VariantNotFoundError(Exception): @@ -68,6 +68,7 @@ actual_cache_key = self._values.get('__cache_key') if actual_cache_key == cache_key: + self._values['__cache_valid'] = True return logger.debug("Outdated cache key '%s' (expected '%s')." % ( actual_cache_key, cache_key)) @@ -92,6 +93,7 @@ self._values['__cache_key'] = cache_key config_text = json.dumps(self._values) self.cache.write('config.json', config_text) + self._values['__cache_valid'] = False def _validateAll(self, values): # Put all the defaults in the `site` section. @@ -181,6 +183,10 @@ sitec['sources'] = sourcesc routesc = [] + routesc.append({ + 'url': '/%path:path%', + 'source': 'pages', + 'func': 'pcurl(path)'}) sitec['routes'] = routesc taxonomiesc = {} @@ -238,9 +244,6 @@ 'taxonomy': 'categories', 'func': 'pccaturl(category)'}) - routesc.append({'url': '/%path:path%', 'source': 'pages', - 'func': 'pcurl(path)'}) - # Validate sources/routes. sourcesc = sitec.get('sources') routesc = sitec.get('routes') diff -r 091f99bfbe44 -r 2f717f961996 piecrust/baking/baker.py --- a/piecrust/baking/baker.py Thu Aug 21 10:56:17 2014 -0700 +++ b/piecrust/baking/baker.py Thu Aug 21 22:28:22 2014 -0700 @@ -8,7 +8,7 @@ import urllib.request, urllib.error, urllib.parse from queue import Queue, Empty from piecrust.baking.records import TransitionalBakeRecord, BakeRecordPageEntry -from piecrust.chefutil import format_timed +from piecrust.chefutil import format_timed, log_friendly_exception from piecrust.data.filters import (PaginationFilter, HasFilterClause, IsFilterClause, AndBooleanClause) from piecrust.processing.base import ProcessorPipeline @@ -157,7 +157,7 @@ ctx, rp = self._bakeSingle(page, sub_uri, cur_sub, out_path, pagination_filter, custom_data) except Exception as ex: - raise Exception("Error baking page '%s' for URI '%s'." % + raise Exception("Error baking page '%s' for URL '%s'." % (page.ref_spec, uri)) from ex # Copy page assets. @@ -263,6 +263,10 @@ logger.debug(format_timed(t, 'loaded previous bake record', colored=False)); + # Figure out if we need to clean the cache because important things + # have changed. + self._handleCacheValidity(record) + # Gather all sources by realm -- we're going to bake each realm # separately so we can handle "overlaying" (i.e. one realm overrides # another realm's pages). @@ -287,6 +291,7 @@ # Save the bake record. t = time.clock() + record.current.bake_time = time.time() record.collapseRecords() record.saveCurrent(record_cache.getCachePath(record_name)) logger.debug(format_timed(t, 'saved bake record', colored=False)) @@ -296,6 +301,43 @@ logger.info('-------------------------'); logger.info(format_timed(start_time, 'done baking')); + def _handleCacheValidity(self, record): + start_time = time.clock() + + reason = None + if self.force: + reason = "ordered to" + elif not self.app.config.get('__cache_valid'): + # The configuration file was changed, or we're running a new + # version of the app. + reason = "not valid anymore" + elif not record.previous.bake_time: + # We have no valid previous bake record. + reason = "need bake record regeneration" + else: + # Check if any template has changed since the last bake. Since + # there could be some advanced conditional logic going on, we'd + # better just force a bake from scratch if that's the case. + max_time = 0 + for d in self.app.templates_dirs: + for _, __, filenames in os.walk(d): + for fn in filenames: + max_time = max(max_time, os.path.getmtime(fn)) + if max_time >= record.previous.bake_time: + reason = "templates modified" + + if reason is not None: + cache_dir = self.app.cache_dir + if os.path.isdir(cache_dir): + logger.debug("Cleaning cache: %s" % cache_dir) + shutil.rmtree(cache_dir) + self.force = True + logger.info(format_timed(start_time, + "cleaned cache (reason: %s)" % reason)) + else: + logger.debug(format_timed(start_time, "cache is assumed valid", + colored=False)) + def _bakeRealm(self, record, realm, srclist): # Gather all page factories from the sources and queue them # for the workers to pick up. Just skip taxonomy pages for now. @@ -435,7 +477,16 @@ for w in pool: w.join() if abort.is_set(): - raise Exception("Worker pool was aborted.") + excs = [w.abort_exception for w in pool + if w.abort_exception is not None] + logger.error("%s errors" % len(excs)) + if self.app.debug: + for e in excs: + logger.exception(e) + else: + for e in excs: + log_friendly_exception(logger, e) + raise Exception("Baking was aborted due to errors.") class BakeWorkerContext(object): @@ -463,10 +514,10 @@ class BakeWorker(threading.Thread): def __init__(self, wid, ctx): - super(BakeWorker, self).__init__() + super(BakeWorker, self).__init__(name=('worker%d' % wid)) self.wid = wid self.ctx = ctx - self.num_bakes = 0 + self.abort_exception = None self._page_baker = PageBaker(ctx.app, ctx.out_dir, ctx.force, ctx.record) @@ -484,8 +535,8 @@ self.ctx.work_queue.task_done() except Exception as ex: self.ctx.abort_event.set() - logger.error("[%d] Critical error, aborting." % self.wid) - logger.exception(ex) + self.abort_exception = ex + logger.debug("[%d] Critical error, aborting." % self.wid) break def _unsafeRun(self, job): @@ -503,5 +554,4 @@ friendly_count = ' (%d pages)' % bake_res.num_subs logger.info(format_timed(start_time, '[%d] %s%s' % (self.wid, friendly_uri, friendly_count))) - self.num_bakes += 1 diff -r 091f99bfbe44 -r 2f717f961996 piecrust/chefutil.py --- a/piecrust/chefutil.py Thu Aug 21 10:56:17 2014 -0700 +++ b/piecrust/chefutil.py Thu Aug 21 22:28:22 2014 -0700 @@ -9,3 +9,11 @@ return '[%s%s%s] %s' % (Fore.GREEN, time_str, Fore.RESET, message) return '[%s] %s' % (time_str, message) + +def log_friendly_exception(logger, ex): + indent = '' + while ex: + logger.error('%s%s' % (indent, str(ex))) + indent += ' ' + ex = ex.__cause__ + diff -r 091f99bfbe44 -r 2f717f961996 piecrust/commands/builtin/baking.py --- a/piecrust/commands/builtin/baking.py Thu Aug 21 10:56:17 2014 -0700 +++ b/piecrust/commands/builtin/baking.py Thu Aug 21 22:28:22 2014 -0700 @@ -41,7 +41,12 @@ # a web server to handle serving default documents. ctx.app.config.set('site/pretty_urls', False) - baker.bake() + try: + baker.bake() + return 0 + except Exception as ex: + logger.error(str(ex)) + return 1 class ShowRecordCommand(ChefCommand): @@ -59,7 +64,7 @@ def run(self, ctx): out_dir = ctx.args.output or os.path.join(ctx.app.root_dir, '_counter') record_cache = ctx.app.cache.getCache('bake_r') - record_name = hashlib.md5(out_dir).hexdigest() + '.record' + record_name = hashlib.md5(out_dir.encode('utf8')).hexdigest() + '.record' if not record_cache.has(record_name): raise Exception("No record has been created for this output path. " "Did you bake there yet?") diff -r 091f99bfbe44 -r 2f717f961996 piecrust/main.py --- a/piecrust/main.py Thu Aug 21 10:56:17 2014 -0700 +++ b/piecrust/main.py Thu Aug 21 22:28:22 2014 -0700 @@ -5,7 +5,7 @@ import argparse import colorama from piecrust.app import PieCrust, PieCrustConfiguration, APP_VERSION -from piecrust.chefutil import format_timed +from piecrust.chefutil import format_timed, log_friendly_exception from piecrust.environment import StandardEnvironment from piecrust.pathutil import SiteNotFoundError, find_app_root from piecrust.plugins.base import PluginLoader @@ -57,7 +57,8 @@ if pre_args.debug: logger.exception(ex) else: - logger.error(str(ex)) + log_friendly_exception(logger, ex) + return 1 class PreParsedChefArgs(object): @@ -122,7 +123,7 @@ log_handler.setFormatter(ColoredFormatter("%(message)s")) root_logger.addHandler(log_handler) if res.log_file: - root_logger.addHandler(logging.FileHandler(res.log_file)) + root_logger.addHandler(logging.FileHandler(res.log_file, mode='w')) return res diff -r 091f99bfbe44 -r 2f717f961996 piecrust/processing/base.py --- a/piecrust/processing/base.py Thu Aug 21 10:56:17 2014 -0700 +++ b/piecrust/processing/base.py Thu Aug 21 22:28:22 2014 -0700 @@ -115,12 +115,18 @@ class ProcessorPipelineRecordEntry(object): - def __init__(self, rel_input, is_processed=False, is_overridden=False): + def __init__(self, base_dir, rel_input, is_processed=False, + is_overridden=False): + self.base_dir = base_dir self.rel_input = rel_input self.rel_outputs = [] self.is_processed = is_processed self.is_overridden = is_overridden + @property + def path(self): + return os.path.join(self.base_dir, self.rel_input) + class ProcessingContext(object): def __init__(self, base_dir, job_queue, record=None): @@ -284,7 +290,8 @@ # This can happen if a theme file (processed via a mount point) # is overridden in the user's website. if record.hasOverrideEntry(rel_path): - record.addEntry(ProcessorPipelineRecordEntry(rel_path, + record.addEntry(ProcessorPipelineRecordEntry( + job.base_dir, rel_path, is_processed=False, is_overridden=True)) logger.info(format_timed(start_time, '%s [not baked, overridden]' % rel_path)) @@ -294,7 +301,7 @@ tree_root = builder.build(rel_path) print_node(tree_root, recursive=True) leaves = tree_root.getLeaves() - fi = ProcessorPipelineRecordEntry(rel_path) + fi = ProcessorPipelineRecordEntry(job.base_dir, rel_path) fi.rel_outputs = [l.path for l in leaves] record.addEntry(fi) diff -r 091f99bfbe44 -r 2f717f961996 piecrust/serving.py --- a/piecrust/serving.py Thu Aug 21 10:56:17 2014 -0700 +++ b/piecrust/serving.py Thu Aug 21 22:28:22 2014 -0700 @@ -42,11 +42,12 @@ # Bake all the assets so we know what we have, and so we can serve # them to the client. We need a temp app for this. app = PieCrust(root_dir=self.root_dir, debug=self.debug) + mounts = app.assets_dirs self._out_dir = os.path.join(app.cache_dir, 'server') self._skip_patterns = app.config.get('baker/skip_patterns') self._force_patterns = app.config.get('baker/force_patterns') pipeline = ProcessorPipeline( - app, self._out_dir, + app, mounts, self._out_dir, skip_patterns=self._skip_patterns, force_patterns=self._force_patterns) self._record = pipeline.run() @@ -112,10 +113,11 @@ # Yep, we know about this URL because we processed an asset that # maps to it... make sure it's up to date by re-processing it # before serving. - asset_in_path = os.path.join(app.root_dir, entry.rel_input) + mounts = app.assets_dirs + asset_in_path = entry.path asset_out_path = os.path.join(self._out_dir, rel_req_path) pipeline = ProcessorPipeline( - app, self._out_dir, + app, mounts, self._out_dir, skip_patterns=self._skip_patterns, force_patterns=self._force_patterns) pipeline.run(asset_in_path)