sheepit-shadow-nabber/src/main/java/com/sheepit/client/rendering/Job.java

/*
 * Copyright (C) 2010-2014 Laurent CLOUET
 * Author Laurent CLOUET <laurent.clouet@nopnop.net>
 *
 * This program is free software; you can redistribute it and/or
 * modify it under the terms of the GNU General Public License
 * as published by the Free Software Foundation; version 2
 * of the License.
 *
 * This program is distributed in the hope that it will be useful,
 * but WITHOUT ANY WARRANTY; without even the implied warranty of
 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
 * GNU General Public License for more details.
 *
 * You should have received a copy of the GNU General Public License
 * along with this program; if not, write to the Free Software
 * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA  02110-1301, USA.
 */

package com.sheepit.client.rendering;

import com.sheepit.client.logger.Log;
import com.sheepit.client.config.Configuration;
import com.sheepit.client.config.Configuration.ComputeType;
import com.sheepit.client.config.DirectoryManager;
import com.sheepit.client.datamodel.client.Error;
import com.sheepit.client.datamodel.client.Error.Type;
import com.sheepit.client.network.DownloadItem;
import com.sheepit.client.os.OS;
import com.sheepit.client.ui.Gui;
import com.sheepit.client.utils.Utils;
import lombok.Data;
import lombok.Getter;

import java.io.BufferedReader;
import java.io.File;
import java.io.FileWriter;
import java.io.FilenameFilter;
import java.io.IOException;
import java.io.InputStreamReader;
import java.io.PrintWriter;
import java.io.StringWriter;
import java.text.DateFormat;
import java.text.ParseException;
import java.text.SimpleDateFormat;
import java.time.Duration;
import java.time.Instant;
import java.time.LocalTime;
import java.util.ArrayList;
import java.util.Arrays;
import java.util.Date;
import java.util.HashMap;
import java.util.List;
import java.util.Map;
import java.util.Observable;
import java.util.Observer;
import java.util.Optional;
import java.util.TimeZone;
import java.util.Timer;
import java.util.TimerTask;
import java.util.regex.Matcher;
import java.util.regex.Pattern;

import static com.sheepit.client.rendering.RenderSettings.UPDATE_METHOD_BY_REMAINING_TIME;
import static com.sheepit.client.rendering.RenderSettings.UPDATE_METHOD_BY_TILE;

@Data public class Job {
	public static final String POST_LOAD_NOTIFICATION = "POST_LOAD_SCRIPT_loaded";
	
	public static final int SHOW_BASE_ICON = -1;
	
	private DownloadItem projectDownload;
	private DownloadItem rendererDownload;
	private String id;
	private String validationUrl;
	private String name;
	private char[] password;
	
	private boolean synchronousUpload;
	
	private RenderSettings renderSettings;
	@Getter private RenderProcess renderProcess;
	private RenderOutput renderOutput;
	private RenderState renderState;

	private Gui gui;
	private Configuration configuration;
	private Log log;
	
	private DirectoryManager directoryManager;
	
	public Job(Configuration config_, Gui gui_, Log log_, String id_, String frame_, String path_, boolean use_gpu, String command_, String validationUrl_,
			String script_, DownloadItem projectDownload_, DownloadItem rendererDownload_, String name_, char[] password_, boolean synchronous_upload_,
			String update_method_) {
		configuration = config_;
		id = id_;
		renderSettings = new RenderSettings(frame_, script_, path_, command_, use_gpu, update_method_);
		validationUrl = validationUrl_;
		projectDownload = projectDownload_;
		rendererDownload = rendererDownload_;
		name = name_;
		password = password_.clone();
		synchronousUpload = synchronous_upload_;
		gui = gui_;
		log = log_;
		directoryManager = new DirectoryManager(configuration);
		renderProcess = new RenderProcess(log_);
		renderState = new RenderState();
		renderOutput = new RenderOutput();
	}
	
	public void block() {
		renderState.setBlock();

		RenderProcess process = getRenderProcess();
		if (process != null) {
			process.kill();
		}
	}
	
	public void incompatibleProcessBlock() {
		renderState.setBlockIncompatibleProcess();
		RenderProcess process = getRenderProcess();
		if (process != null) {
			process.kill();
		}
	}
	
	@Override
	public String toString() {
		return String
				.format("Job (numFrame '%s' archiveChunks %s rendererMD5 '%s' ID '%s' pictureFilename '%s' jobPath '%s' gpu %s name '%s' updateRenderingStatusMethod '%s' render %s)",
						getRenderSettings().getFrameNumber(), projectDownload.getMD5(), rendererDownload.getMD5(), id, getRenderOutput().getFullImagePath(),
					getRenderSettings().getPath(), getRenderSettings().isUseGPU(), name, getRenderSettings().getUpdateRenderingStatusMethod(), renderProcess);
	}
	
	public String getPrefixOutputImage() {
		return id + "_";
	}
	
	public String getRendererDirectory() {
		return configuration.getWorkingDirectory().getAbsolutePath() + File.separator + rendererDownload.getMD5();
	}
	
	public String getRendererPath() {
		return getRendererDirectory() + File.separator + OS.getOS().getRenderBinaryPath();
	}
	
	public String getSceneDirectory() {
		return configuration.getWorkingDirectory().getAbsolutePath() + File.separator + this.id;
	}
	
	public String getScenePath() {
		return getSceneDirectory() + File.separator + getRenderSettings().getPath();
	}
	
	public Error.Type render(Observer renderStarted) {
		gui.status("Rendering");
		RenderProcess process = getRenderProcess();
		Timer timerOfMaxRenderTime = null;
		String core_script;
		// When sending Ctrl+C to the terminal it also get's sent to all subprocesses e.g. also the render process.
		// The java program handles Ctrl+C but the renderer quits on Ctrl+C.
		// This script causes the renderer to ignore Ctrl+C.
		String ignore_signal_script = "import signal\n" + "def hndl(signum, frame):\n" + "    pass\n" + "signal.signal(signal.SIGINT, hndl)\n";
		if (getRenderSettings().isUseGPU() && configuration.getGPUDevice() != null && configuration.getComputeMethod() != ComputeType.CPU) {
			core_script = "sheepit_set_compute_device(\"" + configuration.getGPUDevice().getType() + "\", \"GPU\", \"" + configuration.getGPUDevice().getId()
					+ "\")\n";
			gui.setComputeMethod("GPU");
		}
		else {
			// Otherwise (CPU), fix the tile size to 32x32px
			core_script = "sheepit_set_compute_device(\"NONE\", \"CPU\", \"CPU\")\n";
			gui.setComputeMethod("CPU");
		}
		
		core_script += ignore_signal_script;
		File disableViewportScript = null;
		File script_file = null;
		String[] command1 = getRenderSettings().getCommand().split(" ");
		int size_command = command1.length + 2; // + 2 for script
		
		if (configuration.getNbCores() > 0) { // user has specified something
			size_command += 2;
		}
		
		List<String> command = new ArrayList<>(size_command);
		
		Map<String, String> new_env = new HashMap<>();
		
		//make sure the system doesn´t interfere with the blender runtime, and that blender doesn´t attempt to load external libraries/scripts.
		new_env.put("BLENDER_USER_RESOURCES", "");
		new_env.put("BLENDER_USER_CONFIG", "");
		new_env.put("BLENDER_USER_EXTENSIONS", "");
		new_env.put("BLENDER_USER_SCRIPTS", "");
		new_env.put("BLENDER_USER_DATAFILES", "");

		new_env.put("BLENDER_SYSTEM_RESOURCES", "");
		new_env.put("BLENDER_SYSTEM_SCRIPTS", "");
		new_env.put("BLENDER_SYSTEM_DATAFILES", "");
		new_env.put("BLENDER_SYSTEM_PYTHON", "");

		new_env.put("OCIO", ""); //prevent blender from loading a non-standard color configuration
		new_env.put("TEMP", configuration.getWorkingDirectory().getAbsolutePath().replace("\\", "\\\\"));
		new_env.put("TMP", configuration.getWorkingDirectory().getAbsolutePath().replace("\\", "\\\\"));
		
		new_env.put("CORES", Integer.toString(configuration.getNbCores()));
		new_env.put("PRIORITY", Integer.toString(configuration.getPriority()));

		// Add own lib folder first, because Steam or other environments may set an LD_LIBRARY_PATH that has priority over the runpath in the Blender excutable,
		// but contains incompatible libraries.
		String currentLDLibraryPath = Optional.ofNullable(System.getenv("LD_LIBRARY_PATH")).orElse("");
		new_env.put("LD_LIBRARY_PATH", getRendererDirectory() + "/lib" + ":" + currentLDLibraryPath);
		
		for (String arg : command1) {
			switch (arg) {
				case ".c":
					command.add("-P");
					
					try {
						disableViewportScript = File.createTempFile("pre_load_script_", ".py", configuration.getWorkingDirectory());
						File file = new File(disableViewportScript.getAbsolutePath());
						FileWriter fwriter;
						fwriter = new FileWriter(file);
						
						PrintWriter out = new PrintWriter(fwriter);
						out.write("import bpy");
						out.write("\n");
						out.write("import sys");
						out.write("\n");
						out.write("from bpy.app.handlers import persistent");
						out.write("\n");
						out.write("@persistent");
						out.write("\n");
						out.write("def hide_stuff(hide_dummy):");
						out.write("\n");
						out.write("	print('PRE_LOAD_SCRIPT_hide_viewport')");
						out.write("\n");
						out.write("	#Hide collections in the viewport");
						out.write("\n");
						out.write("	for col in bpy.data.collections:");
						out.write("\n");
						out.write("		col.hide_viewport = True");
						out.write("\n");
						out.write("	for obj in bpy.data.objects:");
						out.write("\n");
						out.write("		#Hide objects in the viewport");
						out.write("\n");
						out.write("		#obj.hide_viewport = True");
						out.write("\n");
						out.write("		#Hide modifier in the viewport");
						out.write("\n");
						out.write("		for mod in obj.modifiers:");
						out.write("\n");
						out.write("			mod.show_viewport = False");
						out.write("\n");
						out.write("	sys.stdout.flush()");
						out.write("\n");
						out.write("bpy.app.handlers.version_update.append(hide_stuff)");
						out.write("\n");
						out.close();
						
						command.add(disableViewportScript.getAbsolutePath());
					}
					catch (IOException e) {
						StringWriter sw = new StringWriter();
						e.printStackTrace(new PrintWriter(sw));
						for (String logline : directoryManager.filesystemHealthCheck()) {
							log.debug(logline);
						}
						log.error("Job::render exception on script generation, will return UNKNOWN " + e + " stacktrace " + sw.toString());
						return Error.Type.UNKNOWN;
					}
					
					command.add(getScenePath());
					command.add("-P");
					
					try {
						script_file = File.createTempFile("post_load_script_", ".py", configuration.getWorkingDirectory());
						File file = new File(script_file.getAbsolutePath());
						FileWriter txt;
						txt = new FileWriter(file);
						
						PrintWriter out = new PrintWriter(txt);
						out.write(getRenderSettings().getScript());
						out.write("\n");
						out.write("import sys");
						out.write("\n");
						out.write("print('" + POST_LOAD_NOTIFICATION + "')");
						out.write("\n");
						out.write("sys.stdout.flush()");
						out.write("\n");
						out.write(core_script); // GPU part
						out.write("\n"); // GPU part
						out.close();
						
						command.add(script_file.getAbsolutePath());
					}
					catch (IOException e) {
						StringWriter sw = new StringWriter();
						e.printStackTrace(new PrintWriter(sw));
						for (String logline : directoryManager.filesystemHealthCheck()) {
							log.debug(logline);
						}
						log.error("Job::render exception on script generation, will return UNKNOWN " + e + " stacktrace " + sw.toString());
						return Error.Type.UNKNOWN;
					}
					script_file.deleteOnExit();
					break;
				case ".e":
					command.add(getRendererPath());
					// the number of cores has to be put after the binary and before the scene arg
					if (configuration.getNbCores() > 0) {
						command.add("-t");
						command.add(Integer.toString(configuration.getNbCores()));
					}
					break;
				case ".o":
					command.add(configuration.getWorkingDirectory().getAbsolutePath() + File.separator + getPrefixOutputImage());
					break;
				case ".f":
					command.add(getRenderSettings().getFrameNumber());
					break;
				default:
					command.add(arg);
					break;
			}
		}
		
		Timer memoryCheck = new Timer();
		try {
			renderStartedObservable event = new renderStartedObservable(renderStarted);
			String line;
			log.debug(command.toString());
			OS os = OS.getOS();
			process.setCoresUsed(configuration.getNbCores());
			process.start();
			getRenderProcess().setProcess(os.exec(command, new_env));
			getRenderProcess().setOsProcess(OS.operatingSystem.getProcess((int) getRenderProcess().getProcess().pid()));
			BufferedReader input = new BufferedReader(new InputStreamReader(getRenderProcess().getProcess().getInputStream()));
			memoryCheck.scheduleAtFixedRate(new TimerTask() {
				@Override public void run() {
					updateProcess();
				}
			}, 0L, 200L);
			
			// Make initial test/power frames ignore the maximum render time in user configuration. Initial test frames have Job IDs below 20
			// so we just activate the user defined timeout when the scene is not one of the initial ones.
			if (configuration.getMaxRenderTime() > 0 && Integer.parseInt(this.getId()) >= 20) {
				timerOfMaxRenderTime = new Timer();
				timerOfMaxRenderTime.schedule(new TimerTask() {
					@Override public void run() {
						RenderProcess process = getRenderProcess();
						if (process != null) {
							long duration = (new Date().getTime() - process.getStartTime()) / 1000; // in seconds
							if (configuration.getMaxRenderTime() > 0 && duration > configuration.getMaxRenderTime()) {
								getRenderState().setAskForRendererKill(true);
								log.debug("Killing render - exceeding allowed process duration");
								process.kill();
							}
						}
					}
				}, configuration.getMaxRenderTime() * 1000 + 2000); // +2s to be sure the delay is over
			}
			
			
			log.debug("renderer output");
			try {
				int progress = -1;
				
				Pattern progressPattern = Pattern.compile(" (Rendered|Path Tracing Tile|Rendering|Sample) (\\d+)\\s?\\/\\s?(\\d+)( Tiles| samples|,)*");
				Pattern beginScenePrepPattern = Pattern.compile(POST_LOAD_NOTIFICATION);
				Pattern beginPostProcessingPattern = Pattern.compile("^Fra:\\d* \\w*(.)* \\| (Compositing|Denoising)");
				Pattern savingPattern = Pattern.compile("Time: \\d\\d:\\d\\d.\\d\\d \\(Saving: (\\d\\d:\\d\\d.\\d\\d)");
				int savingTimeSeconds = -1;
				Instant timeStamp = null;
				Duration phaseDuration;	//We divide the job into 3 phases: preparation, rendering, compositing
				boolean scenePrepStarted = false;
				boolean renderingStarted = false;
				boolean postProcessingStarted = false;
				
				// Initialise the progress bar in the icon and the UI (0% completed at this time)
				gui.updateTrayIcon(0);
				gui.status("Preparing project", 0);
				
				while ((line = input.readLine()) != null) {
					log.debug(line);
					
					// Process lines until the version is loaded (usually first or second line of log)
					if (getRenderOutput().getBlenderLongVersion() == null) {
						Pattern blenderPattern = Pattern.compile("Blender (([0-9]{1,3}\\.[0-9]{0,3}).*)$");
						Matcher blendDetectedVersion = blenderPattern.matcher(line);
						
						if (blendDetectedVersion.find()) {
							getRenderOutput().setBlenderLongVersion(blendDetectedVersion.group(1));
							getRenderOutput().setBlenderShortVersion(blendDetectedVersion.group(2));
						}
					}
					
					Matcher scenePrepDetector = beginScenePrepPattern.matcher(line);
					if (scenePrepStarted == false && scenePrepDetector.find()) {
						scenePrepStarted = true;
						timeStamp = Instant.now();
					}
					
					progress = computeRenderingProgress(line, progressPattern, progress);
					if (renderingStarted == false && progress != -1) {
						renderingStarted = true;
						if (timeStamp == null) {
							timeStamp = new Date(process.getStartTime()).toInstant();
						}
						phaseDuration = Duration.between(timeStamp, Instant.now());
						timeStamp = Instant.now();
						process.setScenePrepDuration((int) phaseDuration.toSeconds());
					}
					
					Matcher postProcessingDetector = beginPostProcessingPattern.matcher(line);
					if (postProcessingStarted == false && postProcessingDetector.find()) {
						postProcessingStarted = true;
						if (timeStamp == null) {
							timeStamp = new Date(process.getStartTime()).toInstant();
						}
						phaseDuration = Duration.between(timeStamp, Instant.now());
						timeStamp = Instant.now();
						process.setRenderDuration((int) phaseDuration.toSeconds());
					}
					
					Matcher savingTimeDetector = savingPattern.matcher(line);
					if (savingTimeDetector.find()) {
						String savingTime = savingTimeDetector.group(1);
						if (savingTime != null) {
							savingTimeSeconds = (int) Duration.between(LocalTime.MIN, LocalTime.parse("00:" + savingTime)).toSeconds();	//add leading hours to comply with ISO time format
						}
					}
					
					if (configuration.getMaxAllowedMemory() != -1 && getRenderProcess().getMemoryUsed().get() > configuration.getMaxAllowedMemory()) {
						log.debug("Blocking render because process ram used (" + getRenderProcess().getMemoryUsed().get() + "k) is over user setting (" + configuration
								.getMaxAllowedMemory() + "k)");
						process.finish();
						if (process.getRenderDuration() == -1) {
							if (timeStamp == null) {
								timeStamp = new Date(process.getStartTime()).toInstant();
							}
							phaseDuration = Duration.between(timeStamp, Instant.now());
							process.setRenderDuration((int) phaseDuration.toSeconds());
						}
						if (script_file != null) {
							script_file.delete();
						}
						if (disableViewportScript != null) {
							disableViewportScript.delete();
						}
						
						// Once the process is finished (either finished successfully or with an error) move back to
						// base icon (isolated S with no progress bar)
						gui.updateTrayIcon(SHOW_BASE_ICON);
						
						return Error.Type.RENDERER_OUT_OF_MEMORY;
					}
					
					updateSpeedSamplesRendered(line);
					updateRenderingStatus(line, progress);
					Type error = getRenderOutput().detectError(line);
					if (error != Error.Type.OK) {
						if (script_file != null) {
							script_file.delete();
						}
						if (disableViewportScript != null) {
							disableViewportScript.delete();
						}
						if (process.getRenderDuration() == -1) {
							if (timeStamp == null) {
								timeStamp = new Date(process.getStartTime()).toInstant();
							}
							phaseDuration = Duration.between(timeStamp, Instant.now());
							process.setRenderDuration((int) phaseDuration.toSeconds());
						}
						
						// Put back base icon
						gui.updateTrayIcon(SHOW_BASE_ICON);
						process.kill();
						maybeCleanWorkingDir(error);
						for (String logline : directoryManager.filesystemHealthCheck()) {
							log.debug(logline);
						}
						
						return error;
					}
					
					if (!event.isStarted() && (getRenderProcess().getMemoryUsed().get() > 0 && scenePrepStarted || process.getRemainingDuration() > 0)) {
						event.doNotifyIsStarted();
					}
				}
				
				if (timeStamp == null) {
					timeStamp = new Date(process.getStartTime()).toInstant();
				}
				
				if (postProcessingStarted == false) {
					phaseDuration = Duration.between(timeStamp, Instant.now());
					process.setRenderDuration((int) phaseDuration.toSeconds());
					
					//we need to subtract the time to save the frame to disk
					if (savingTimeSeconds > 0 && process.getRenderDuration() > 0) {
						process.setRenderDuration(Math.max(0, process.getRenderDuration() - savingTimeSeconds));
					}
				}
				else {
					phaseDuration = Duration.between(timeStamp, Instant.now());
					process.setPostProcessingDuration((int) phaseDuration.toSeconds());
				}
				input.close();
				
				log.debug(String.format("render times: %n\tScene prep: %ds%n\tRendering: %ds%n\tPost: %ss%n\tTotal: %ds%n\tRendering/Total: %.03f%n",
					process.getScenePrepDuration(),
					process.getRenderDuration(),
					process.getPostProcessingDuration(),
					process.getDuration(),
					(Math.max(process.getRenderDuration(), 0) * 100.0) / process.getDuration()
				));
			}
			catch (IOException err1) { // for the input.readline
				// most likely The handle is invalid
				log.error("Job::render exception(B) (silent error) " + err1);
			}
			finally {
				memoryCheck.cancel();
			}
			
			// Put back base icon
			gui.updateTrayIcon(SHOW_BASE_ICON);

			log.debug("end of rendering");
			
		}
		catch (Exception err) {
			if (script_file != null) {
				script_file.delete();
			}
			if (disableViewportScript != null) {
				disableViewportScript.delete();
			}
			StringWriter sw = new StringWriter();
			err.printStackTrace(new PrintWriter(sw));
			for (String logline : directoryManager.filesystemHealthCheck()) {
				log.debug(logline);
			}
			log.error("Job::render exception(A) " + err + " stacktrace " + sw.toString());
			return Error.Type.FAILED_TO_EXECUTE;
		}
		
		int exit_value = process.exitValue();
		process.finish();
		if (timerOfMaxRenderTime != null) {
			timerOfMaxRenderTime.cancel();
		}
		
		if (script_file != null) {
			script_file.delete();
		}
		if (disableViewportScript != null) {
			disableViewportScript.delete();
		}
		// find the picture file
		final String filename_without_extension = getPrefixOutputImage() + getRenderSettings().getFrameNumber();
		
		FilenameFilter textFilter = new FilenameFilter() {
			@Override public boolean accept(File dir, String name) {
				return name.startsWith(filename_without_extension);
			}
		};
		
		File[] files = configuration.getWorkingDirectory().listFiles(textFilter);
		
		if (getRenderState().isAskForRendererKill()) {
			log.debug("Job::render been asked to end render");
			
			long duration = (new Date().getTime() - process.getStartTime()) / 1000; // in seconds
			if (configuration.getMaxRenderTime() > 0 && duration > configuration.getMaxRenderTime() && Integer.parseInt(this.getId()) >= 20) {
				log.debug("Render killed because process duration (" + duration + "s) is over user setting (" + configuration.getMaxRenderTime() + "s)");
				return Error.Type.RENDERER_KILLED_BY_USER_OVER_TIME;
			}
			
			if (files.length != 0) {
				Arrays.stream(files).forEach( file -> new File(file.getAbsolutePath()).delete());
			}
			if (getRenderState().isServerBlock()) {
				return Error.Type.RENDERER_KILLED_BY_SERVER;
			}
			if (getRenderState().isUserBlock()) {
				return Error.Type.RENDERER_KILLED_BY_USER;
			}
			if (getRenderState().isIncompatibleProcessKill()) {
				return Error.Type.RENDERER_KILLED_BY_USER_INCOMPATIBLE_PROCESS;
			}
			return Error.Type.RENDERER_KILLED;
		}
		
		if (files.length == 0) {
			for (String logline : directoryManager.filesystemHealthCheck()) {
				log.debug(logline);
			}
			log.error("Job::render no picture file found (after finished render (filename_without_extension " + filename_without_extension + ")");
			
			String basename = "";
			try {
				basename = getRenderSettings().getPath().substring(0, getRenderSettings().getPath().lastIndexOf('.'));
			}
			catch (Exception e) {
				e.printStackTrace();
			}
			File crash_file = new File(configuration.getWorkingDirectory() + File.separator + basename + ".crash.txt");
			if (crash_file.exists()) {
				for (String logline : directoryManager.filesystemHealthCheck()) {
					log.debug(logline);
				}
				log.error("Job::render crash file found => the renderer crashed");
				crash_file.delete();
				return Error.Type.RENDERER_CRASHED;
			}
			
			if (exit_value == 127 && process.getDuration() < 10) {
				for (String logline : directoryManager.filesystemHealthCheck()) {
					log.debug(logline);
				}
				log.error("Job::render renderer returned 127 and took " + process.getDuration() + "s, some libraries may be missing");
				return Error.Type.RENDERER_MISSING_LIBRARIES;
			}
			
			return Error.Type.NOOUTPUTFILE;
		}
		else {
			if (files.length == 2) {
				Arrays.sort(files);	//in case of an exr we end up with 2 images, the output as an exr and the preview as a jpg, we want to ensure the output comes first
				String path = files[1].getAbsolutePath();
				String extension = path.substring(path.lastIndexOf(".") + 1).toLowerCase();
				if ("jpg".equals(extension)) {
					getRenderOutput().setPreviewImagePath(files[1].getAbsolutePath());
				}
			}
			
			getRenderOutput().setFullImagePath(files[0].getAbsolutePath());
			getRenderOutput().setFullImageSize(new File(getRenderOutput().getFullImagePath()).length());
			log.debug(String.format("Job::render pictureFilename: %s, size: %d'", getRenderOutput().getFullImagePath(), getRenderOutput().getFullImageSize()));
		}
		
		File scene_dir = new File(getSceneDirectory());
		long date_modification_scene_directory = (long) Utils.lastModificationTime(scene_dir);
		if (date_modification_scene_directory > process.getStartTime()) {
			scene_dir.delete();
		}
		
		gui.status(String.format("Render time: %dmin%ds",
			process.getRenderDuration() / 60,
			process.getRenderDuration() % 60)
		);
		
		return Error.Type.OK;
	}
	
	private int computeRenderingProgress(String line, Pattern tilePattern, int currentProgress) {
		Matcher standardTileInfo = tilePattern.matcher(line);
		int newProgress = currentProgress;
		
		if (standardTileInfo.find()) {
			int tileJustProcessed = Integer.parseInt(standardTileInfo.group(2));
			int totalTilesInJob = Integer.parseInt(standardTileInfo.group(3));
			
			newProgress = Math.abs((tileJustProcessed * 100) / totalTilesInJob);
		}
		
		// Only update the tray icon and the screen if percentage has changed
		if (newProgress != currentProgress) {
			gui.updateTrayIcon(newProgress);
			gui.status("Rendering", newProgress);
		}
		
		return newProgress;
	}
	
	private void updateSpeedSamplesRendered(String line) {
		// Looking for "Rendered 1281 samples in 66.319402 seconds"
		Pattern pattern = Pattern.compile("^Rendered (\\d+) samples in ([\\d.]+) seconds$");
		Matcher matcher = pattern.matcher(line);
		
		if (matcher.find()) {
			int amount = Integer.parseInt(matcher.group(1));
			float duration = Float.parseFloat(matcher.group(2));
			
			if (duration != 0 && amount != 0) {
				this.renderOutput.setSpeedSamplesRendered(amount / duration);
			}
		}
		
		// should we use this, instead ???
		// "Average time per sample: 0.052112 seconds"
	}
	
	private void updateRenderingStatus(String line, int progress) {
		if (getRenderSettings().getUpdateRenderingStatusMethod() == null || UPDATE_METHOD_BY_REMAINING_TIME.equals(getRenderSettings().getUpdateRenderingStatusMethod())) {
			String search_remaining = "remaining:";
			int index = line.toLowerCase().indexOf(search_remaining);
			if (index != -1) {
				String buf1 = line.substring(index + search_remaining.length());
				index = buf1.indexOf(" ");
				
				if (index != -1) {
					String remaining_time = buf1.substring(0, index).trim();
					int last_index = remaining_time.lastIndexOf('.'); //format 00:00:00.00 (hr:min:sec)
					if (last_index > 0) {
						remaining_time = remaining_time.substring(0, last_index);
					}
					
					try {
						DateFormat date_parse_minute = new SimpleDateFormat("m:s");
						DateFormat date_parse_hour = new SimpleDateFormat("h:m:s");
						DateFormat date_parse = date_parse_minute;
						if (remaining_time.split(":").length > 2) {
							date_parse = date_parse_hour;
						}
						date_parse.setTimeZone(TimeZone.getTimeZone("GMT"));
						Date date = date_parse.parse(remaining_time);
						gui.setRemainingTime(Utils.humanDuration(date));
						getRenderProcess().setRemainingDuration((int) (date.getTime() / 1000));
					}
					catch (ParseException err) {
						log.error("Client::updateRenderingStatus ParseException " + err);
					}
				}
			}
			else {	//extrapolate remaining time from time rendered & progress
				if (line.contains("Time") == true) {
					long timeRendered = new Date().getTime() - getRenderProcess().getStartTime();
					
					if (progress > 0 && timeRendered > 0) {
						long linearTimeEstimation = (long) ((100.0 / progress) * timeRendered);
						long timeRemaining = linearTimeEstimation - timeRendered;
						Date date = new Date(timeRemaining);
						
						gui.setRemainingTime(Utils.humanDuration(date));
						getRenderProcess().setRemainingDuration((int) (date.getTime() / 1000));
					}
				}
			}
		}
		else if (UPDATE_METHOD_BY_TILE.equals(getRenderSettings().getUpdateRenderingStatusMethod())) {
			String search = " Tile ";
			int index = line.lastIndexOf(search);
			if (index != -1) {
				String buf = line.substring(index + search.length());
				String[] parts = buf.split("/");
				if (parts.length == 2) {
					try {
						int current = Integer.parseInt(parts[0]);
						int total = Integer.parseInt(parts[1]);
						if (total != 0) {
							gui.status(String.format("Rendering %s %%", (int) (100.0 * current / total)));
							return;
						}
					}
					catch (NumberFormatException e) {
						log.error("Exception 94: " + e);
					}
				}
			}
			gui.status("Rendering");
		}
	}
	
	private void updateProcess() {
		getRenderProcess().update();
	}
	
	private void maybeCleanWorkingDir(Type error) {
		boolean cleanup = Type.COLOR_MANAGEMENT_ERROR == error
			|| Type.RENDERER_CRASHED_PYTHON_ERROR == error
			|| Type.ENGINE_NOT_AVAILABLE == error
			|| Type.DETECT_DEVICE_ERROR == error;
		if (cleanup) {
			directoryManager.cleanWorkingDirectory();
		}
	}
	
	public static class renderStartedObservable extends Observable {
		
		@Getter private boolean isStarted;
		
		public renderStartedObservable(Observer observer) {
			super();
			addObserver(observer);
		}
		
		public void doNotifyIsStarted() {
			setChanged();
			notifyObservers();
			isStarted = true;
		}
	}
}