vfxreview/RenderWorker/VFXReviewWorker/BlenderRunner.cs

using System.Diagnostics;
using System.Text;
using Microsoft.Extensions.Logging;

namespace VFXReviewWorker;

/// <summary>
/// Standalone Blender renders: `blender -b file.blend -s N -e M -a`.
///
/// The .blend is expected to be ready to render — output path, format and
/// frame range already set by whoever built it. Overrides are only applied
/// when the submission asked for them, so this stays "Ctrl+F12 on the farm"
/// rather than a second place where render settings can drift.
/// </summary>
public sealed class BlenderRunner
{
    private readonly WorkerOptions _options;
    private readonly ApiClient _api;
    private readonly ILogger<BlenderRunner> _log;

    public BlenderRunner(WorkerOptions options, ApiClient api, ILogger<BlenderRunner> log)
    {
        _options = options;
        _api = api;
        _log = log;
    }

    public async Task<RenderResult> RunAsync(
        ClaimedJob job,
        BlenderManifest m,
        string machineId,
        ServerConfig config,
        CancellationToken cancelJob,
        CancellationToken shutdown)
    {
        var mapper = new PathMapper(_options.PathMappings);
        var blendLocal = mapper.Map(m.BlendFile);
        var totalFrames = m.TotalFrames;

        if (!File.Exists(blendLocal))
        {
            return new RenderResult(false, -1, Retryable: false,
                $"Blend file not found on this machine: {blendLocal}", "", "", 0);
        }

        // Argument order matters to Blender: everything before -a configures the
        // render, and -a must come last or it renders with the old settings.
        var args = new List<string> { "-b", blendLocal };
        if (!string.IsNullOrWhiteSpace(m.Scene)) { args.Add("-S"); args.Add(m.Scene!); }
        if (!string.IsNullOrWhiteSpace(m.OutputPath))
        {
            args.Add("-o");
            args.Add(mapper.Map(m.OutputPath!));
        }
        if (!string.IsNullOrWhiteSpace(m.Engine)) { args.Add("-E"); args.Add(m.Engine!); }

        var pythonOverrides = BuildOverrideExpression(m);
        if (pythonOverrides is not null) { args.Add("--python-expr"); args.Add(pythonOverrides); }

        args.Add("-s"); args.Add(m.FrameStart.ToString());
        args.Add("-e"); args.Add(m.FrameEnd.ToString());
        args.Add("-a");

        _log.LogInformation("Rendering {Label}: {Blend} frames {Start}-{End}",
            job.Label ?? job.Id, blendLocal, m.FrameStart, m.FrameEnd);

        return await ExecuteAsync(job.Id, machineId, args, totalFrames, m.FrameStart, config,
            $"blender_{job.Id}.log", cancelJob, shutdown);
    }

    /// <summary>
    /// Settings Blender has no command-line flag for. Returns null when the
    /// submission asked for no overrides, so the file renders exactly as saved.
    /// </summary>
    private static string? BuildOverrideExpression(BlenderManifest m)
    {
        var parts = new List<string>();
        if (m.Samples is int samples)
        {
            parts.Add($"getattr(S.cycles, 'samples', None) and setattr(S.cycles, 'samples', {samples})");
        }
        if (m.ResolutionPercent is int pct)
        {
            parts.Add($"setattr(S.render, 'resolution_percentage', {pct})");
        }
        if (!string.IsNullOrWhiteSpace(m.Device))
        {
            var deviceValue = m.Device!.Equals("GPU", StringComparison.OrdinalIgnoreCase) ? "GPU" : "CPU";
            parts.Add($"hasattr(S, 'cycles') and setattr(S.cycles, 'device', '{deviceValue}')");
        }
        if (parts.Count == 0) return null;

        return "import bpy; S = bpy.context.scene; " + string.Join("; ", parts);
    }

    private async Task<RenderResult> ExecuteAsync(
        string jobId,
        string machineId,
        List<string> 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.BlenderPath,
            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;
        var framesSaved = 0;
        var currentFrame = frameStart;
        string? firstError = null;
        var nonRetryable = false;
        var 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 = BlenderProgressParser.ParseFrame(line);
            if (frame is not null)
            {
                // A frame line only proves Blender is alive; a long frame emits
                // many of them, so this feeds the stall watchdog, not progress.
                currentFrame = frame.Value;
                lastProgressAt = DateTimeOffset.UtcNow;
            }
            if (BlenderProgressParser.ParseSaved(line) is not null)
            {
                framesSaved++;
                lastProgressAt = DateTimeOffset.UtcNow;
                eta.RecordFrame(lastProgressAt);
            }
            if ((isStderr || BlenderProgressParser.IsErrorLine(line)) && !string.IsNullOrWhiteSpace(line))
            {
                if (BlenderProgressParser.IsErrorLine(line)) firstError ??= line.Trim();
                if (BlenderProgressParser.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 Blender at {_options.BlenderPath}: {ex.Message}",
                tail.ToString(), fullLogPath, 0);
        }
        process.BeginOutputReadLine();
        process.BeginErrorReadLine();

        while (!process.HasExited)
        {
            await Task.Delay(TimeSpan.FromSeconds(2), CancellationToken.None);

            if (cancelJob.IsCancellationRequested || shutdown.IsCancellationRequested)
            {
                _log.LogWarning("Cancellation requested — killing Blender tree for job {JobId}", jobId);
                KillTree(process);
                cancelledByServer = cancelJob.IsCancellationRequested;
                break;
            }

            if ((DateTimeOffset.UtcNow - lastProgressAt).TotalSeconds > config.StallTimeoutSeconds)
            {
                _log.LogError("Blender stalled ({Sec}s without output) — killing job {JobId}", config.StallTimeoutSeconds, jobId);
                KillTree(process);
                await WaitForExitSafe(process);
                return new RenderResult(false, -2, Retryable: true,
                    $"Blender produced no output for {config.StallTimeoutSeconds}s (stall timeout)",
                    tail.ToString(), fullLogPath, sw.Elapsed.TotalSeconds);
            }

            if ((DateTimeOffset.UtcNow - lastReportAt).TotalSeconds >= 10)
            {
                lastReportAt = DateTimeOffset.UtcNow;
                var progress = totalFrames > 0 ? Math.Min(1.0, (double)framesSaved / totalFrames) : 0;
                var resp = await _api.ProgressAsync(jobId, machineId, progress, currentFrame, totalFrames,
                    eta.EstimateSeconds(totalFrames - framesSaved), tail.ToString(), shutdown);
                if (resp?.CancelRequested == true)
                {
                    _log.LogWarning("Server requested cancel for job {JobId}", jobId);
                    KillTree(process);
                    cancelledByServer = true;
                    break;
                }
            }
        }

        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)
        {
            return new RenderResult(false, exitCode, Retryable: !nonRetryable,
                firstError ?? $"Blender exited with code {exitCode}",
                tail.ToString(), fullLogPath, sw.Elapsed.TotalSeconds);
        }

        // Blender exits 0 having rendered nothing if the range is empty or the
        // output path is unwritable, so a silent success is treated as failure.
        if (framesSaved == 0)
        {
            return new RenderResult(false, 0, Retryable: false,
                "Blender exited cleanly but saved no frames — check the output path and frame range in the .blend",
                tail.ToString(), fullLogPath, sw.Elapsed.TotalSeconds);
        }

        _log.LogInformation("Job {JobId}: {Saved}/{Total} frames in {Sec:F0}s", jobId, framesSaved, totalFrames, sw.Elapsed.TotalSeconds);
        return new RenderResult(true, 0, true, null, tail.ToString(), fullLogPath, sw.Elapsed.TotalSeconds);
    }

    private static void KillTree(Process process)
    {
        try { if (!process.HasExited) process.Kill(entireProcessTree: true); } catch { }
    }

    private static async Task WaitForExitSafe(Process process)
    {
        try { await process.WaitForExitAsync(); } catch { }
    }
}