From 5c004ec3ce8ace90a92b7a72caa02be06bc556a5 Mon Sep 17 00:00:00 2001 From: David Steele Date: Fri, 31 Jul 2026 23:21:47 +0700 Subject: [PATCH] Trim the stack trace the tools show and report ctrl-c as a signal. A ctrl-c raised KeyboardInterrupt out of main() and python printed the traceback, which is the whole path from main() down to the select() the harness happened to be waiting in and says nothing about a run that was stopped on purpose. Catch it and log "terminated on signal SIGINT" as the C does, exiting with the status the C exits with for TermError. An unexpected exception is a bug in the tool so the trace is what gets it fixed, but the trace ends with the message that says what went wrong, which is where the message gets lost. Show the message first and keep only the innermost frames, since the frames above them are the path from main() into the tool and are much the same for every error. The frame count says how many were dropped and how to get them, and the complete trace, which is what python printed before, is shown at debug level the same way the C shows a stack trace only at debug level. The rendering is error_trace() in common/error.py, beside ToolError, so every tool reports a bug in itself the same way. The CI wrapper asks for the complete trace since a run there cannot be repeated at debug level to get it, and the code builder handles the interrupt but not the trace since it has no log level to raise. --- build/build.py | 7 ++- build/lib/common/error.py | 38 +++++++++++++- doc/doc.py | 14 +++-- doc/release.py | 14 +++-- test/ci.py | 15 ++++-- test/src/module/build/common/error_test.py | 59 ++++++++++++++++++++++ test/test.py | 14 +++-- 7 files changed, 139 insertions(+), 22 deletions(-) diff --git a/build/build.py b/build/build.py index 34377db7b..aac95f91f 100755 --- a/build/build.py +++ b/build/build.py @@ -21,7 +21,7 @@ sys.dont_write_bytecode = True sys.path.insert(0, os.path.join(os.path.dirname(os.path.abspath(__file__)), "lib")) from command.main import cfg_load, cmd_build # noqa: E402 -from common.error import ToolError # noqa: E402 +from common.error import EXIT_TERM, ToolError # noqa: E402 #################################################################################################################################### @@ -35,6 +35,11 @@ def main(): try: config = cfg_load(sys.argv[1:], path_repo) cmd_build(config) + except KeyboardInterrupt: + # A ctrl-c is what was asked for, so report it the way the C reports a signal rather than as a stack trace + print("ERROR: terminated on signal SIGINT") + + return EXIT_TERM except ToolError as error: print("ERROR: %s" % error) diff --git a/build/lib/common/error.py b/build/lib/common/error.py index e5a616472..f9b341214 100644 --- a/build/lib/common/error.py +++ b/build/lib/common/error.py @@ -1,12 +1,23 @@ """Error Handling. Each tool reports failures with ToolError, which carries the exit status to return. Exit status mirrors the C: 0 is success, 1 means a -top-level coverage check found modules missing coverage, and anything greater is an error.""" +top-level coverage check found modules missing coverage, and anything greater is an error. + +Anything else that gets out of a tool is a bug in the tool, which error_trace() renders the way the C renders a stack trace: enough to +find the bug without burying the message that says what it was.""" #################################################################################################################################### +import traceback + # Exit status for an error. Distinct from 1, which a coverage command uses to report incomplete coverage rather than a failure. EXIT_ERROR = 2 +# Exit status when a signal terminated the tool, the same status the C exits with for TermError +EXIT_TERM = 63 + +# Innermost frames of a stack trace to show when it is trimmed +TRACE_FRAME_MAX = 6 + #################################################################################################################################### class ToolError(Exception): @@ -17,6 +28,31 @@ class ToolError(Exception): self.status = status +#################################################################################################################################### +def error_trace(error, full=False): + """Render an unexpected exception and its stack trace. + + An unexpected exception is a bug in the tool rather than a problem with what the tool was working on, so the stack trace is what + gets it fixed. Only the innermost frames are shown, since the frames above them are the path from main() into the tool and are + long enough to bury the message that says what went wrong. + + The complete trace, including any exception this one was raised while handling, is rendered when full is set, which is what the + tools do at debug level as the C shows a stack trace only at debug level.""" + + frame_list = traceback.extract_tb(error.__traceback__) + + # There is nothing to trim when the whole trace is already short enough, so render it as python does + if full or len(frame_list) <= TRACE_FRAME_MAX: + return "".join(traceback.format_exception(type(error), error, error.__traceback__)).rstrip("\n") + + # The message comes first so it is what gets read, followed by the frames in the order python reports them + return ( + "".join(traceback.format_exception_only(type(error), error)).rstrip("\n") + + "\nstack trace (innermost %u of %u frames, --log-level=debug shows all of them):\n" % (TRACE_FRAME_MAX, len(frame_list)) + + "".join(traceback.format_list(frame_list[-TRACE_FRAME_MAX:])).rstrip("\n") + ) + + #################################################################################################################################### def check(condition, message): """Raise ToolError when a condition does not hold. diff --git a/doc/doc.py b/doc/doc.py index 697245f8e..279b6f039 100755 --- a/doc/doc.py +++ b/doc/doc.py @@ -10,7 +10,6 @@ Exit status: 0 = success, greater = error.""" import os import signal import sys -import traceback # Do not cache bytecode. The tool runs from the source tree, where a __pycache__ would show up as an unexpected binary file in the # linter and in the distribution. This must be set before the library modules are imported below. @@ -22,7 +21,7 @@ for lib in ("build", "doc"): sys.path.insert(0, os.path.join(os.path.dirname(os.path.dirname(os.path.abspath(__file__))), lib, "lib")) from command.doc import cfg_load, cmd_doc # noqa: E402 -from common.error import EXIT_ERROR, ToolError # noqa: E402 +from common.error import EXIT_ERROR, EXIT_TERM, ToolError, error_trace # noqa: E402 from common.log import * # noqa: E402 @@ -48,13 +47,18 @@ def main(): try: cmd_doc(config) + except KeyboardInterrupt: + # A ctrl-c is what was asked for, so report it the way the C reports a signal rather than as a stack trace + log(ERROR, "terminated on signal SIGINT") + + return EXIT_TERM except ToolError as error: log(ERROR, error) return error.status - except Exception: - # An unexpected exception is a bug here rather than a problem with the documentation, so show the traceback - print(traceback.format_exc()) + except Exception as error: + # An unexpected exception is a bug here rather than a problem with the documentation, so show the stack trace + log(ERROR, error_trace(error, config.log_level >= DEBUG)) return EXIT_ERROR diff --git a/doc/release.py b/doc/release.py index d03a4d9d5..46f307901 100755 --- a/doc/release.py +++ b/doc/release.py @@ -18,7 +18,6 @@ import re import shutil import signal import sys -import traceback # Send everything written to stderr to stdout instead so the output is in the order it happened sys.stderr = sys.stdout @@ -33,7 +32,7 @@ for lib in ("build", "doc"): sys.path.insert(0, os.path.join(os.path.dirname(os.path.dirname(os.path.abspath(__file__))), lib, "lib")) from command.render.release import release_last # noqa: E402 -from common.error import EXIT_ERROR, ToolError # noqa: E402 +from common.error import EXIT_ERROR, EXIT_TERM, ToolError, error_trace # noqa: E402 from common.exec import exec_result # noqa: E402 from common.log import * # noqa: E402 from common.storage import file_read, file_remove, file_write # noqa: E402 @@ -382,13 +381,18 @@ def main(): try: return command_run(config) + except KeyboardInterrupt: + # A ctrl-c is what was asked for, so report it the way the C reports a signal rather than as a stack trace + log(ERROR, "terminated on signal SIGINT") + + return EXIT_TERM except ToolError as error: log(ERROR, error) return error.status - except Exception: - # An unexpected exception is a bug here rather than a problem with the release, so show the traceback - print(traceback.format_exc()) + except Exception as error: + # An unexpected exception is a bug here rather than a problem with the release, so show the stack trace + log(ERROR, error_trace(error, config.log_level >= DEBUG)) return EXIT_ERROR diff --git a/test/ci.py b/test/ci.py index 9755ac44b..47c9ff19e 100755 --- a/test/ci.py +++ b/test/ci.py @@ -15,7 +15,6 @@ import os import signal import sys import time -import traceback # Send everything written to stderr to stdout instead so the output is in the order it happened sys.stderr = sys.stdout @@ -29,7 +28,7 @@ sys.dont_write_bytecode = True for lib in ("build", "doc", "test"): sys.path.insert(0, os.path.join(os.path.dirname(os.path.dirname(os.path.abspath(__file__))), lib, "lib")) -from common.error import EXIT_ERROR, ToolError # noqa: E402 +from common.error import EXIT_ERROR, EXIT_TERM, ToolError, error_trace # noqa: E402 from common.exec import exec_one # noqa: E402 from common.log import * # noqa: E402 from common.user import user_name # noqa: E402 @@ -190,13 +189,19 @@ def main(): try: return command_run(cfg_load(sys.argv[1:], path_repo)) + except KeyboardInterrupt: + # A ctrl-c is what was asked for, so report it the way the C reports a signal rather than as a stack trace + log(ERROR, "terminated on signal SIGINT") + + return EXIT_TERM except ToolError as error: log(ERROR, error) return error.status - except Exception: - # An unexpected exception is a bug here rather than a problem with the run, so show the traceback - print(traceback.format_exc()) + except Exception as error: + # An unexpected exception is a bug here rather than a problem with the run, so show the stack trace. The complete trace is + # shown since a run cannot be repeated at debug level to get it, and there is no terminal here for it to get in the way of. + log(ERROR, error_trace(error, True)) return EXIT_ERROR diff --git a/test/src/module/build/common/error_test.py b/test/src/module/build/common/error_test.py index 77172a208..bdbacb98d 100644 --- a/test/src/module/build/common/error_test.py +++ b/test/src/module/build/common/error_test.py @@ -31,6 +31,65 @@ def test_error_status(): # The default is distinct from the incomplete coverage status so the two are never confused assert_not_equal(EXIT_ERROR, 1) + # A run that was terminated by a signal is distinct from one that failed + assert_not_equal(EXIT_TERM, EXIT_ERROR) + assert_not_equal(EXIT_TERM, 1) + + +#################################################################################################################################### +def _raise_nested(depth): + """Raise from depth nested calls.""" + + if depth > 0: + _raise_nested(depth - 1) + + raise ValueError("something unexpected") + + +#################################################################################################################################### +def _error_nested(depth): + """Return an exception raised from depth nested calls, so its trace has depth + 2 frames. + + The exception is caught here rather than with assert_raises(), which clears the traceback the test needs.""" + + try: + _raise_nested(depth) + except ValueError as error: + return error + + +#################################################################################################################################### +def test_error_trace_trim(): + """A trace with more frames than the limit keeps the innermost of them and says how many there were.""" + + error = _error_nested(TRACE_FRAME_MAX) + trace = error_trace(error) + + # The message comes first so a trace cannot bury it, and the frame count says what is missing and how to get it + assert_true(trace.startswith("ValueError: something unexpected\n")) + assert_in("stack trace (innermost %u of %u frames" % (TRACE_FRAME_MAX, TRACE_FRAME_MAX + 2), trace) + assert_in("--log-level=debug", trace) + + # The frames kept are the innermost ones, so the trace is shorter than the complete one and ends where the error was raised + assert_true(len(trace.splitlines()) < len(error_trace(error, True).splitlines())) + assert_true(trace.endswith('raise ValueError("something unexpected")')) + + +#################################################################################################################################### +def test_error_trace_full(): + """The complete trace is python's own, which is what debug level gets and what a trace short enough to keep gets anyway.""" + + trace = error_trace(_error_nested(TRACE_FRAME_MAX), True) + + assert_true(trace.startswith("Traceback (most recent call last):\n")) + assert_true(trace.endswith("ValueError: something unexpected")) + + # A trace with no more frames than the limit is not trimmed, so there is nothing to say about what was dropped + trace = error_trace(_error_nested(0)) + + assert_true(trace.startswith("Traceback (most recent call last):\n")) + assert_not_in("innermost", trace) + #################################################################################################################################### def test_check_pass(): diff --git a/test/test.py b/test/test.py index 1eb5a45ae..a74dca58b 100755 --- a/test/test.py +++ b/test/test.py @@ -13,7 +13,6 @@ import os import signal import sys import time -import traceback # Send everything written to stderr to stdout instead. Anything a test writes to stderr is a failure, so an error raised before # the handler in main() is installed, e.g. while importing below, would otherwise look like one. @@ -32,7 +31,7 @@ from command.code.format import cmd_code_format # noqa: E402 from command.test.test import cmd_test # noqa: E402 from command.test.unit import cmd_unit # noqa: E402 from command.vm.build import cmd_vm_build # noqa: E402 -from common.error import EXIT_ERROR, ToolError # noqa: E402 +from common.error import EXIT_ERROR, EXIT_TERM, ToolError, error_trace # noqa: E402 from common.log import * # noqa: E402 from config.config import cfg_load # noqa: E402 from config.project import project_version # noqa: E402 @@ -77,14 +76,19 @@ def main(): try: result = command_run(config) + except KeyboardInterrupt: + # A ctrl-c is what was asked for, so report it the way the C reports a signal rather than as a stack trace + log(ERROR, "terminated on signal SIGINT") + + return EXIT_TERM except ToolError as error: log(ERROR, error) log(INFO, "%s command end: aborted with exception" % config.command) return error.status - except Exception: - # An unexpected exception is a harness bug, so show the traceback. It goes to stdout like everything else. - print(traceback.format_exc()) + except Exception as error: + # An unexpected exception is a harness bug, so show the stack trace. It goes to stdout like everything else. + log(ERROR, error_trace(error, config.log_level >= DEBUG)) return EXIT_ERROR