import io import logging import os import subprocess import threading from datetime import datetime from enum import Enum import psutil logger = logging.getLogger() class RenderStatus(Enum): NOT_STARTED = "not_started" RUNNING = "running" COMPLETED = "completed" CANCELLED = "cancelled" ERROR = "error" SCHEDULED = "scheduled" def string_to_status(string): for stat in RenderStatus: if stat.value == string: return stat return RenderStatus.ERROR class BaseRenderWorker(object): renderer = 'BaseRenderWorker' render_engine = None supported_extensions = [] install_paths = [] @staticmethod def version(): return 'Unknown' def __init__(self, input_path, output_path, args=None, ignore_extensions=False): if not ignore_extensions: if not any(ext in input_path for ext in self.supported_extensions): err_meg = f'Cannot find valid project with supported file extension for {self.renderer} renderer' logger.error(err_meg) raise ValueError(err_meg) # Essential Info self.input = input_path self.output = output_path self.args = args or {} self.date_created = datetime.now() self.attributes = {} self.renderer_version = self.version() # Ranges self.total_frames = 0 self.current_frame = 0 # Logging self.log_path = None self.start_time = None self.end_time = None self.last_error = None # History self.status = RenderStatus.NOT_STARTED self.warnings = [] self.errors = [] self.failed_attempts = 0 self.maximum_attempts = 1 # Threads and processes self.thread = threading.Thread(target=self.run, args=()) self.thread.daemon = True self.process = None self.is_finished = False self.last_output = None def renderer_path(self): path = None try: path = subprocess.check_output(['which', self.render_engine]).decode('utf-8').strip() except Exception as e: for p in self.install_paths: if os.path.exists(p): path = p # if not path: # logger.error("Failed to get path to {}: {}".format(self.renderer, e)) return path def _generate_subprocess(self): return [] def start(self): if not os.path.exists(self.input): self.status = RenderStatus.ERROR msg = 'Cannot find input path: {}'.format(self.input) logger.error(msg) self.errors.append(msg) return if not self.renderer_path(): self.status = RenderStatus.ERROR msg = 'Cannot find render engine path for {}'.format(self.render_engine) logger.error(msg) self.errors.append(msg) return self.status = RenderStatus.RUNNING logger.info('Starting {0} {1} Render for {2}'.format(self.renderer, self.version(), self.input)) self.thread.start() def run(self): # Setup logging try: if not self.log_path: log_dir = os.path.join(os.path.dirname(self.input), 'logs') if not os.path.exists(log_dir): os.makedirs(log_dir) self.log_path = os.path.join(log_dir, os.path.basename(self.input)) + '.log' logger.info('Logs saved in {}'.format(self.log_path)) except Exception as e: logger.error("Error setting up logging: {}".format(e)) while self.failed_attempts < self.maximum_attempts and self.status is not RenderStatus.COMPLETED: if self.failed_attempts: logger.info('Attempt #{} failed. Starting attempt #{}'.format(self.failed_attempts, self.failed_attempts + 1)) # Start process and get updates subprocess_cmds = self._generate_subprocess() logger.debug("Renderer commands generated - {}".format(" ".join(subprocess_cmds))) self.process = subprocess.Popen(subprocess_cmds, stdout=subprocess.PIPE, stderr=subprocess.STDOUT, universal_newlines=False) self.start_time = datetime.now() with open(self.log_path, "a") as f: f.write("{3} - Starting {0} {1} Render for {2}\n".format(self.renderer, self.version(), self.input, self.start_time.isoformat())) for c in io.TextIOWrapper(self.process.stdout, encoding="utf-8"): # or another encoding f.write(c) logger.debug(f"{self.renderer}Worker: {c.strip()}") self.last_output = c.strip() self._parse_stdout(c.strip()) f.write('\n') # Check return codes return_code = self.process.wait() self.end_time = datetime.now() # Return early if job was cancelled if self.status is RenderStatus.CANCELLED: self.is_finished = True return duration = self.end_time - self.start_time if return_code: message = f"{self.renderer} render failed with return_code {return_code} after {duration}" logger.error(message) self.failed_attempts = self.failed_attempts + 1 else: message = f"{self.renderer} render completed successfully in {duration}" logger.info(message) self.status = RenderStatus.COMPLETED f.write(message) if self.failed_attempts >= self.maximum_attempts and self.status is not RenderStatus.CANCELLED: logger.error('{} Render of {} failed after {} attempts'.format(self.renderer, self.input, self.failed_attempts)) self.status = RenderStatus.ERROR if not self.errors: self.errors = [self.last_output] self.is_finished = True def is_running(self): if self.thread: return self.thread.is_alive() return False def stop(self): if self.process: try: self.status = RenderStatus.CANCELLED self.maximum_attempts = 0 process = psutil.Process(self.process.pid) for proc in process.children(recursive=True): proc.kill() process.kill() except Exception as e: logger.error(f"Exception stopping the process: {e}") def percent_complete(self): return 0 def _parse_stdout(self, line): pass def elapsed_time(self): elapsed = "" if self.start_time: if self.end_time: elapsed = self.end_time - self.start_time elif self.is_running(): elapsed = datetime.now() - self.start_time return elapsed class RenderWorkerFactory: @staticmethod def create_worker(renderer, input_path, output_path, args=None): from utilities.blender_worker import BlenderRenderWorker from utilities.aerender_worker import AERenderWorker from utilities.ffmpeg_worker import FFMPEGRenderWorker if "blender" == renderer.lower(): worker = BlenderRenderWorker(input_path, output_path, args=args) elif "aerender" == renderer.lower() or "after effects" == renderer.lower(): worker = AERenderWorker(input_path, output_path, args=args) elif "ffmpeg" == renderer.lower(): worker = FFMPEGRenderWorker(input_path, output_path, args=args) else: raise ValueError(f"Cannot find renderer for type '{renderer}'") return worker @staticmethod def supported_renderers(): return ['aerender', 'blender', 'ffmpeg'] def timecode_to_frames(timecode, frame_rate): e = [int(x) for x in timecode.split(':')] seconds = (((e[0] * 60) + e[1] * 60) + e[2]) frames = (seconds * frame_rate) + e[-1] + 1 return frames