diff --git a/common/prefix.py b/common/prefix.py index b19ce1472..b24872a40 100644 --- a/common/prefix.py +++ b/common/prefix.py @@ -50,7 +50,10 @@ class OpenpilotPrefix: symlink_path = Params().get_param_path() if os.path.exists(symlink_path): shutil.rmtree(os.path.realpath(symlink_path), ignore_errors=True) - os.remove(symlink_path) + # when the params path is a real directory rather than a symlink, rmtree above already + # removed it and there is no link left to unlink + if os.path.islink(symlink_path): + os.remove(symlink_path) shutil.rmtree(self.msgq_path, ignore_errors=True) if PC: shutil.rmtree(Paths.log_root(), ignore_errors=True) diff --git a/common/utils.py b/common/utils.py index 71b29a0c4..f0dce1daa 100644 --- a/common/utils.py +++ b/common/utils.py @@ -5,7 +5,7 @@ import contextlib import subprocess import time import functools -from subprocess import Popen, PIPE, TimeoutExpired +from subprocess import Popen, PIPE, STDOUT, TimeoutExpired import zstandard as zstd from openpilot.common.swaglog import cloudlog @@ -87,16 +87,20 @@ def run_cmd_default(cmd: list[str], default: str = "", cwd=None, env=None) -> st @contextlib.contextmanager def managed_proc(cmd: list[str], env: dict[str, str]): - proc = Popen(cmd, env=env, stdout=PIPE, stderr=PIPE) - try: - yield proc - finally: - if proc.poll() is None: - proc.terminate() + # capture output to a temp file rather than a pipe. nothing drains the pipe while the process + # runs, so a long lived, chatty child would eventually fill the pipe buffer and block forever. + with tempfile.TemporaryFile() as log_file: + proc = Popen(cmd, env=env, stdout=log_file, stderr=STDOUT) + proc.log_file = log_file try: - proc.wait(timeout=5) - except TimeoutExpired: - proc.kill() + yield proc + finally: + if proc.poll() is None: + proc.terminate() + try: + proc.wait(timeout=5) + except TimeoutExpired: + proc.kill() def retry(attempts=3, delay=1.0, ignore_failure=False): diff --git a/tools/clip/run.py b/tools/clip/run.py index 078146131..be2f3df9e 100755 --- a/tools/clip/run.py +++ b/tools/clip/run.py @@ -34,6 +34,9 @@ RESOLUTION = '2160x1080' SECONDS_TO_WARM = 2 PROC_WAIT_SECONDS = 30*10 RECORD_TAIL_MARGIN = 5 # extra seconds recorded past the requested end, see record_raybig +MAX_CACHED_SEGMENTS = 5 # replay's own default, see tools/replay/main.cc +PROGRESS_INTERVAL = 30 # seconds between progress lines while recording +STALL_WARN_SECONDS = 60 # warn if the output file stops growing for this long OPENPILOT_FONT = str(Path(BASEDIR, 'selfdrive/assets/fonts/Inter-Regular.ttf').resolve()) REPLAY = str(Path(BASEDIR, 'tools/replay/replay').resolve()) @@ -45,6 +48,18 @@ WSLG_X11_DIR = '/mnt/wslg/.X11-unix' logger = logging.getLogger('clip.py') +def proc_output(proc: Popen, tail: int = 4000) -> str: + log_file = getattr(proc, 'log_file', None) + if log_file is None: + return '' + pos = log_file.tell() + log_file.seek(0) + try: + return log_file.read().decode(errors='replace')[-tail:] + finally: + log_file.seek(pos) + + def check_for_failure(procs: list[Popen]): for proc in procs: exit_code = proc.poll() @@ -56,11 +71,9 @@ def check_for_failure(procs: list[Popen]): cmd = str(proc.args[0]) msg = f'{cmd} failed, exit code {exit_code}' logger.error(msg) - stdout, stderr = proc.communicate() - if stdout: - logger.error(stdout.decode()) - if stderr: - logger.error(stderr.decode()) + output = proc_output(proc) + if output: + logger.error(output) raise ChildProcessError(msg) @@ -201,6 +214,13 @@ def validate_title(title: str): return title +def validate_scale(scale: str): + value = float(scale) + if not 0 < value <= 1: + raise ArgumentTypeError('scale must be greater than 0 and at most 1') + return value + + def wait_for_frames(procs: list[Popen]): from cereal.messaging import SubMaster @@ -347,7 +367,33 @@ def record_raybig(ui_proc: Popen, replay_proc: Popen, duration: int, out: str): wait_for_frames(procs) logger.info(f'recording in progress ({duration}s)...') started_at = time.monotonic() - time.sleep(SECONDS_TO_WARM + duration + RECORD_TAIL_MARGIN) + record_for = SECONDS_TO_WARM + duration + RECORD_TAIL_MARGIN + out_path = Path(out) + last_size, grew_at, logged_at = -1, started_at, started_at + + # poll rather than sleeping straight through, so a replay or UI that dies partway is caught + # now instead of after the full duration has elapsed + while (elapsed := time.monotonic() - started_at) < record_for: + check_for_failure(procs) + now = time.monotonic() + size = out_path.stat().st_size if out_path.exists() else 0 + + if size > last_size: + last_size, grew_at = size, now + elif now - grew_at > STALL_WARN_SECONDS: + logger.warning(f'{out} has not grown in {now - grew_at:.0f}s; recording may have stalled') + # the source is the usual suspect, so show what it last reported + output = proc_output(replay_proc, tail=1500) + if output: + logger.warning(f'last replay output:\n{output}') + grew_at = now + + if now - logged_at >= PROGRESS_INTERVAL: + logger.info(f'recording {elapsed:.0f}/{record_for:.0f}s, {size / 1e6:.0f}MB') + logged_at = now + + time.sleep(1) + check_for_failure(procs) logger.info('stopping recording...') @@ -382,6 +428,7 @@ def clip( target_mb: int, title: str | None, ui: Literal['c3', 'raybig'], + scale: float | None, ): logger.info(f'clipping route {route.name.canonical_name}, start={start} end={end} quality={quality} target_filesize={target_mb}MB') Path(out).resolve().parent.mkdir(parents=True, exist_ok=True) @@ -419,9 +466,10 @@ def clip( "fps=60", ] - # cache enough of the ~60s segments to cover the clip, else replay runs dry partway through - # and loops back on itself, repeating earlier footage - segments_to_cache = math.ceil((end - begin_at) / 60) + 1 + # read far enough ahead that replay doesn't run dry partway through and loop back on itself, + # repeating earlier footage. capped because each cached ~60s segment holds its logs and camera + # video in memory, and a long clip would otherwise try to hold the whole route at once. + segments_to_cache = min(math.ceil((end - begin_at) / 60) + 1, MAX_CACHED_SEGMENTS) replay_cmd = [REPLAY, '--ecam', '-c', str(segments_to_cache), '-s', str(begin_at), '--prefix', prefix] if data_dir: replay_cmd.extend(['--data_dir', data_dir]) @@ -461,6 +509,10 @@ def clip( # the UI defaults to 60fps and tags the export as such, but the per-frame GPU readback # can't sustain that and the clip plays fast. ask for a rate it can actually hit. env['FPS'] = str(FRAMERATE) + # sets the render texture size, which is what gets piped to ffmpeg. left unset, the UI + # picks a scale that fits the screen. + if scale is not None: + env['SCALE'] = str(scale) if use_wslg: logger.info('WSLg detected: rendering against the live desktop display.') @@ -495,6 +547,8 @@ def main(): p.add_argument('-u', '--ui', help='desktop UI to record. raybig exports its own frames, so it also works where screen capture ' 'cannot see the window (e.g. WSLg), but gets no title/metadata overlays', choices=['c3', 'raybig'], default='c3') + p.add_argument('--scale', help='scale the recorded resolution, e.g. 0.5 for half size (raybig only, default is to fit the screen)', + type=validate_scale) args = parse_args(p) validate_env(p, args.ui) exit_code = 1 @@ -511,6 +565,7 @@ def main(): target_mb=args.file_size, title=args.title, ui=args.ui, + scale=args.scale, ) exit_code = 0 except KeyboardInterrupt as e: