Zordon/src/engines/blender/blender_worker.py

#!/usr/bin/env python3
import re
from collections import Counter

from src.engines.blender.blender_engine import Blender
from src.utilities.ffmpeg_helper import image_sequence_to_video
from src.engines.core.base_worker import *


class BlenderRenderWorker(BaseRenderWorker):

    engine = Blender

    def __init__(self, input_path, output_path, engine_path, args=None, parent=None, name=None):
        super(BlenderRenderWorker, self).__init__(input_path=input_path, output_path=output_path, engine_path=engine_path, args=args, parent=parent, name=name)

        # Stats
        self.__frame_percent_complete = 0.0

        # Scene Info
        self.scene_info = Blender(engine_path).get_project_info(input_path)
        self.start_frame = int(self.scene_info.get('start_frame', 1))
        self.end_frame = int(self.scene_info.get('end_frame', self.start_frame))
        self.project_length = (self.end_frame - self.start_frame) + 1
        self.current_frame = -1

    def generate_worker_subprocess(self):

        cmd = [self.renderer_path]
        if self.args.get('background', True):  # optionally run render not in background
            cmd.append('-b')
        cmd.append(self.input_path)

        # Start Python expressions - # todo: investigate splitting into separate 'setup' script
        cmd.append('--python-expr')
        python_exp = 'import bpy; bpy.context.scene.render.use_overwrite = False;'

        # Setup Custom Camera
        custom_camera = self.args.get('camera', None)
        if custom_camera:
            python_exp = python_exp + f"bpy.context.scene.camera = bpy.data.objects['{custom_camera}'];"

        # Set Render Device (gpu/cpu/any)
        blender_engine = self.args.get('engine', 'BLENDER_EEVEE').upper()
        if blender_engine == 'CYCLES':
            render_device = self.args.get('render_device', 'any').lower()
            if render_device not in {'any', 'gpu', 'cpu'}:
                raise AttributeError(f"Invalid Cycles render device: {render_device}")

            use_gpu = render_device in {'any', 'gpu'}
            use_cpu = render_device in {'any', 'cpu'}

            python_exp = python_exp + ("exec(\"for device in bpy.context.preferences.addons["
                                       f"'cycles'].preferences.devices: device.use = {use_cpu} if device.type == 'CPU'"
                                       f" else {use_gpu}\")")

        # -- insert any other python exp checks / generators here --

        # End Python expressions here
        cmd.append(python_exp)

        # Export format
        export_format = self.args.get('export_format', None) or 'JPEG'

        main_part, ext = os.path.splitext(self.output_path)
        # Remove the extension only if it is not composed entirely of digits
        path_without_ext = main_part if not ext[1:].isdigit() else self.output_path
        path_without_ext += "_"
        cmd.extend(['-E', blender_engine, '-o', path_without_ext, '-F', export_format])

        # set frame range
        cmd.extend(['-s', self.start_frame, '-e', self.end_frame, '-a'])

        # 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])

            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:
            render_stats_match = re.match(r'Time: (.*) \(Saving', line)
            output_filename_match = re.match(r"Saved: .*_(\d+)\.\w+", line)  # try to get frame # from filename
            if output_filename_match:
                output_file_number = output_filename_match.groups()[0]
                try:
                    self.current_frame = int(output_file_number)
                except ValueError:
                    pass
            elif render_stats_match:
                time_completed = render_stats_match.groups()[0]
                frame_count = self.current_frame - self.end_frame + self.total_frames
                logger.info(f'Frame #{self.current_frame} - '
                            f'{frame_count} of {self.total_frames} completed in {time_completed} | '
                            f'Total Elapsed Time: {datetime.now() - self.start_time}')
            else:
                logger.debug(f'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 - self.start_frame) / 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):

        def most_common_extension(file_paths):
            extensions = [os.path.splitext(path)[1] for path in file_paths]
            counter = Counter(extensions)
            most_common_ext, _ = counter.most_common(1)[0]
            return most_common_ext

        output_dir_files = os.listdir(os.path.dirname(self.output_path))
        if self.total_frames > 1 and len(output_dir_files) > 1 and not self.parent:
            logger.info("Generating preview for image sequence")

            # Calculate what the real start frame # is if we have child objects
            start_frame = self.start_frame
            if self.children:
                min_child_frame = min(int(child["start_frame"]) for child in self.children.values())
                start_frame = min(min_child_frame, self.start_frame)
                logger.debug(f"Post processing start frame #{start_frame}")

            try:
                pattern = os.path.splitext(self.output_path)[0] + "_%04d" + most_common_extension(output_dir_files)
                image_sequence_to_video(source_glob_pattern=pattern,
                                        output_path=self.output_path + '.mov',
                                        framerate=self.scene_info['fps'],
                                        start_frame=start_frame)
                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_project_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)