vfxreview/RenderWorker/VFXReviewWorker.Tests/BlenderProgressParserTests.cs

using System.Text;
using VFXReviewWorker;
using Xunit;

namespace VFXReviewWorker.Tests;

/// <summary>
/// Blender writes its render status with a carriage return so it overwrites one
/// line in the terminal, and only emits a newline when a frame is saved. A
/// reader that splits on newlines alone therefore sees nothing at all while a
/// long frame renders — which had the stall watchdog killing healthy jobs.
/// </summary>
public class BlenderProgressParserTests
{
    [Theory]
    [InlineData("Fra:1042 Mem:512.00M (Peak 640.00M) | Time:00:12.34 | Path Tracing Sample 12/128", 1042)]
    [InlineData("Fra:1 Mem:64.00M | Syncing Cube", 1)]
    [InlineData("Saved: 'X:/renders/frame_1042.exr'", null)]
    [InlineData("Blender quit", null)]
    public void ParsesTheFrameBeingRendered(string line, int? expected)
    {
        Assert.Equal(expected, BlenderProgressParser.ParseFrame(line));
    }

    [Theory]
    [InlineData("Saved: 'X:/renders/frame_1042.exr'", "X:/renders/frame_1042.exr")]
    [InlineData(" Saved: 'nope'", null)] // leading space: not the real form
    [InlineData("Fra:1042 Mem:512.00M", null)]
    public void ParsesSavedFrames(string line, string? expected)
    {
        Assert.Equal(expected, BlenderProgressParser.ParseSaved(line));
    }

    [Fact]
    public void TreatsAMissingBlendAsNonRetryable()
    {
        const string line = "Error: Cannot read file 'X:/gone.blend': No such file or directory";
        Assert.True(BlenderProgressParser.IsErrorLine(line));
        Assert.True(BlenderProgressParser.IsNonRetryableError(line));
    }

    [Fact]
    public void TreatsAnUnknownFailureAsRetryable()
    {
        const string line = "Error: CUDA device lost, out of memory";
        Assert.True(BlenderProgressParser.IsErrorLine(line));
        Assert.False(BlenderProgressParser.IsNonRetryableError(line));
    }

    /// <summary>
    /// The regression itself: a realistic stdout chunk where progress is
    /// separated by CR and only the saved lines end in LF.
    /// </summary>
    [Fact]
    public void CarriageReturnProgressIsSeenWithoutWaitingForANewline()
    {
        var stdout =
            "Fra:1001 Mem:64.00M | Sample 1/128\r" +
            "Fra:1001 Mem:120.00M | Sample 64/128\r" +
            "Fra:1001 Mem:128.00M | Sample 128/128\r" +
            "\nSaved: 'X:/renders/frame_1001.exr'\n" +
            "Fra:1002 Mem:128.00M | Sample 1/128\r";

        var lines = SplitLikeThePump(stdout);

        var frames = lines.Select(BlenderProgressParser.ParseFrame).Where(f => f is not null).ToList();
        var saved = lines.Select(BlenderProgressParser.ParseSaved).Where(s => s is not null).ToList();

        // Four status updates and one saved frame; splitting on "\n" alone
        // would have yielded a single unusable blob and no progress at all.
        Assert.Equal(4, frames.Count);
        Assert.Single(saved);
        Assert.Equal(1002, frames[^1]);
    }

    /// <summary>
    /// Blender 5.x prefixes every line with elapsed time and a log category.
    /// Anchored on "Saved:", the parser counted no frames from a render that
    /// wrote every one, and the job failed as "saved no frames".
    /// These lines are verbatim Blender 5.2 output.
    /// </summary>
    [Fact]
    public void ParsesBlender5PrefixedOutput()
    {
        Assert.Equal(@"X:\renders\frame_0001.png",
            BlenderProgressParser.ParseSaved(@"00:02.954  render           | Saved: 'X:\renders\frame_0001.png'"));
        Assert.Equal(1, BlenderProgressParser.ParseFrame("00:02.469  render           | Fra: 1 | Mem: 0M | Synchronizing object | Cube"));
        Assert.Null(BlenderProgressParser.ParseSaved("00:02.954  render           | Time: 00:00.87 (Saving: 00:00.14)"));
        Assert.Null(BlenderProgressParser.ParseFrame("00:02.079  render           | Rendering frame 1"));
    }

    [Fact]
    public void RecognisesBlender5Errors()
    {
        const string unwritable = @"00:03.063  reports          | ERROR Render error (No such file or directory) cannot save: 'Q:\out\f_0001.png'";
        Assert.True(BlenderProgressParser.IsErrorLine(unwritable));
        Assert.True(BlenderProgressParser.IsNonRetryableError(unwritable));

        const string missing = @"00:13.250  reports          | ERROR Cannot read file ""X:\gone.blend"": No such file or directory";
        Assert.True(BlenderProgressParser.IsErrorLine(missing));
        Assert.True(BlenderProgressParser.IsNonRetryableError(missing));
    }

    /// <summary>
    /// Add-ons print warnings on every launch; one must never become the
    /// reported reason a render failed.
    /// </summary>
    [Theory]
    [InlineData("Warning: add-on missing 'bl_info', this can cause poor performance!: 'G:\\addons\\x\\__init__.py'")]
    [InlineData("00:01.000  addon            | WARNING something harmless")]
    public void WarningsAreNotErrors(string line)
    {
        Assert.False(BlenderProgressParser.IsErrorLine(line));
    }

    /// <summary>Mirrors BlenderRunner.PumpAsync: CR and LF both end a line.</summary>
    private static List<string> SplitLikeThePump(string text)
    {
        var lines = new List<string>();
        var current = new StringBuilder();
        foreach (var c in text)
        {
            if (c == '\r' || c == '\n')
            {
                if (current.Length > 0) { lines.Add(current.ToString()); current.Clear(); }
            }
            else current.Append(c);
        }
        if (current.Length > 0) lines.Add(current.ToString());
        return lines;
    }
}