feat(compile): stream live ESP-IDF cmake + ninja output to the console

A user reported on Discord: "the Velxio Console doesn't update anything,
it just waits until the very end and displays everything in one go".
True for the async compile path — /compile/status only carried `state`
and the final `result`, so the editor's CompilationConsole stayed empty
during the 5-7 minute cold ESP-IDF builds and dumped 1500 lines at once
when the build finished.

This wires live build output through the whole stack.

Backend (espidf_compiler.py)
- New _run_with_streaming() helper. When a progress_callback is provided
  it spawns the subprocess via Popen + stdout/stderr drain threads and
  invokes the callback line-by-line. When None it falls back to the
  existing subprocess.run(capture_output=True) one-shot path so the
  unit-test code that doesn't care about live output is unaffected.
- compile() and _compile_in_dir() take an optional ProgressCallback.
- _run_cmake / _run_ninja closures now go through _run_with_streaming
  with that callback. cmake configure (~2-5 s) + ninja (~5-300+ s) both
  stream now; the ninja output is the one users actually want to watch.

Backend (compile.py)
- _compile_job seeds COMPILE_JOBS[id]['stdout_buffer'] = '' and defines
  on_progress_line(line) which appends to it. Buffer capped at 256 KB
  (tail kept) so a runaway build can't OOM the FastAPI process.
- The buffer is preserved on both the success and the error path so
  late polls still see the log even after state transitions to
  done/error.
- /compile/status now returns the buffer as a `stdout` field.
  CompileStatusResponse gains the field with default '' so old clients
  that don't read it still work.

Frontend (compilation.ts)
- compileCode() takes a 4th argument: optional CompileProgress
  callback fired every poll while state ∈ {pending, running}. Carries
  the cumulative stdout (caller computes deltas) plus elapsed seconds.
- Surfaces the new `stdout` field of /compile/status and forwards it
  to the callback. Errors thrown from the callback are swallowed —
  a faulty UI hook must never break the polling loop.

Frontend (EditorToolbar.tsx)
- Both compileCode() call sites (Run and Compile-All) now pass an
  onProgress callback. It tracks `lastStreamedLen` per-compile, splits
  each new delta on newlines, and appends them as `info`-typed
  CompilationLog entries via setCompileLogs. The Compile-All flow
  prefixes each line with the board label so multi-board builds stay
  readable.
- After the build settles, the existing parseCompileResult call still
  runs and appends the structured analysis on top of the live stream
  — that's where FAILED-block detection + the `error`-typed entries
  that drive the auto-switch-to-errors filter live.

Net effect on the user complaint: cold ESP-IDF builds now show the
ninja [N/1483] progress lines streaming into the console as they
happen, instead of staring at an empty panel for 5-7 minutes.

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
This commit is contained in:
davidmonterocrespo24 2026-05-09 23:36:58 +02:00
parent e1eec8124b
commit 4a42a3e9a2
4 changed files with 262 additions and 17 deletions

View File

@ -152,11 +152,21 @@ def _resolve_files(request: CompileRequest) -> list[dict[str, str]]:
async def _run_compile(
request: CompileRequest,
files: list[dict[str, str]],
progress_callback: Any = None,
) -> CompileResponse:
"""Do the actual compile (ESP-IDF for esp32:*, arduino-cli otherwise)."""
"""Do the actual compile (ESP-IDF for esp32:*, arduino-cli otherwise).
`progress_callback`, if provided, receives every stdout/stderr line as
cmake + ninja run. Wired into the async compile path so the live build
output is exposed via /api/compile/status/{job_id}'s `stdout` field.
AVR / RP2040 builds via arduino-cli don't surface progress yet — those
typically finish in seconds anyway.
"""
if request.board_fqbn.startswith("esp32:") and espidf_compiler.available:
logger.info(f"[compile] Using ESP-IDF for {request.board_fqbn}")
result = await espidf_compiler.compile(files, request.board_fqbn)
result = await espidf_compiler.compile(
files, request.board_fqbn, progress_callback=progress_callback,
)
return CompileResponse(
success=result["success"],
hex_content=result.get("hex_content"),
@ -241,11 +251,34 @@ async def _compile_job(
`state=pending` while waiting on either gate; transitions to `running`
only once the actual build is about to start, so clients polling
/compile/status see an accurate snapshot of where their job is.
Live build output is appended to COMPILE_JOBS[job_id]['stdout_buffer']
line-by-line as cmake + ninja emit it, so /compile/status responses
stream a growing log instead of returning everything at the end.
"""
started = time.monotonic()
job = COMPILE_JOBS[job_id]
started_at = job["started_at"]
job_key = job.get("key")
# Live stdout buffer — written from a worker thread (espidf_compiler
# drain threads). dict[str].update with a single str assignment is GIL-
# protected so we don't need an explicit lock; the polling endpoint
# reads the same field.
COMPILE_JOBS[job_id]["stdout_buffer"] = ""
def on_progress_line(line: str) -> None:
# Cap buffer at 256 KB so a runaway build can't OOM the process.
# Keep the tail (most recent output) — that's what the user wants
# to see anyway.
current = COMPILE_JOBS.get(job_id)
if current is None:
return
new = (current.get("stdout_buffer", "") or "") + line
if len(new) > 262_144:
new = new[-262_144:]
current["stdout_buffer"] = new
try:
async with _COMPILE_SEMAPHORE:
async with _target_lock(request.board_fqbn):
@ -255,13 +288,19 @@ async def _compile_job(
logger.info(f"[compile] job {job_id} purged before run; skipping")
return
COMPILE_JOBS[job_id]["state"] = "running"
response = await _run_compile(request, files)
response = await _run_compile(
request, files, progress_callback=on_progress_line,
)
COMPILE_JOBS[job_id] = {
"state": "done",
"started_at": started_at,
"finished_at": time.time(),
"result": response.model_dump(),
"key": job_key,
# Preserve the streamed buffer post-completion so a late poll
# still has access to the live log (clients usually display
# result.stdout once state=done, but having both costs nothing).
"stdout_buffer": COMPILE_JOBS.get(job_id, {}).get("stdout_buffer", ""),
}
error_kind = (
None if response.success
@ -284,6 +323,7 @@ async def _compile_job(
"finished_at": time.time(),
"error": str(exc)[:500],
"key": job_key,
"stdout_buffer": COMPILE_JOBS.get(job_id, {}).get("stdout_buffer", ""),
}
await _record_async_metric(
user_id=user_id,
@ -355,6 +395,11 @@ class CompileStatusResponse(BaseModel):
state: str # 'pending' | 'running' | 'done' | 'error'
started_at: float
finished_at: float | None = None
# Live build output. Grows line-by-line during state=running so the
# frontend can stream it into the compilation console instead of
# waiting for everything to land at the end. Capped at 256 KB
# (most recent tail kept).
stdout: str = ""
result: CompileResponse | None = None
error: str | None = None
@ -406,7 +451,14 @@ async def compile_start(
@router.get("/status/{job_id}", response_model=CompileStatusResponse)
async def compile_status(job_id: str):
"""Poll the status of an async compile job submitted via /compile/start."""
"""Poll the status of an async compile job submitted via /compile/start.
`stdout` carries live cmake + ninja output captured line-by-line as
the build runs. Clients should poll every 1-2s and re-render the
full string each time (or compute a length delta). Once state=done,
`result.stdout` carries the same content too both are kept so a
late-arriving poll always has the log available.
"""
job = COMPILE_JOBS.get(job_id)
if not job:
raise HTTPException(status_code=404, detail="job not found or expired")
@ -414,6 +466,7 @@ async def compile_status(job_id: str):
state=job["state"],
started_at=job["started_at"],
finished_at=job.get("finished_at"),
stdout=job.get("stdout_buffer", "") or "",
result=job.get("result"),
error=job.get("error"),
)

View File

@ -22,7 +22,10 @@ import re
import shutil
import subprocess
import tempfile
import threading
from dataclasses import dataclass
from pathlib import Path, PurePosixPath
from typing import Callable, Optional
logger = logging.getLogger(__name__)
@ -73,6 +76,96 @@ def _idf_version_signature() -> str:
return '|'.join(parts)
# Type for live progress callback. Called from a worker thread for every
# stdout/stderr line as the build runs. Implementations should be cheap and
# thread-safe (callers commonly stash lines into a dict shared with the main
# event loop). Exceptions raised from the callback are swallowed so a faulty
# UI hook can never break the build.
ProgressCallback = Callable[[str], None]
@dataclass
class _RunResult:
"""Drop-in replacement for the fields we read off subprocess.CompletedProcess."""
returncode: int
stdout: str
stderr: str
def _run_with_streaming(
cmd: list[str],
*,
cwd: str,
env: dict[str, str],
timeout: float,
progress_callback: Optional[ProgressCallback],
) -> _RunResult:
"""Run `cmd` synchronously and stream stdout + stderr line-by-line.
Behaves like subprocess.run(capture_output=True, text=True) but invokes
`progress_callback(line)` for every line as it arrives. When
progress_callback is None this falls back to a single subprocess.run call
so we don't pay the threading cost on the unit-test path that doesn't
care about live output.
Raises subprocess.TimeoutExpired on timeout (matches the existing flow).
"""
if progress_callback is None:
cp = subprocess.run(
cmd, cwd=cwd, env=env, capture_output=True, text=True, timeout=timeout,
)
return _RunResult(returncode=cp.returncode, stdout=cp.stdout, stderr=cp.stderr)
proc = subprocess.Popen(
cmd,
cwd=cwd,
env=env,
stdout=subprocess.PIPE,
stderr=subprocess.PIPE,
text=True,
bufsize=1, # line-buffered
)
stdout_lines: list[str] = []
stderr_lines: list[str] = []
def _drain(stream, sink: list[str]) -> None:
try:
for line in iter(stream.readline, ''):
sink.append(line)
try:
progress_callback(line)
except Exception:
# A faulty progress sink must never break the build.
pass
finally:
try:
stream.close()
except Exception:
pass
t_out = threading.Thread(target=_drain, args=(proc.stdout, stdout_lines), daemon=True)
t_err = threading.Thread(target=_drain, args=(proc.stderr, stderr_lines), daemon=True)
t_out.start()
t_err.start()
try:
proc.wait(timeout=timeout)
except subprocess.TimeoutExpired:
proc.kill()
# Give drain threads a chance to flush before we raise.
t_out.join(timeout=2)
t_err.join(timeout=2)
raise
t_out.join(timeout=5)
t_err.join(timeout=5)
return _RunResult(
returncode=proc.returncode,
stdout=''.join(stdout_lines),
stderr=''.join(stderr_lines),
)
def _prepare_persistent_project_dir(idf_target: str) -> Path:
"""Return the path to a per-target persistent project dir, materialising
it from the template on first use and resetting the per-compile parts
@ -883,7 +976,12 @@ class ESPIDFCompiler:
)
return merged_path
async def compile(self, files: list[dict], board_fqbn: str) -> dict:
async def compile(
self,
files: list[dict],
board_fqbn: str,
progress_callback: Optional[ProgressCallback] = None,
) -> dict:
"""
Compile Arduino sketch using ESP-IDF.
@ -901,6 +999,11 @@ class ESPIDFCompiler:
The caller (routes/compile.py:_compile_job) holds a per-target
asyncio.Lock for the duration of this call, so the persistent dir
is never accessed by two compiles at once.
progress_callback (optional): if provided, called from a worker
thread for every stdout/stderr line as cmake and ninja run. Used
by the async compile path to expose live build output to clients
polling /api/compile/status/{job_id}.
"""
if not self.available:
return {
@ -919,13 +1022,17 @@ class ESPIDFCompiler:
if _USE_PERSISTENT_DIR:
project_dir = _prepare_persistent_project_dir(idf_target)
logger.info(f'[espidf] Using persistent build dir: {project_dir}')
return await self._compile_in_dir(project_dir, files, idf_target, is_c3)
return await self._compile_in_dir(
project_dir, files, idf_target, is_c3, progress_callback,
)
with tempfile.TemporaryDirectory(prefix='espidf_') as temp_dir:
project_dir = Path(temp_dir) / 'project'
shutil.copytree(_TEMPLATE_DIR, project_dir)
logger.info(f'[espidf] Using ephemeral build dir: {project_dir}')
return await self._compile_in_dir(project_dir, files, idf_target, is_c3)
return await self._compile_in_dir(
project_dir, files, idf_target, is_c3, progress_callback,
)
async def _compile_in_dir(
self,
@ -933,6 +1040,7 @@ class ESPIDFCompiler:
files: list[dict],
idf_target: str,
is_c3: bool,
progress_callback: Optional[ProgressCallback] = None,
) -> dict:
"""Inner compile body: writes sketch + libs into `project_dir`,
runs cmake + ninja, merges binaries. Caller is responsible for
@ -1075,13 +1183,12 @@ class ESPIDFCompiler:
logger.info(f'[espidf] cmake: {" ".join(cmake_cmd)}')
def _run_cmake():
return subprocess.run(
return _run_with_streaming(
cmake_cmd,
cwd=str(build_dir),
capture_output=True,
text=True,
env=env,
timeout=120,
progress_callback=progress_callback,
)
try:
@ -1115,13 +1222,12 @@ class ESPIDFCompiler:
NINJA_TIMEOUT_S = 600
def _run_ninja():
return subprocess.run(
return _run_with_streaming(
ninja_cmd,
cwd=str(build_dir),
capture_output=True,
text=True,
env=env,
timeout=NINJA_TIMEOUT_S,
progress_callback=progress_callback,
)
try:

View File

@ -198,8 +198,38 @@ export const EditorToolbar = ({
name: f.name,
content: f.content,
}));
const result = await compileCode(sketchFiles, fqbn, currentProject?.id ?? null);
// Stream live cmake + ninja output into the compilation console as
// it arrives, instead of waiting for the whole build to finish.
// Each poll the backend returns the cumulative stdout buffer; we
// append only the delta since the previous call as 'info' lines.
let lastStreamedLen = 0;
const result = await compileCode(
sketchFiles,
fqbn,
currentProject?.id ?? null,
({ stdout }) => {
if (stdout.length <= lastStreamedLen) return;
const delta = stdout.slice(lastStreamedLen);
lastStreamedLen = stdout.length;
const newLines = delta.split('\n').filter((s) => s.trim());
if (!newLines.length) return;
const now = new Date();
setCompileLogs((prev: CompilationLog[]) => [
...prev,
...newLines.map((line) => ({
timestamp: now,
type: 'info' as const,
message: line,
})),
]);
},
);
// After the build settles, append the structured analysis on top of
// the live stream — parseCompileResult highlights FAILED blocks and
// tags compiler errors with type='error', which the console uses for
// colour + the auto-switch-to-errors filter.
const resultLogs = parseCompileResult(result, boardLabel);
setCompileLogs((prev: CompilationLog[]) => [...prev, ...resultLogs]);
@ -456,7 +486,31 @@ export const EditorToolbar = ({
try {
const groupFiles = useEditorStore.getState().getGroupFiles(board.activeFileGroupId);
const sketchFiles = groupFiles.map((f) => ({ name: f.name, content: f.content }));
const result = await compileCode(sketchFiles, fqbn, currentProject?.id ?? null);
// Stream live cmake + ninja output per-board (Compile-All flow).
let lastStreamedLen = 0;
const result = await compileCode(
sketchFiles,
fqbn,
currentProject?.id ?? null,
({ stdout }) => {
if (stdout.length <= lastStreamedLen) return;
const delta = stdout.slice(lastStreamedLen);
lastStreamedLen = stdout.length;
const newLines = delta.split('\n').filter((s) => s.trim());
if (!newLines.length) return;
const now = new Date();
setCompileLogs((prev: CompilationLog[]) => [
...prev,
...newLines.map((line) => ({
timestamp: now,
type: 'info' as const,
message: `${label}: ${line}`,
})),
]);
},
);
const resultLogs = parseCompileResult(result, label);
setCompileLogs((prev: CompilationLog[]) => [...prev, ...resultLogs]);

View File

@ -27,10 +27,23 @@ interface CompileStatusResponse {
state: 'pending' | 'running' | 'done' | 'error';
started_at: number;
finished_at: number | null;
stdout: string;
result: CompileResult | null;
error: string | null;
}
/**
* Live progress callback called on every poll while state {pending,
* running}. `stdout` is the full live cmake + ninja output captured so far
* (cap of ~256 KB on the server side, tail kept). Caller can compute a
* delta against the previous call if it wants to append-only render.
*/
export type CompileProgress = (info: {
state: 'pending' | 'running';
stdout: string;
elapsedSeconds: number;
}) => void;
const POLL_INTERVAL_MS = 2000;
const MAX_POLL_DURATION_MS = 15 * 60 * 1000; // 15 minutes — covers cold ESP-IDF builds
@ -40,16 +53,21 @@ const sleep = (ms: number) => new Promise((r) => setTimeout(r, ms));
* Compile a sketch via the async job pipeline.
*
* POST /compile/start { job_id }
* GET /compile/status/<job_id> (×N) { state, result?, error? }
* GET /compile/status/<job_id> (×N) { state, stdout, result?, error? }
*
* Each individual request returns in milliseconds, so Cloudflare's 100s edge
* timeout never kicks in even when the underlying ESP-IDF cold build runs
* for 5-7 minutes. Falls back to throwing an Error after MAX_POLL_DURATION_MS.
*
* `onProgress` (optional): called every poll with the live cmake + ninja
* output so the editor can stream the compilation console instead of
* waiting for everything at the end.
*/
export async function compileCode(
files: SketchFile[],
board: string = 'arduino:avr:uno',
projectId?: string | null,
onProgress?: CompileProgress,
): Promise<CompileResult> {
console.log('Sending compilation request to:', `${API_BASE}/compile/start`);
console.log('Board:', board);
@ -119,12 +137,26 @@ export async function compileCode(
console.error(`[compile] job ${jobId} errored:`, status.error);
return {
success: false,
stdout: '',
stdout: status.stdout || '',
stderr: '',
error: status.error || 'Compile failed',
};
}
// state ∈ {pending, running} — surface live build output if requested
if (onProgress) {
try {
onProgress({
state: status.state,
stdout: status.stdout || '',
elapsedSeconds: Math.round((Date.now() - startedAt) / 1000),
});
} catch (err) {
// A faulty UI hook must never break the polling loop.
console.warn('[compile] onProgress threw:', err);
}
}
await sleep(POLL_INTERVAL_MS);
}
}