fix(worker): parse Blender 5.x output so rendered frames are counted
Deploy / deploy (push) Successful in 3m28s

Blender 5 logs through CLOG, prefixing every line with elapsed time and a
category ("00:02.954  render | Saved: '...'"), and reports errors as
"ERROR ..." instead of "Error: ...". The parser anchored on "Saved:" at the
start of the line, so it counted no frames from a render that wrote all of
them and the job failed as "saved no frames". Progress (Fra:) and error
detection were dead on 5.x for the same reason.

The prefix is now stripped before matching; 4.x output parses as before.
Warnings no longer count as errors: add-ons print them on every launch and
one would otherwise be reported as the reason a render failed. A run that
saves nothing now reports Blender's own error when there is one.

Verified on the real DH2 test.blend under Blender 5.2: the 1.6.2 parser
counts 0 of 3 saved frames, this one counts 3.

Bump worker to 1.6.3.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
This commit is contained in:
twotalesanimation
2026-09-18 04:42:33 +02:00
parent 97246bcbc3
commit 708e8a0d8f
4 changed files with 69 additions and 7 deletions
@@ -73,6 +73,46 @@ public class BlenderProgressParserTests
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)
{
@@ -8,18 +8,36 @@ namespace VFXReviewWorker;
/// with "Saved: '...'". The saved lines are the reliable signal — a frame can
/// be reported for a long time while it renders — so progress counts those and
/// falls back to Fra: for a first sign of life.
///
/// Blender 5.x logs through CLOG, which prefixes every line with an elapsed
/// time and a category ("00:02.954 render | Saved: '...'") and
/// reports errors as "ERROR ..." rather than "Error: ...". The prefix is
/// stripped before matching, so both formats parse the same way.
/// </summary>
public static partial class BlenderProgressParser
{
[GeneratedRegex(@"^Fra:(\d+)", RegexOptions.Compiled)]
[GeneratedRegex(@"^(?:\d+:)?\d{2}:\d{2}\.\d{3}\s+\S+\s*\| ?", RegexOptions.Compiled)]
private static partial Regex LogPrefix();
[GeneratedRegex(@"^Fra:\s*(\d+)", RegexOptions.Compiled)]
private static partial Regex FrameLine();
[GeneratedRegex(@"^Saved:\s*'(.+)'", RegexOptions.Compiled)]
private static partial Regex SavedLine();
[GeneratedRegex(@"^(Error|Warning): |^Error: ", RegexOptions.Compiled | RegexOptions.IgnoreCase)]
// Errors only. Warnings are not failures, and add-ons print them on every
// launch ("Warning: add-on missing 'bl_info'"), so counting them made an
// add-on's complaint the reported reason for a failed render.
[GeneratedRegex(@"(?i:^Error: )|^(ERROR|FATAL) ", RegexOptions.Compiled)]
private static partial Regex ErrorLine();
/// <summary>The line without Blender 5.x's "elapsed category | " prefix.</summary>
private static string Message(string line)
{
var m = LogPrefix().Match(line);
return m.Success ? line[m.Length..] : line;
}
/// <summary>
/// Failures that will repeat identically on another machine — a missing
/// file, an unknown scene, an unwritable output. Retrying these burns the
@@ -35,7 +53,9 @@ public static partial class BlenderProgressParser
"unknown scene",
"scene not found",
"unable to create directory",
"couldn't create directory",
"cannot write file",
"cannot save:",
"no camera",
"python script fail",
"unknown argument",
@@ -44,18 +64,18 @@ public static partial class BlenderProgressParser
/// <summary>The frame Blender is currently working on, or null.</summary>
public static int? ParseFrame(string line)
{
var m = FrameLine().Match(line);
var m = FrameLine().Match(Message(line));
return m.Success && int.TryParse(m.Groups[1].Value, out var f) ? f : null;
}
/// <summary>The path of a frame Blender has just written, or null.</summary>
public static string? ParseSaved(string line)
{
var m = SavedLine().Match(line);
var m = SavedLine().Match(Message(line));
return m.Success ? m.Groups[1].Value : null;
}
public static bool IsErrorLine(string line) => ErrorLine().IsMatch(line);
public static bool IsErrorLine(string line) => ErrorLine().IsMatch(Message(line));
public static bool IsNonRetryableError(string line)
{
@@ -268,7 +268,9 @@ public sealed class BlenderRunner
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",
firstError is not null
? $"Blender exited cleanly but saved no frames: {firstError}"
: "Blender exited cleanly but saved no frames — check the output path and frame range in the .blend",
tail.ToString(), fullLogPath, sw.Elapsed.TotalSeconds);
}
@@ -15,7 +15,7 @@
every change that gets published. publish.ps1 appends the git SHA via
SourceRevisionId, giving "1.1.0+feb1c7b".
-->
<Version>1.6.2</Version>
<Version>1.6.3</Version>
</PropertyGroup>
<ItemGroup>