Remove Old Multi-Client Code / Refactoring (#13)

* Remove a lot of old code from render_queue regarding clients

* More code cleanup

* More code cleanup

* Move everything around

* Minor log change
This commit is contained in:
2023-06-11 14:50:20 -05:00
committed by GitHub
parent 86a1dae5b6
commit 94bb1e4362
22 changed files with 66 additions and 210 deletions

0
lib/workers/__init__.py Normal file
View File

View File

@@ -0,0 +1,133 @@
#!/usr/bin/env python3
import glob
import json
import re
import time
from .base_worker import *
from ..engines.aerender_engine import AERender
def aerender_path():
paths = glob.glob('/Applications/*After Effects*/aerender')
if len(paths) > 1:
logging.warning('Multiple After Effects installations detected')
elif not paths:
logging.error('After Effects installation not found')
else:
return paths[0]
class AERenderWorker(BaseRenderWorker):
supported_extensions = ['.aep']
engine = AERender
def __init__(self, input_path, output_path, priority=2, args=None, owner=None,
client=None, name=None):
super(AERenderWorker, self).__init__(input_path=input_path, output_path=output_path, args=args,
client=client, priority=priority, owner=owner, name=name)
self.comp = args.get('comp', None)
self.render_settings = args.get('render_settings', None)
self.omsettings = args.get('omsettings', None)
self.progress = 0
self.progress_history = []
self.attributes = {}
def generate_worker_subprocess(self):
if os.path.exists('nexrender-cli-macos'):
logging.info('nexrender found')
# {
# "template": {
# "src": String,
# "composition": String,
#
# "frameStart": Number,
# "frameEnd": Number,
# "frameIncrement": Number,
#
# "continueOnMissing": Boolean,
# "settingsTemplate": String,
# "outputModule": String,
# "outputExt": String,
# },
# "assets": [],
# "actions": {
# "prerender": [],
# "postrender": [],
# },
# "onChange": Function,
# "onRenderProgress": Function
# }
job = {'template':
{
'src': 'file://' + self.input_path, 'composition': self.comp.replace('"', ''),
'settingsTemplate': self.render_settings.replace('"', ''),
'outputModule': self.omsettings.replace('"', ''), 'outputExt': 'mov'}
}
x = ['./nexrender-cli-macos', "'{}'".format(json.dumps(job))]
else:
logging.info('nexrender not found')
x = [aerender_path(), '-project', self.input_path, '-comp', self.comp, '-RStemplate', self.render_settings,
'-OMtemplate', self.omsettings, '-output', self.output_path]
return x
def _parse_stdout(self, line):
# print line
if line.startswith('PROGRESS:'):
# print 'progress'
trimmed = line.replace('PROGRESS:', '').strip()
if len(trimmed):
self.progress_history.append(line)
if 'Seconds' in trimmed:
self._update_progress(line)
elif ': ' in trimmed:
tmp = trimmed.split(': ')
self.attributes[tmp[0].strip()] = tmp[1].strip()
elif line.startswith('WARNING:'):
trimmed = line.replace('WARNING:', '').strip()
self.warnings.append(trimmed)
logging.warning(trimmed)
elif line.startswith('aerender ERROR') or 'ERROR:' in line:
self.log_error(line)
def _update_progress(self, line):
if not self.total_frames:
duration_string = self.attributes.get('Duration', None)
frame_rate = self.attributes.get('Frame Rate', '0').split(' ')[0]
self.total_frames = timecode_to_frames(duration_string.split('Duration:')[-1], float(frame_rate))
match = re.match(r'PROGRESS:.*\((?P<frame>\d+)\): (?P<time>\d+)', line).groupdict()
self.last_frame = match['frame']
def average_frame_duration(self):
total_durations = 0
for line in self.progress_history:
match = re.match(r'PROGRESS:.*\((?P<frame>\d+)\): (?P<time>\d+)', line)
if match:
total_durations += int(match.group(2))
average = float(total_durations) / self.last_frame
return average
def percent_complete(self):
if self.total_frames:
return (float(self.last_frame) / float(self.total_frames)) * 100
else:
return 0
if __name__ == '__main__':
logging.basicConfig(format='%(asctime)s - %(message)s', datefmt='%d-%b-%y %H:%M:%S', level=logging.DEBUG)
r = AERenderWorker('/Users/brett/Desktop/Youtube_Vids/Film_Formats/Frame_Animations.aep', '"Film Pan"',
'"Draft Settings"', '"ProRes"', '/Users/brett/Desktop/test_render')
r.start()
while r.is_running():
time.sleep(0.1)

323
lib/workers/base_worker.py Normal file
View File

@@ -0,0 +1,323 @@
#!/usr/bin/env python3
import io
import logging
import os
import subprocess
import threading
import json
import glob
from datetime import datetime
from enum import Enum
from sqlalchemy import Column, Integer, String, DateTime
from sqlalchemy.ext.declarative import declarative_base
from lib.utilities.misc_helper import get_time_elapsed
import psutil
logger = logging.getLogger()
Base = declarative_base()
class RenderStatus(Enum):
NOT_STARTED = "not_started"
RUNNING = "running"
COMPLETED = "completed"
CANCELLED = "cancelled"
ERROR = "error"
SCHEDULED = "scheduled"
UNDEFINED = "undefined"
def string_to_status(string):
for stat in RenderStatus:
if stat.value == string:
return stat
return RenderStatus.UNDEFINED
class BaseRenderWorker(Base):
__tablename__ = 'render_workers'
id = Column(String, primary_key=True)
input_path = Column(String)
output_path = Column(String)
date_created = Column(DateTime)
start_time = Column(DateTime, nullable=True)
end_time = Column(DateTime, nullable=True)
renderer = Column(String)
renderer_version = Column(String)
priority = Column(Integer)
total_frames = Column(Integer)
owner = Column(String)
client = Column(String)
name = Column(String)
file_hash = Column(String)
_status = Column(String)
engine = None
def __init__(self, input_path, output_path, priority=2, args=None, ignore_extensions=True, owner=None, client=None,
name=None):
if not ignore_extensions:
if not any(ext in input_path for ext in self.engine.supported_extensions):
err_meg = f'Cannot find valid project with supported file extension for {self.engine.name()} renderer'
logger.error(err_meg)
raise ValueError(err_meg)
if not self.engine:
raise NotImplementedError("Engine not defined")
def generate_id():
import uuid
return str(uuid.uuid4()).split('-')[0]
# Essential Info
self.id = generate_id()
self.input_path = input_path
self.output_path = output_path
self.args = args or {}
self.date_created = datetime.now()
self.renderer = self.engine.name()
self.renderer_version = self.engine.version()
self.priority = priority
self.owner = owner
self.client = client
self.name = name
# Frame Ranges
self.total_frames = 0
self.current_frame = 0
# Logging
self.start_time = None
self.end_time = 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
@property
def status(self):
return self._status
@status.setter
def status(self, value):
self._status = value.value
@status.getter
def status(self):
if self._status in [RenderStatus.RUNNING.value, RenderStatus.NOT_STARTED.value]:
if not hasattr(self, 'errors'):
return RenderStatus.CANCELLED
return string_to_status(self._status)
def validate(self):
if not os.path.exists(self.input_path):
raise FileNotFoundError(f"Cannot find input path: {self.input_path}")
self.generate_subprocess()
def generate_subprocess(self):
# Convert raw args from string if available and catch conflicts
generated_args = self.generate_worker_subprocess()
generated_args_flags = [x for x in generated_args if x.startswith('-')]
if len(generated_args_flags) != len(set(generated_args_flags)):
msg = "Cannot generate subprocess - Multiple arg conflicts detected"
logger.error(msg)
logger.debug(f"Generated args for subprocess: {generated_args}")
raise ValueError(msg)
return generated_args
def get_raw_args(self):
raw_args_string = self.args.get('raw', None)
raw_args = None
if raw_args_string:
import shlex
raw_args = shlex.split(raw_args_string)
return raw_args
def generate_worker_subprocess(self):
raise NotImplementedError("generate_worker_subprocess not implemented")
def log_path(self):
filename = (self.name or os.path.basename(self.input_path)) + '_' + \
self.date_created.strftime("%Y.%m.%d_%H.%M.%S") + '.log'
return os.path.join(os.path.dirname(self.input_path), filename)
def start(self):
if self.status not in [RenderStatus.SCHEDULED, RenderStatus.NOT_STARTED]:
logger.error(f"Trying to start job with status: {self.status}")
return
if not os.path.exists(self.input_path):
self.status = RenderStatus.ERROR
msg = 'Cannot find input path: {}'.format(self.input_path)
logger.error(msg)
self.errors.append(msg)
return
if not self.engine.renderer_path():
self.status = RenderStatus.ERROR
msg = 'Cannot find render engine path for {}'.format(self.engine.name())
logger.error(msg)
self.errors.append(msg)
return
self.status = RenderStatus.RUNNING
logger.info(f'Starting {self.engine.name()} {self.engine.version()} Render for {self.input_path}')
self.__thread.start()
def run(self):
# Setup logging
log_dir = os.path.dirname(self.log_path())
os.makedirs(log_dir, exist_ok=True)
while self.failed_attempts < self.maximum_attempts and self.status is not RenderStatus.COMPLETED:
if self.failed_attempts:
logger.info(f'Attempt #{self.failed_attempts} failed. Starting attempt #{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(f"{self.start_time.isoformat()} - Starting {self.engine.name()} {self.engine.version()} "
f"Render for {self.input_path}")
f.write(f"Running command: {' '.join(subprocess_cmds)}\n")
for c in io.TextIOWrapper(self.__process.stdout, encoding="utf-8"): # or another encoding
f.write(c)
logger.debug(f"{self.engine.name()}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 in [RenderStatus.CANCELLED, RenderStatus.ERROR]:
self.is_finished = True
return
if return_code:
message = f"{self.engine.name()} render failed with return_code {return_code} after {self.time_elapsed()}"
logger.error(message)
self.failed_attempts = self.failed_attempts + 1
else:
message = f"{self.engine.name()} render completed successfully in {self.time_elapsed()}"
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.engine.name(), self.input_path,
self.failed_attempts))
self.status = RenderStatus.ERROR
if not self.errors:
self.errors = [self.last_output]
self.is_finished = True
self.post_processing()
def post_processing(self):
pass
def is_running(self):
if self.__thread:
return self.__thread.is_alive()
return False
def log_error(self, error_line, halt_render=False):
logger.error(error_line)
self.errors.append(error_line)
if halt_render:
self.stop(is_error=True)
def stop(self, is_error=False):
if hasattr(self, '__process'):
try:
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.debug(f"Error stopping the process: {e}")
if self.status in [RenderStatus.RUNNING, RenderStatus.NOT_STARTED, RenderStatus.SCHEDULED]:
if is_error:
err_message = self.errors[-1] if self.errors else 'Unknown error'
logger.error(f"Halting render due to error: {err_message}")
self.status = RenderStatus.ERROR
else:
self.status = RenderStatus.CANCELLED
def percent_complete(self):
return 0
def _parse_stdout(self, line):
raise NotImplementedError("_parse_stdout not implemented")
def time_elapsed(self):
return get_time_elapsed(self.start_time, self.end_time)
def file_list(self):
job_dir = os.path.dirname(self.output_path)
file_list = glob.glob(os.path.join(job_dir, '*'))
file_list.sort()
return file_list
def json(self):
job_dict = {
'id': self.id,
'name': self.name,
'input_path': self.input_path,
'output_path': self.output_path,
'priority': self.priority,
'owner': self.owner,
'client': self.client,
'date_created': self.date_created,
'start_time': self.start_time,
'end_time': self.end_time,
'status': self.status.value,
'file_hash': self.file_hash,
'percent_complete': self.percent_complete(),
'file_count': len(self.file_list()),
'renderer': self.renderer,
'renderer_version': self.renderer_version,
'errors': getattr(self, 'errors', None),
'total_frames': self.total_frames,
'last_output': getattr(self, 'last_output', None),
'log_path': self.log_path()
}
# convert to json and back to auto-convert dates to iso format
def date_serializer(o):
if isinstance(o, datetime):
return o.isoformat()
json_convert = json.dumps(job_dict, default=date_serializer)
worker_json = json.loads(json_convert)
return worker_json
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

View File

@@ -0,0 +1,149 @@
#!/usr/bin/env python3
import json
import re
try:
from .base_worker import *
except ImportError:
from base_worker import *
from ..engines.blender_engine import Blender
class BlenderRenderWorker(BaseRenderWorker):
engine = Blender
def __init__(self, input_path, output_path, priority=2, args=None, owner=None,
client=None, name=None):
super(BlenderRenderWorker, self).__init__(input_path=input_path, output_path=output_path, args=args,
client=client, priority=priority, owner=owner, name=name)
# Args
self.blender_engine = self.args.get('engine', 'BLENDER_EEVEE').upper()
self.export_format = self.args.get('export_format', None) or 'JPEG'
self.camera = self.args.get('camera', None)
self.render_all_frames = self.args.get('render_all_frames', False) or \
'-a' in (self.args.get('raw', None) or "").split(' ')
# Stats
self.__frame_percent_complete = 0.0
# Scene Info
self.scene_info = Blender.get_scene_info(input_path)
self.total_frames = (int(self.scene_info.get('frame_end', 1)) - int(self.scene_info.get('frame_start', 1)) + 1) \
if self.render_all_frames else 1
self.current_frame = int(self.scene_info.get('frame_start', 1))
def generate_worker_subprocess(self):
cmd = [self.engine.renderer_path()]
if self.args.get('background', True): # optionally run render not in background
cmd.append('-b')
cmd.append(self.input_path)
if self.camera:
cmd.extend(['--python-expr', f"import bpy;bpy.context.scene.camera = bpy.data.objects['{self.camera}'];"])
cmd.extend(['-E', self.blender_engine, '-o', self.output_path, '-F', self.export_format])
# all frames or single
cmd.extend(['-a'] if self.render_all_frames else ['-f', str(self.current_frame)])
# Convert raw args from string if available
raw_args = self.get_raw_args()
if raw_args:
cmd.extend(raw_args)
return cmd
def _parse_stdout(self, line):
pattern = re.compile(
r'Fra:(?P<frame>\d*).*Mem:(?P<memory>\S+).*Time:(?P<time>\S+)(?:.*Remaining:)?(?P<remaining>\S*)')
found = pattern.search(line)
if found:
stats = found.groupdict()
memory_use = stats['memory']
time_elapsed = stats['time']
time_remaining = stats['remaining'] or 'Unknown'
sample_string = line.split('|')[-1].strip()
if "sample" in sample_string.lower():
samples = re.sub(r'[^\d/]', '', sample_string)
self.__frame_percent_complete = int(samples.split('/')[0]) / int(samples.split('/')[-1])
# Calculate rough percent based on cycles
# EEVEE
# 10-Apr-22 22:42:06 - RENDERER: Fra:0 Mem:857.99M (Peak 928.55M) | Time:00:03.96 | Rendering 1 / 65 samples
# 10-Apr-22 22:42:10 - RENDERER: Fra:0 Mem:827.09M (Peak 928.55M) | Time:00:07.92 | Rendering 26 / 64 samples
# 10-Apr-22 22:42:10 - RENDERER: Fra:0 Mem:827.09M (Peak 928.55M) | Time:00:08.17 | Rendering 51 / 64 samples
# 10-Apr-22 22:42:10 - RENDERER: Fra:0 Mem:827.09M (Peak 928.55M) | Time:00:08.31 | Rendering 64 / 64 samples
# CYCLES
# 10-Apr-22 22:43:22 - RENDERER: Fra:0 Mem:836.30M (Peak 1726.13M) | Time:00:01.56 | Remaining:00:30.65 | Mem:588.68M, Peak:588.68M | Scene, View Layer | Sample 1/150
# 10-Apr-22 22:43:43 - RENDERER: Fra:0 Mem:836.30M (Peak 1726.13M) | Time:00:22.01 | Remaining:00:03.36 | Mem:588.68M, Peak:588.68M | Scene, View Layer | Sample 129/150
if int(stats['frame']) > self.current_frame:
self.current_frame = int(stats['frame'])
logger.debug(
'Frame:{0} | Mem:{1} | Time:{2} | Remaining:{3}'.format(self.current_frame, memory_use,
time_elapsed, time_remaining))
elif "file doesn't exist" in line.lower():
self.log_error(line, halt_render=True)
elif line.lower().startswith('error'):
self.log_error(line)
elif 'Saved' in line or 'Saving' in line or 'quit' in line:
match = re.match(r'Time: (.*) \(Saving', line)
if match:
time_completed = match.groups()[0]
if self.render_all_frames:
logger.debug(f'Frame {self.current_frame} completed in {time_completed}')
else:
logger.info(f'Render completed in {time_completed}')
else:
logger.debug(line)
else:
pass
# if len(line.strip()):
# logger.debug(line.strip())
def percent_complete(self):
if self.total_frames <= 1:
return self.__frame_percent_complete
else:
whole_frame_percent = (self.current_frame - 1) / self.total_frames
adjusted_frame_percent = self.__frame_percent_complete / self.total_frames
total_percent = whole_frame_percent + adjusted_frame_percent
return max(total_percent, 0)
def post_processing(self):
output_dir = os.listdir(os.path.dirname(self.output_path))
if self.render_all_frames and len(output_dir) > 1:
from ..utilities.ffmpeg_helper import image_sequence_to_video
logger.info("Generating preview for image sequence")
# get proper file extension
found_output = next(obj for obj in output_dir if os.path.basename(self.output_path) in obj)
glob_pattern = self.output_path + '%04d' + ('.' + found_output.split('.')[-1] if found_output else "")
try:
image_sequence_to_video(source_glob_pattern=glob_pattern,
output_path=self.output_path + '.mp4',
framerate=self.scene_info['fps'])
logger.info('Successfully generated preview video from image sequence')
except Exception as e:
logger.error(f'Error generating video from image sequence: {e}')
if __name__ == '__main__':
import pprint
x = Blender.get_scene_info('/Users/brett/Desktop/TC Previz/nallie_farm.blend')
pprint.pprint(x)
# logging.basicConfig(format='%(asctime)s - %(message)s', datefmt='%d-%b-%y %H:%M:%S', level=logging.DEBUG)
# r = BlenderRenderWorker('/Users/brett/Blender Files/temple_animatic.blend', '/Users/brett/testing1234')
# # r.engine = 'CYCLES'
# r.start()
# while r.is_running():
# time.sleep(1)

View File

@@ -0,0 +1,69 @@
#!/usr/bin/env python3
import re
from .base_worker import *
from ..engines.ffmpeg_engine import FFMPEG
class FFMPEGRenderWorker(BaseRenderWorker):
engine = FFMPEG
def __init__(self, input_path, output_path, priority=2, args=None, owner=None,
client=None, name=None):
super(FFMPEGRenderWorker, self).__init__(input_path=input_path, output_path=output_path, args=args,
client=client, priority=priority, owner=owner, name=name)
stream_info = subprocess.check_output([self.engine.renderer_path(), "-i", # https://stackoverflow.com/a/61604105
input_path, "-map", "0:v:0", "-c", "copy", "-f", "null", "-y",
"/dev/null"], stderr=subprocess.STDOUT).decode('utf-8')
found_frames = re.findall('frame=\s*(\d+)', stream_info)
self.total_frames = found_frames[-1] if found_frames else '-1'
self.frame = 0
# Stats
self.current_frame = -1
def generate_worker_subprocess(self):
cmd = [self.engine.renderer_path(), '-y', '-stats', '-i', self.input_path]
# Resize frame
if self.args.get('x_resolution', None) and self.args.get('y_resolution', None):
cmd.extend(['-vf', f"scale={self.args['x_resolution']}:{self.args['y_resolution']}"])
# Convert raw args from string if available
raw_args = self.args.get('raw', None)
if raw_args:
cmd.extend(raw_args.split(' '))
# Close with output path
cmd.append(self.output_path)
return cmd
def percent_complete(self):
return max(float(self.current_frame) / float(self.total_frames), 0.0)
def _parse_stdout(self, line):
pattern = re.compile(r'frame=\s*(?P<current_frame>\d+)\s*fps.*time=(?P<time_elapsed>\S+)')
found = pattern.search(line)
if found:
stats = found.groupdict()
self.current_frame = stats['current_frame']
time_elapsed = stats['time_elapsed']
elif "not found" in line:
self.log_error(line)
if __name__ == '__main__':
print(FFMPEG.full_report())
# logging.basicConfig(format='%(asctime)s - %(message)s', datefmt='%d-%b-%y %H:%M:%S', level=logging.DEBUG)
#
# test_movie = '/Users/brettwilliams/Desktop/dark_knight_rises.mp4'
#
# r = FFMPEGRenderWorker(test_movie, '/Users/brettwilliams/Desktop/test-ffmpeg.mp4', args=['-c:v', 'libx265', '-vtag', 'hvc1'])
# # r = FFMPEGRenderer(test_movie, '/Users/brettwilliams/Desktop/dark_knight_rises-output.mp4')
# r.start()
# while r.is_running():
# time.sleep(1)

View File

@@ -0,0 +1,29 @@
class RenderWorkerFactory:
@staticmethod
def supported_classes():
# to add support for any additional RenderWorker classes, import their classes and add to list here
from .blender_worker import BlenderRenderWorker
from .aerender_worker import AERenderWorker
from .ffmpeg_worker import FFMPEGRenderWorker
classes = [BlenderRenderWorker, AERenderWorker, FFMPEGRenderWorker]
return classes
@staticmethod
def create_worker(renderer, input_path, output_path, priority=2, args=None, owner=None,
client=None, name=None):
worker_class = RenderWorkerFactory.class_for_name(renderer)
return worker_class(input_path=input_path, output_path=output_path, args=args, priority=priority, owner=owner,
client=client, name=name)
@staticmethod
def supported_renderers():
return [x.engine.name() for x in RenderWorkerFactory.supported_classes()]
@staticmethod
def class_for_name(name):
name = name.lower()
for render_class in RenderWorkerFactory.supported_classes():
if render_class.engine.name() == name:
return render_class
raise LookupError(f'Cannot find class for name: {name}')