feat(render): real progress %, ETA, and frequent preview during AE renders

The render page already displayed progress/ETA/preview — but the node agent never
fed real data: aeRender used fake +5%/10s increments, discarded aerender stdout,
and pushed a preview only every 30s. (Plus the deployed agent predated even the
progress-reporting wiring.)

node-agent (aeRender):
- Capture aerender stdout; parse "(N):" current frame + "N frames"/"to N" total.
- Real percentage when total is known (5–90%, headroom for transcode/upload),
  else a smooth time-asymptotic estimate that never sticks — message shows the
  live frame number either way.
- Push a preview frame ~every 8s (was 30s) so the box fills in quickly.

render-svc:
- GET /v1/renders/:id/progress now computes eta_seconds from started_at + progress
  (linear extrapolation) instead of returning null.

frontend:
- Thread eta_seconds → status route → render page; page prefers the server ETA and
  falls back to the client-observed rate.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
This commit is contained in:
soroush.asadi
2026-06-18 01:18:54 +03:30
parent 23d1fd8fb1
commit 6d79ddb8d1
5 changed files with 116 additions and 29 deletions
+87 -26
View File
@@ -4,17 +4,32 @@
package runner package runner
import ( import (
"bufio"
"context" "context"
"fmt" "fmt"
"io"
"log" "log"
"os" "os"
"os/exec" "os/exec"
"path/filepath" "path/filepath"
"regexp"
"runtime" "runtime"
"strconv"
"strings" "strings"
"sync/atomic"
"time" "time"
) )
// aerender prints one "PROGRESS: <timecode> (<frame>): <n> Seconds" line per
// rendered frame, and (on most versions) an up-front line naming the frame range
// or total count. We parse the current frame for live progress + the total to
// turn it into a real percentage and ETA.
var (
reFrameNum = regexp.MustCompile(`\((\d+)\)\s*:`) // "(59):"
reTotalRange = regexp.MustCompile(`(?i)\bto\s+(\d+)\b`) // "0 to 299"
reTotalCount = regexp.MustCompile(`(?i)\b(\d+)\s+frames?\b`) // "300 frames"
)
// ProgressFn is called periodically during rendering with (percent 0-100, message). // ProgressFn is called periodically during rendering with (percent 0-100, message).
type ProgressFn func(ctx context.Context, percent int, message string) error type ProgressFn func(ctx context.Context, percent int, message string) error
@@ -265,27 +280,52 @@ func aeRender(ctx context.Context, aePath string, job *Job, outputPath string, o
// Run from the project's folder so a .zip bundle's relative footage/font paths // Run from the project's folder so a .zip bundle's relative footage/font paths
// resolve correctly (the .aep sits alongside its assets after extraction). // resolve correctly (the .aep sits alongside its assets after extraction).
cmd.Dir = filepath.Dir(job.AEPFilePath) cmd.Dir = filepath.Dir(job.AEPFilePath)
cmd.Stdout = os.Stdout stdout, pipeErr := cmd.StdoutPipe()
if pipeErr != nil {
return "", fmt.Errorf("stdout pipe: %w", pipeErr)
}
cmd.Stderr = os.Stderr cmd.Stderr = os.Stderr
if err := cmd.Start(); err != nil { if err := cmd.Start(); err != nil {
return "", fmt.Errorf("start aerender: %w", err) return "", fmt.Errorf("start aerender: %w", err)
} }
// Poll process while alive — aerender does not expose machine-readable progress. // Scan aerender stdout in the background: echo it to our log AND extract the
// We advance the progress indicator every 10 seconds until the process exits. // current frame + total frame count for real progress.
var curFrame, totalFrames int64
go func() {
sc := bufio.NewScanner(stdout)
sc.Buffer(make([]byte, 64*1024), 1024*1024)
for sc.Scan() {
line := sc.Text()
_, _ = io.WriteString(os.Stdout, line+"\n")
if m := reFrameNum.FindStringSubmatch(line); m != nil {
if n, e := strconv.ParseInt(m[1], 10, 64); e == nil {
atomic.StoreInt64(&curFrame, n)
}
}
if atomic.LoadInt64(&totalFrames) == 0 {
if m := reTotalRange.FindStringSubmatch(line); m != nil {
if n, e := strconv.ParseInt(m[1], 10, 64); e == nil && n > 1 {
atomic.StoreInt64(&totalFrames, n)
}
} else if m := reTotalCount.FindStringSubmatch(line); m != nil {
if n, e := strconv.ParseInt(m[1], 10, 64); e == nil && n > 1 {
atomic.StoreInt64(&totalFrames, n)
}
}
}
}
}()
done := make(chan error, 1) done := make(chan error, 1)
go func() { done <- cmd.Wait() }() go func() { done <- cmd.Wait() }()
_ = onProgress(ctx, 10, "After Effects starting…") _ = onProgress(ctx, 5, "After Effects starting…")
pct := 10 start := time.Now()
ticker := time.NewTicker(10 * time.Second) ticker := time.NewTicker(2 * time.Second)
defer ticker.Stop() defer ticker.Stop()
lastPreview := time.Time{}
// Generate preview frames every 30 seconds during real AE render.
// In a full implementation this would screenshot the AE composition output.
previewTicker := time.NewTicker(30 * time.Second)
defer previewTicker.Stop()
for { for {
select { select {
@@ -293,37 +333,32 @@ func aeRender(ctx context.Context, aePath string, job *Job, outputPath string, o
if err != nil { if err != nil {
return "", fmt.Errorf("aerender exit: %w", err) return "", fmt.Errorf("aerender exit: %w", err)
} }
// Find what aerender actually wrote (output.avi / .mov / .mp4).
actual := findRenderedOutput(outputPath) actual := findRenderedOutput(outputPath)
if actual == "" { if actual == "" {
return "", fmt.Errorf("aerender finished but no output file found in %s", filepath.Dir(outputPath)) return "", fmt.Errorf("aerender finished but no output file found in %s", filepath.Dir(outputPath))
} }
// Already an MP4? done.
if strings.EqualFold(filepath.Ext(actual), ".mp4") { if strings.EqualFold(filepath.Ext(actual), ".mp4") {
_ = onProgress(ctx, 95, "Encoding complete") _ = onProgress(ctx, 98, "Encoding complete")
return actual, nil return actual, nil
} }
// Transcode the lossless render → H.264 MP4 (much smaller, web-playable).
_ = onProgress(ctx, 92, "Transcoding to MP4…") _ = onProgress(ctx, 92, "Transcoding to MP4…")
mp4, terr := transcodeToMP4(ctx, actual, outputPath, resolutionHeight(job.Resolution)) mp4, terr := transcodeToMP4(ctx, actual, outputPath, resolutionHeight(job.Resolution))
if terr != nil { if terr != nil {
// ffmpeg missing/failed — fall back to the raw render so the job
// still delivers a file (large, but valid).
log.Printf("[ae] transcode failed (%v) — uploading raw %s", terr, filepath.Ext(actual)) log.Printf("[ae] transcode failed (%v) — uploading raw %s", terr, filepath.Ext(actual))
return actual, nil return actual, nil
} }
_ = onProgress(ctx, 95, "Encoding complete") _ = onProgress(ctx, 98, "Encoding complete")
_ = os.Remove(actual) // drop the multi-GB intermediate _ = os.Remove(actual) // drop the multi-GB intermediate
return mp4, nil return mp4, nil
case <-ticker.C: case <-ticker.C:
if pct < 90 { cur := atomic.LoadInt64(&curFrame)
pct += 5 tot := atomic.LoadInt64(&totalFrames)
} pct, msg := aeProgress(cur, tot, time.Since(start))
_ = onProgress(ctx, pct, fmt.Sprintf("Rendering… %d%%", pct)) _ = onProgress(ctx, pct, msg)
case <-previewTicker.C: // Preview ~every 8s so the box shows something soon after start.
if onPreview != nil { if onPreview != nil && time.Since(lastPreview) >= 8*time.Second {
b64 := GeneratePreviewB64(pct, job.Quality, job.Resolution) lastPreview = time.Now()
if err := onPreview(ctx, b64); err != nil { if err := onPreview(ctx, GeneratePreviewB64(pct, job.Quality, job.Resolution)); err != nil {
log.Printf("[ae] preview push error: %v", err) log.Printf("[ae] preview push error: %v", err)
} }
} }
@@ -333,3 +368,29 @@ func aeRender(ctx context.Context, aePath string, job *Job, outputPath string, o
} }
} }
} }
// aeProgress turns the current/total frame counts (and elapsed time) into a
// render percentage (590, leaving headroom for transcode/upload) plus a human
// message. When the total is known the percentage is real; otherwise it eases
// toward 88% over time so the bar keeps moving without ever sticking or lying
// about being done.
func aeProgress(cur, total int64, elapsed time.Duration) (int, string) {
if total > 1 && cur >= 0 {
frac := float64(cur) / float64(total)
if frac > 1 {
frac = 1
}
pct := 5 + int(frac*85) // 5..90
return pct, fmt.Sprintf("در حال رندر… فریم %d از %d", cur, total)
}
// Unknown total: asymptotic ease toward 88% (~half-way by ~90s).
secs := elapsed.Seconds()
pct := 5 + int(83*(secs/(secs+90)))
if pct > 88 {
pct = 88
}
if cur > 0 {
return pct, fmt.Sprintf("در حال رندر… فریم %d", cur)
}
return pct, "در حال رندر…"
}
+18 -1
View File
@@ -1,6 +1,7 @@
package handlers package handlers
import ( import (
"time"
"log" "log"
"net/http" "net/http"
"strconv" "strconv"
@@ -259,13 +260,29 @@ func (h *RenderHandler) Progress(c *gin.Context) {
c.JSON(http.StatusNotFound, models.APIError{Code: "not_found", Message: err.Error()}) c.JSON(http.StatusNotFound, models.APIError{Code: "not_found", Message: err.Error()})
return return
} }
// Estimate remaining seconds from elapsed time and progress (linear extrapolation).
// Only once the job is actually progressing (599%) and we know when it started.
var etaSeconds *int
if job.StartedAt != nil && job.RenderProgress >= 5 && job.RenderProgress < 100 {
elapsed := time.Since(*job.StartedAt).Seconds()
if elapsed > 0 {
remaining := elapsed * float64(100-job.RenderProgress) / float64(job.RenderProgress)
if remaining < 0 {
remaining = 0
}
eta := int(remaining)
etaSeconds = &eta
}
}
c.JSON(http.StatusOK, gin.H{ c.JSON(http.StatusOK, gin.H{
"job_id": job.ID, "job_id": job.ID,
"step": job.Step, "step": job.Step,
"progress": job.RenderProgress, "progress": job.RenderProgress,
"current_frame": nil, "current_frame": nil,
"total_frames": nil, "total_frames": nil,
"eta_seconds": nil, "eta_seconds": etaSeconds,
"preview_b64": job.ImagePreviewB64, "preview_b64": job.ImagePreviewB64,
"active_nodes": job.CurrentActiveNodes, "active_nodes": job.CurrentActiveNodes,
"message": job.FailedMessage, "message": job.FailedMessage,
@@ -29,6 +29,7 @@ interface StatusResponse {
progressMessage?: string | null; progressMessage?: string | null;
errorMessage?: string | null; errorMessage?: string | null;
previewB64?: string | null; previewB64?: string | null;
etaSeconds?: number | null;
} }
interface ActiveRender { interface ActiveRender {
@@ -180,8 +181,11 @@ export default function RenderPage() {
setProgressMessage(data.progressMessage ?? `Rendering… ${p}%`); setProgressMessage(data.progressMessage ?? `Rendering… ${p}%`);
if (data.previewB64) setPreviewB64(data.previewB64); if (data.previewB64) setPreviewB64(data.previewB64);
// ETA from the observed progress rate. // ETA: prefer the server's estimate (elapsed vs. progress); otherwise fall
if (p > 0 && p < 100) { // back to the client-observed progress rate.
if (typeof data.etaSeconds === "number" && data.etaSeconds >= 0 && p < 100) {
setEtaSec(data.etaSeconds);
} else if (p > 0 && p < 100) {
const now = Date.now(); const now = Date.now();
const base = etaBaseRef.current; const base = etaBaseRef.current;
if (!base || p < base.p) { if (!base || p < base.p) {
@@ -33,5 +33,6 @@ export async function GET(_request: Request, context: RouteContext) {
progressMessage: job.progress_message, progressMessage: job.progress_message,
errorMessage: job.error_message, errorMessage: job.error_message,
previewB64: job.preview_b64 ?? null, previewB64: job.preview_b64 ?? null,
etaSeconds: job.eta_seconds ?? null,
}); });
} }
+4
View File
@@ -33,6 +33,8 @@ export interface RenderJobRow {
error_message: string | null; error_message: string | null;
/** Base64-encoded PNG preview frame pushed by the node agent. Null until first frame arrives. */ /** Base64-encoded PNG preview frame pushed by the node agent. Null until first frame arrives. */
preview_b64: string | null; preview_b64: string | null;
/** Estimated seconds remaining (server extrapolation from elapsed + progress). Null until progressing. */
eta_seconds: number | null;
} }
// ── Helpers ────────────────────────────────────────────────────────────────── // ── Helpers ──────────────────────────────────────────────────────────────────
@@ -123,6 +125,7 @@ export async function getRenderJob(
progress?: number; progress?: number;
message?: string; message?: string;
preview_b64?: string | null; preview_b64?: string | null;
eta_seconds?: number | null;
} | null; } | null;
if (!progress) return null; if (!progress) return null;
@@ -165,6 +168,7 @@ export async function getRenderJob(
error_message: error_message:
status === "failed" ? (progress.message ?? "Render failed") : null, status === "failed" ? (progress.message ?? "Render failed") : null,
preview_b64: progress.preview_b64 ?? null, preview_b64: progress.preview_b64 ?? null,
eta_seconds: progress.eta_seconds ?? null,
}; };
} }