def _init_logging(self): """ Creates logger that logs to file and stdout. Used for: - adding variants in daemonized proc; - clean(), which would typically be run as a cron, but can also be run manually (hence the logging to stdout also) """ logger = logging.getLogger("rez-pkg-cache") logger.setLevel(logging.INFO) logger.propagate = False logfilepath = os.path.join(self._log_dir, time.strftime("%Y-%m-%d.log")) handler1 = logging.FileHandler(logfilepath) handler2 = ColorizedStreamHandler() formatter = logging.Formatter( "%(name)s %(asctime)s PID-%(process)d %(levelname)s %(message)s") for h in (handler1, handler2): h.setFormatter(formatter) logger.addHandler(h) # delete old logfiles now = int(time.time()) try: for name in os.listdir(self._log_dir): filepath = os.path.join(self._log_dir, name) st = os.stat(filepath) age_secs = now - int(st.st_ctime) age_days = age_secs / (3600 * 24) if age_days > config.package_cache_log_days: safe_remove(filepath) except: logger.exception("Failed to delete old logfiles") return logger
def _run_daemon_step(self, state): logger = state["logger"] # pick a random pending variant to copy pending_filenames = set(os.listdir(self._pending_dir)) pending_filenames -= set(state.get("copying", set())) if not pending_filenames: return False i = random.randint(0, len(pending_filenames) - 1) filename = list(pending_filenames)[i] filepath = os.path.join(self._pending_dir, filename) try: with open(filepath) as f: variant_handle_dict = json.loads(f.read()) except IOError as e: if e.errno == errno.ENOENT: return True # was probably deleted by another rez-pkg-cache proc raise variant = get_variant(variant_handle_dict) # copy the variant and log activity logger.info("Started caching of variant %s...", variant.uri) t = time.time() try: rootpath, status = self.add_variant(variant) except PackageCacheError as e: # variant cannot be cached, so remove as a pending variant logger.warning(str(e)) safe_remove(filepath) return True except Exception: # This is probably an error during shutil.copytree (eg a perms fail). # In this case, the variant will be in VARIANT_COPYING status, and # will shortly transition to VARIANT_COPY_STALLED. Thus we can # remove the pending variant, as there's nothing more we can do. # logger.exception("Failed to add variant to the cache") safe_remove(filepath) return True secs = time.time() - t if status == self.VARIANT_FOUND: logger.info("Variant was already cached at %s", rootpath) elif status == self.VARIANT_COPYING: logger.info("Variant is already being copied to %s", rootpath) elif status == self.VARIANT_COPY_STALLED: logger.info("Variant is stalled copying to %s", rootpath) else: # VARIANT_CREATED logger.info("Cached variant to %s in %g seconds", rootpath, secs) if status == self.VARIANT_COPYING: # we cannot delete the pending file (another proc is copying the # variant, so it's responsible); but we also have to ignore this # variant from now on. # state.setdefault("copying", set()).add(filename) else: safe_remove(filepath) return True