using System.Diagnostics; using System.Text; using Microsoft.Extensions.Logging; namespace VFXReviewWorker; public sealed record RenderResult( bool Success, int ExitCode, bool Retryable, string? ErrorMessage, string LogTail, string FullLogPath, double RenderSeconds); /// /// Stage 1: aerender execution (§7.3). Launches aerender.exe, parses stdout /// for PROGRESS/ERROR lines, reports progress (renewing the lease), enforces /// the stall timeout, and honours cancellation by killing the process tree. /// public sealed class AerenderRunner { private readonly WorkerOptions _options; private readonly ApiClient _api; private readonly ILogger _log; public AerenderRunner(WorkerOptions options, ApiClient api, ILogger log) { _options = options; _api = api; _log = log; } /// /// Renders every queued item in an already-prepared project (no -comp), used /// by the preview stage: the build script saved an AEP with the MOV and MP4 /// output modules already queued, so one launch produces both. /// public Task RunProjectAsync( string jobId, string machineId, string projectPathLocal, int totalFrames, ServerConfig config, CancellationToken cancelJob, CancellationToken shutdown) { var args = new List { "-project", projectPathLocal, "-mp" }; _log.LogInformation("Rendering prepared project for job {JobId}: {Project}", jobId, projectPathLocal); return ExecuteAsync(jobId, machineId, args, totalFrames, 0, config, $"aerender_{jobId}_preview.log", cancelJob, shutdown); } public async Task RunAsync( ClaimedJob job, RenderManifest m, string machineId, string outputDirLocal, ServerConfig config, CancellationToken cancelJob, CancellationToken shutdown) { var mapper = new PathMapper(_options.PathMappings); var aepLocal = mapper.Map(m.AepPath); var outputArg = Path.Combine(outputDirLocal, m.OutputPattern); PrepareOutputDir(outputDirLocal, m.OutputPattern); var args = new List { "-project", aepLocal, "-comp", m.CompName, "-s", m.FrameStart.ToString(), "-e", m.FrameEnd.ToString(), }; if (!string.IsNullOrEmpty(m.RenderSettingsTemplate)) { args.Add("-RStemplate"); args.Add(m.RenderSettingsTemplate); } if (!string.IsNullOrEmpty(m.OutputModuleTemplate)) { args.Add("-OMtemplate"); args.Add(m.OutputModuleTemplate); } args.Add("-output"); args.Add(outputArg); // NB: no "-continueOnMissingFootage" — the real flag takes no value // (passing "false" is an aerender SYNTAX ERROR), and its *presence* // enables skipping missing footage. aerender's default is to stop on // missing footage, which is exactly what the pipeline wants. _log.LogInformation("Launching aerender for job {JobId}: {Aep} comp \"{Comp}\" frames {S}-{E} → {Out}", job.Id, aepLocal, m.CompName, m.FrameStart, m.FrameEnd, outputArg); return await ExecuteAsync(job.Id, machineId, args, m.TotalFrames, m.FrameStart, config, $"aerender_{job.Id}.log", cancelJob, shutdown); } private async Task ExecuteAsync( string jobId, string machineId, List args, int totalFrames, int frameStart, ServerConfig config, string logFileName, CancellationToken cancelJob, CancellationToken shutdown) { var fullLogPath = Path.Combine(WorkerOptions.LogsDir, logFileName); Directory.CreateDirectory(WorkerOptions.LogsDir); var psi = new ProcessStartInfo { FileName = _options.AerenderPath, RedirectStandardOutput = true, RedirectStandardError = true, UseShellExecute = false, CreateNoWindow = true, StandardOutputEncoding = Encoding.UTF8, StandardErrorEncoding = Encoding.UTF8, }; foreach (var a in args) psi.ArgumentList.Add(a); var tail = new LogTail(200); var eta = new EtaCalculator(); var sw = Stopwatch.StartNew(); var lastProgressAt = DateTimeOffset.UtcNow; var lastReportAt = DateTimeOffset.MinValue; int framesDone = 0; string? firstError = null; bool nonRetryable = false; bool cancelledByServer = false; using var process = new Process { StartInfo = psi }; await using var fullLog = new StreamWriter(fullLogPath, append: false, Encoding.UTF8); var logLock = new object(); void HandleLine(string? line, bool isStderr) { if (line is null) return; lock (logLock) { fullLog.WriteLine(line); tail.Add(line); } var frame = ProgressParser.ParseFrame(line); if (frame is not null) { framesDone = Math.Max(framesDone, frame.Value); lastProgressAt = DateTimeOffset.UtcNow; eta.RecordFrame(lastProgressAt); } if ((isStderr || ProgressParser.IsErrorLine(line)) && !string.IsNullOrWhiteSpace(line)) { if (ProgressParser.IsErrorLine(line)) firstError ??= line.Trim(); if (ProgressParser.IsNonRetryableError(line)) nonRetryable = true; } } process.OutputDataReceived += (_, e) => HandleLine(e.Data, isStderr: false); process.ErrorDataReceived += (_, e) => HandleLine(e.Data, isStderr: true); try { process.Start(); } catch (Exception ex) { return new RenderResult(false, -1, Retryable: false, $"Failed to launch aerender at {_options.AerenderPath}: {ex.Message}", tail.ToString(), fullLogPath, 0); } process.BeginOutputReadLine(); process.BeginErrorReadLine(); var total = totalFrames; while (!process.HasExited) { await Task.Delay(TimeSpan.FromSeconds(2), CancellationToken.None); if (cancelJob.IsCancellationRequested || shutdown.IsCancellationRequested) { _log.LogWarning("Cancellation requested — killing aerender tree for job {JobId}", jobId); KillTree(process); cancelledByServer = cancelJob.IsCancellationRequested; break; } // Stall watchdog (§7.3): no progress line for stallTimeoutSeconds → kill if ((DateTimeOffset.UtcNow - lastProgressAt).TotalSeconds > config.StallTimeoutSeconds) { _log.LogError("aerender stalled ({Sec}s without progress) — killing job {JobId}", config.StallTimeoutSeconds, jobId); KillTree(process); await WaitForExitSafe(process); return new RenderResult(false, -2, Retryable: true, $"aerender produced no progress for {config.StallTimeoutSeconds}s (stall timeout)", tail.ToString(), fullLogPath, sw.Elapsed.TotalSeconds); } // Progress report every ~10 s (renews lease); best-effort if ((DateTimeOffset.UtcNow - lastReportAt).TotalSeconds >= 10) { lastReportAt = DateTimeOffset.UtcNow; var progress = total > 0 ? Math.Min(1.0, (double)framesDone / total) : 0; try { var resp = await _api.ProgressAsync(jobId, machineId, progress, framesDone > 0 ? frameStart + framesDone - 1 : null, total, eta.EstimateSeconds(total - framesDone), tail.ToString(), shutdown); if (resp?.CancelRequested == true) { _log.LogWarning("Server requested cancel for job {JobId}", jobId); KillTree(process); cancelledByServer = true; break; } } catch (Exception ex) { _log.LogDebug(ex, "Progress report failed (non-fatal; lease covered by reaper)"); } } } await WaitForExitSafe(process); sw.Stop(); lock (logLock) { fullLog.Flush(); } if (cancelledByServer) { return new RenderResult(false, -3, Retryable: false, "Cancelled", tail.ToString(), fullLogPath, sw.Elapsed.TotalSeconds); } var exitCode = process.ExitCode; if (exitCode == 0 && firstError is null) { return new RenderResult(true, 0, true, null, tail.ToString(), fullLogPath, sw.Elapsed.TotalSeconds); } return new RenderResult(false, exitCode, Retryable: !nonRetryable, firstError ?? $"aerender exited with code {exitCode}", tail.ToString(), fullLogPath, sw.Elapsed.TotalSeconds); } /// /// §7.3: outputDir is created before launch; a pre-existing non-empty dir /// can only hold output from a previous crashed attempt of this same /// immutable version. Safety guard: only files matching the job's own /// output pattern prefix are ever deleted. /// /// Filename prefix of an output pattern ("X.[####].exr" → "X"). internal static string OutputPatternPrefix(string outputPattern) { var bracket = outputPattern.IndexOf('['); return bracket > 0 ? outputPattern[..bracket].TrimEnd('.') : Path.GetFileNameWithoutExtension(outputPattern); } internal static void PrepareOutputDir(string outputDirLocal, string outputPattern) { Directory.CreateDirectory(outputDirLocal); var prefix = OutputPatternPrefix(outputPattern); if (string.IsNullOrEmpty(prefix)) return; foreach (var file in Directory.EnumerateFiles(outputDirLocal)) { if (Path.GetFileName(file).StartsWith(prefix, StringComparison.OrdinalIgnoreCase)) { try { File.Delete(file); } catch { /* locked leftovers surface as an aerender error */ } } } } private static void KillTree(Process process) { try { if (!process.HasExited) process.Kill(entireProcessTree: true); } catch { /* already gone */ } } private static async Task WaitForExitSafe(Process process) { try { await process.WaitForExitAsync(new CancellationTokenSource(TimeSpan.FromSeconds(30)).Token); } catch { try { process.Kill(entireProcessTree: true); } catch { } } } } /// Ring buffer of the last N output lines (§5.3 logTail). public sealed class LogTail { private readonly Queue _lines; private readonly int _capacity; public LogTail(int capacity) { _capacity = capacity; _lines = new Queue(capacity); } public void Add(string line) { _lines.Enqueue(line); while (_lines.Count > _capacity) _lines.Dequeue(); } public override string ToString() => string.Join('\n', _lines); }