Skip to content

Error messages can be lost/truncated when tfx is run as a child process and fails #566

Description

Summary

When tfx fails and exits via the CLI's error handler, error output written to stderr can be lost or truncated. This is most noticeable when tfx is invoked as a child process by another tool (e.g. a build task, a CI pipeline step, or a wrapper script) that pipes/redirects its stdout/stderr.

Root cause

app/lib/errorhandler.ts's errLog() handler does:

export function errLog(arg: any): void {
    trace.debug(arg?.stack);
    trace.error(formatError(arg));
    process.exit(-1);
}

trace.error() ultimately calls console.error(), which writes to process.stderr. When stderr is a TTY, this write is synchronous, so it's safe to call process.exit() immediately afterwards. However, when stderr is piped or redirected (which is exactly what happens when tfx is spawned as a child process with stdio: 'pipe'), writes to it become asynchronous.

Calling process.exit() immediately after an async write does not wait for that write to flush. Per the Node.js docs:

In most situations, it is not actually necessary to call process.exit() explicitly... Node.js will exit by itself once the event loop no longer has any additional work to schedule. ... calling process.exit() will force the process to exit as quickly as possible even if there are still asynchronous operations pending that have not yet completed fully, including I/O operations to process.stdout and process.stderr.

As a result, the last (and most important) line(s) of error output — the actual failure message — can be silently dropped or truncated before the parent process finishes reading tfx's stderr. This is especially confusing since the process still exits with a non-zero code, but the accompanying error message is missing, making the failure very hard to diagnose from CI logs.

Reproduction

  1. Invoke tfx from a parent process that pipes stdio, e.g. from Node:
    const { spawnSync } = require('child_process');
    const result = spawnSync('tfx', ['extension', 'isvalid', '--publisher', 'x', '--extension-id', 'y'], { stdio: 'pipe' });
    console.log('stderr:', result.stderr.toString());
  2. Trigger a failure path in tfx (e.g. invalid credentials, unreachable service, invalid arguments).
  3. Observe that stderr captured by the parent process is empty or missing the final error line, even though tfx exited with a non-zero exit code.

This is more likely to reproduce on larger error messages (e.g. formatted AggregateError output with multiple lines) and on Windows, where pipes have smaller buffers, but can happen with any redirected stderr.

Proposed fix

Stop calling process.exit() explicitly in errLog(). Instead, set process.exitCode = -1; and let Node.js exit naturally once the event loop drains. This is exactly what the successful command path already does today (app/app.ts's Bootstrap.begin().then(() => {}) never calls process.exit() either), so this makes the error path consistent with the success path and guarantees all buffered output is flushed before the process terminates.

export function errLog(arg: any): void {
    trace.debug(arg?.stack);
    trace.error(formatError(arg));
    process.exitCode = -1;
}

Alternative fix

If explicitly terminating the process is still desired (e.g. to avoid waiting on unrelated open handles), an alternative is to deliberately drain stdout/stderr before exiting, only calling process.exit() once any pending writes have completed:

function flushAndExit(code: number): void {
    const streams = [process.stdout, process.stderr];
    let pending = 0;

    const tryExit = () => {
        if (pending <= 0) {
            process.exit(code);
        }
    };

    streams.forEach(stream => {
        if (stream && stream.writableLength > 0) {
            pending++;
            stream.write("", () => {
                pending--;
                tryExit();
            });
        }
    });

    tryExit();
}

This preserves the current "hard exit" behavior while ensuring queued writes are flushed first. Note: we evaluated using the (unmaintained, 2013) exit npm package for this, but found it monkey-patches stream.write to a permanent no-op and registers a process.on('exit', ...) listener that forcibly re-exits — behavior that is unsafe for anything other than a true one-shot process, so we don't recommend it here.

Suggested resolution

A PR implementing the first ("stop calling process.exit() explicitly") option will be linked to this issue.

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions