Error message improvements
cover Error message improvements
A number of fixes to improve the readability of error messages, primarily for fetch errors, but will improve error output in other situations as well.
(This supersedes the set of patches I sent a couple of days ago.)
The changes (against Poky, but apply cleanly with -p2 against bitbake master) are available in the git repository at:
git://git.yoctoproject.org/poky-contrib paule/errorhandling
http://git.yoctoproject.org/cgit.cgi/poky-contrib/log/?h=paule/errorhandling
Paul Eggleton (8):
bitbake/knotty: don't count errors as warnings in summary bitbake/fetch2: improve error formatting for fetcher errors bitbake/runqueue: avoid "failed" in task summary if nothing did bitbake/fetch2: correctly decode exit signal/status bitbake/knotty: avoid printing full task log when error already
printed
bitbake/fetch2: reduce output for fetch failures bitbake/cooker: avoid printing stack trace for -b match error bitbake/knotty: print task failure summary
bitbake/lib/bb/build.py | 20 ++++++++++++++++---- bitbake/lib/bb/cooker.py | 21 +++++++++++---------- bitbake/lib/bb/fetch2/__init__.py | 29 ++++++++++++++++++++--------- bitbake/lib/bb/runqueue.py | 6 +++++- bitbake/lib/bb/ui/knotty.py | 28 ++++++++++++++++++++++++---- 5 files changed, 76 insertions(+), 28 deletions(-)
Signature · 1 line
1.7.5.4
PATCH 1/8 bitbake/knotty: don't count errors as warnings in summary
The count of warnings being shown in the summary at the end was also including the number of errors.
--- bitbake/lib/bb/ui/knotty.py | 2 +- 1 files changed, 1 insertions(+), 1 deletions(-)
bitbake/lib/bb/ui/knotty.py +1 -1
@@ -127,7 +127,7 @@ def main(server, eventHandler): if event.levelno >= format.ERROR: errors = errors + 1 return_value = 1 - if event.levelno >= format.WARNING: + elif event.levelno == format.WARNING: warnings = warnings + 1 # For "normal" logging conditions, don't show note logs from tasks # but do show them if the user has changed the default log level to
Signature · 1 line
1.7.5.4
PATCH 2/8 bitbake/fetch2: improve error formatting for fetcher errors
In reply to Paul Eggleton* The "name" argument to FuncFailed is rarely used as a name in actual usage within bitbake, so don't treat it as one in the output.
* Don't print URL for FetchError if it was not specified (i.e. don't output "Fetcher failure for URL 'None'")
* Don't include URL in "unable to fetch from any source" message since we supply it to FetchError and it will be printed anyway.
* Don't include URL in "checksum failed" message for the same reason
--- bitbake/lib/bb/build.py | 2 +- bitbake/lib/bb/fetch2/__init__.py | 11 +++++++---- 2 files changed, 8 insertions(+), 5 deletions(-)
bitbake/lib/bb/build.py +1 -1
@@ -53,7 +53,7 @@ class FuncFailed(Exception): self.logfile = logfile self.name = name if name: - self.msg = "Function '%s' failed" % name + self.msg = 'Function failed: %s' % name else: self.msg = "Function failed"
bitbake/lib/bb/fetch2/__init__.py +7 -4
@@ -55,7 +55,10 @@ class MalformedUrl(BBFetchException): class FetchError(BBFetchException): """General fetcher exception when something happens incorrectly""" def __init__(self, message, url = None): - msg = "Fetcher failure for URL: '%s'. %s" % (url, message) + if url: + msg = "Fetcher failure for URL: '%s'. %s" % (url, message) + else: + msg = "Fetcher failure: %s" % message self.url = url BBFetchException.__init__(self, msg) self.args = (message, url)
@@ -302,10 +305,10 @@ def verify_checksum(u, ud, d): # it does not match. msg = "" if md5mismatch and ud.md5_expected: - msg = msg + "\nFile: '%s' has %s checksum %s when %s was expected (from URL: '%s')" % (ud.localpath, 'md5', md5data, ud.md5_expected, u) + msg = msg + "\nFile: '%s' has %s checksum %s when %s was expected" % (ud.localpath, 'md5', md5data, ud.md5_expected) if sha256mismatch and ud.sha256_expected: - msg = msg + "\nFile: '%s' has %s checksum %s when %s was expected (from URL: '%s')" % (ud.localpath, 'sha256', sha256data, ud.sha256_expected, u) + msg = msg + "\nFile: '%s' has %s checksum %s when %s was expected" % (ud.localpath, 'sha256', sha256data, ud.sha256_expected) if len(msg): raise FetchError('Checksum mismatch!%s' % msg, u)
@@ -983,7 +986,7 @@ class Fetch(object): localpath = try_mirrors (self.d, ud, mirrors) if not localpath or ((not os.path.exists(localpath)) and localpath.find("*") == -1): - raise FetchError("Unable to fetch URL %s from any source." % u, u) + raise FetchError("Unable to fetch URL from any source.", u) update_stamp(u, ud, self.d)
Signature · 1 line
1.7.5.4
PATCH 3/8 bitbake/runqueue: avoid "failed" in task summary if nothing did
In reply to Paul EggletonSeeing the word "failed" alone without reading the whole context has occasionally triggered an automatic assumption on the part of some users (myself included) that something has gone wrong, even when this message is telling you that "0 [tasks] failed". To avoid this let's just say "all succeeded" in this case instead.
As a bonus this means you can now search the output for "fail" and not find anything if all went well.
--- bitbake/lib/bb/runqueue.py | 6 +++++- 1 files changed, 5 insertions(+), 1 deletions(-)
bitbake/lib/bb/runqueue.py +5 -1
@@ -968,7 +968,11 @@ class RunQueue: if self.state is runQueueComplete: # All done - logger.info("Tasks Summary: Attempted %d tasks of which %d didn't need to be rerun and %d failed.", self.rqexe.stats.completed, self.rqexe.stats.skipped, self.rqexe.stats.failed) + if self.rqexe.stats.failed: + logger.info("Tasks Summary: Attempted %d tasks of which %d didn't need to be rerun and %d failed.", self.rqexe.stats.completed, self.rqexe.stats.skipped, self.rqexe.stats.failed) + else: + # Let's avoid the word "failed" if nothing actually did + logger.info("Tasks Summary: Attempted %d tasks of which %d didn't need to be rerun and all succeeded.", self.rqexe.stats.completed, self.rqexe.stats.skipped) return False if self.state is runQueueChildProcess:
Signature · 1 line
1.7.5.4
PATCH 4/8 bitbake/fetch2: correctly decode exit signal/status
In reply to Paul EggletonThe termination signal and exit code of the fetch process were not being decoded correctly, resulting in bitbake reporting that the process terminated with a signal of the exit code (if it was under 255). There are functions in the Python os module to do this decoding correctly (for Unix at least), so let's use them.
--- bitbake/lib/bb/fetch2/__init__.py | 11 +++++++---- 1 files changed, 7 insertions(+), 4 deletions(-)
bitbake/lib/bb/fetch2/__init__.py +7 -4
@@ -422,8 +422,11 @@ def runfetchcmd(cmd, d, quiet = False, cleanup = []): output += line status = stdout_handle.close() or 0 - signal = status >> 8 - exitstatus = status & 0xff + signal = os.WTERMSIG(status) + if os.WIFEXITED(status): + exitstatus = os.WEXITSTATUS(status) + else: + exitstatus = 0 if (signal or status != 0): for f in cleanup:
@@ -434,8 +437,8 @@ def runfetchcmd(cmd, d, quiet = False, cleanup = []): if signal: raise FetchError("Fetch command %s failed with signal %s, output:\n%s" % (cmd, signal, output)) - elif status != 0: - raise FetchError("Fetch command %s failed with exit code %s, output:\n%s" % (cmd, status, output)) + elif exitstatus: + raise FetchError("Fetch command %s failed with exit code %s, output:\n%s" % (cmd, exitstatus, output)) return output
Signature · 1 line
1.7.5.4
PATCH 5/8 bitbake/knotty: avoid printing full task log when error already printed
In reply to Paul EggletonIf a task has logged an ERROR then don't print the contents of the task's log file in knotty (the default terminal UI).
As a side-effect we now also respect BBINCLUDELOGS in knotty; if it is false we never print the log (but the pointer to the log file is always printed).
--- bitbake/lib/bb/build.py | 18 +++++++++++++++--- bitbake/lib/bb/ui/knotty.py | 2 +- 2 files changed, 16 insertions(+), 4 deletions(-)
bitbake/lib/bb/build.py +15 -3
@@ -91,8 +91,9 @@ class TaskSucceeded(TaskBase): class TaskFailed(TaskBase): """Task execution failed""" - def __init__(self, task, logfile, metadata): + def __init__(self, task, logfile, metadata, errprinted = False): self.logfile = logfile + self.errprinted = errprinted super(TaskFailed, self).__init__(task, metadata) class TaskInvalid(TaskBase):
@@ -286,6 +287,13 @@ def _exec_task(fn, task, d, quieterr): prefuncs = localdata.getVarFlag(task, 'prefuncs', expand=True) postfuncs = localdata.getVarFlag(task, 'postfuncs', expand=True) + class ErrorCheckHandler(logging.Handler): + def __init__(self): + self.triggered = False + logging.Handler.__init__(self, logging.ERROR) + def emit(self, record): + self.triggered = True + # Handle logfiles si = file('/dev/null', 'r') try:
@@ -311,6 +319,9 @@ def _exec_task(fn, task, d, quieterr): handler.setLevel(logging.DEBUG - 2) bblogger.addHandler(handler) + errchk = ErrorCheckHandler() + bblogger.addHandler(errchk) + localdata.setVar('BB_LOGFILE', logfn) event.fire(TaskStarted(task, localdata), localdata)
@@ -322,8 +333,9 @@ def _exec_task(fn, task, d, quieterr): exec_func(func, localdata) except FuncFailed as exc: if not quieterr: + errprinted = errchk.triggered logger.error(str(exc)) - event.fire(TaskFailed(task, logfn, localdata), localdata) + event.fire(TaskFailed(task, logfn, localdata, errprinted), localdata) return 1 finally: sys.stdout.flush()
@@ -366,7 +378,7 @@ def exec_task(fn, task, d): if not quieterr: logger.error("Build of %s failed" % (task)) logger.error(format_exc()) - failedevent = TaskFailed(task, None, d) + failedevent = TaskFailed(task, None, d, True) event.fire(failedevent, d) return 1
bitbake/lib/bb/ui/knotty.py +1 -1
@@ -142,7 +142,7 @@ def main(server, eventHandler): logfile = event.logfile if logfile and os.path.exists(logfile): print("ERROR: Logfile of failure stored in: %s" % logfile) - if 1 or includelogs: + if includelogs and not event.errprinted: print("Log data follows:") f = open(logfile, "r") lines = []
Signature · 1 line
1.7.5.4
PATCH 6/8 bitbake/fetch2: reduce output for fetch failures
In reply to Paul EggletonMake the warning for the initial fetch failure a single line - we don't need the full command and output here yet, but write it into the log in full as a debug message. However, if fetching from mirrors fails as well then print out the full details for the first error that occurred as an ERROR rather than a WARNING.
Since this is logged as an ERROR, combined with an earlier patch it suppresses the full log which does make the output much more readable for any fetch error.
Fixes [YOCTO #1832].
--- bitbake/lib/bb/fetch2/__init__.py | 7 ++++++- 1 files changed, 6 insertions(+), 1 deletions(-)
bitbake/lib/bb/fetch2/__init__.py +6 -1
@@ -965,6 +965,7 @@ class Fetch(object): if premirroronly: self.d.setVar("BB_NO_NETWORK", "1") + firsterr = None if not localpath and m.need_update(u, ud, self.d): try: logger.debug(1, "Trying Upstream")
@@ -980,7 +981,9 @@ class Fetch(object): raise except BBFetchException as e: - logger.warn(str(e)) + logger.warn('Failed to fetch URL %s' % u) + logger.debug(1, str(e)) + firsterr = e # Remove any incomplete fetch if os.path.isfile(ud.localpath): bb.utils.remove(ud.localpath)
@@ -989,6 +992,8 @@ class Fetch(object): localpath = try_mirrors (self.d, ud, mirrors) if not localpath or ((not os.path.exists(localpath)) and localpath.find("*") == -1): + if firsterr: + logger.error(str(firsterr)) raise FetchError("Unable to fetch URL from any source.", u) update_stamp(u, ud, self.d)
Signature · 1 line
1.7.5.4
PATCH 7/8 bitbake/cooker: avoid printing stack trace for -b match error
In reply to Paul EggletonImproves error output for matching problems when the -b / --buildfile command line option is used.
Rename MultipleMatches exception to NoSpecificMatch (as it is also raised when there are no matching recipes) and make it inherit from BBHandledException so that it doesn't print a stack trace (we always log an ERROR prior to raising it.)
In addition, improve the formatting of the error message - only call the log function once rather than once for every match, and use a more appropriate message if there are no matches.
Fixes [YOCTO #1141]
--- bitbake/lib/bb/cooker.py | 17 +++++++++++------ 1 files changed, 11 insertions(+), 6 deletions(-)
bitbake/lib/bb/cooker.py +11 -6
@@ -44,9 +44,9 @@ buildlog = logging.getLogger("BitBake.Build") parselog = logging.getLogger("BitBake.Parsing") providerlog = logging.getLogger("BitBake.Provider") -class MultipleMatches(Exception): +class NoSpecificMatch(bb.BBHandledException): """ - Exception raised when multiple file matches are found + Exception raised when no or multiple file matches are found """ class NothingToBuild(Exception):
@@ -979,10 +979,15 @@ class BBCooker: """ matches = self.matchFiles(buildfile) if len(matches) != 1: - parselog.error("Unable to match %s (%s matches found):" % (buildfile, len(matches))) - for f in matches: - parselog.error(" %s" % f) - raise MultipleMatches + if matches: + msg = "Unable to match '%s' to a specific recipe file - %s matches found:" % (buildfile, len(matches)) + if matches: + for f in matches: + msg += "\n %s" % f + parselog.error(msg) + else: + parselog.error("Unable to find any recipe file matching '%s'" % buildfile) + raise NoSpecificMatch return matches[0] def buildFile(self, buildfile, task):
Signature · 1 line
1.7.5.4
PATCH 8/8 bitbake/knotty: print task failure summary
In reply to Paul EggletonRemove the error logged within cooker summarising the list of failed tasks, and instead print this in the UI (knotty) where it belongs. This also adds the actual name of the task that failed as well as the corresponding recipe file that was being shown previously.
In addition, reformat the summary messages more tidily - no extra breaks between lines and use correct English singular/plurals, with some allowance for future translation.
--- bitbake/lib/bb/cooker.py | 4 ---- bitbake/lib/bb/ui/knotty.py | 24 ++++++++++++++++++++++-- 2 files changed, 22 insertions(+), 6 deletions(-)
bitbake/lib/bb/cooker.py +0 -4
@@ -1065,8 +1065,6 @@ class BBCooker: try: retval = rq.execute_runqueue() except runqueue.TaskFailure as exc: - for fnid in exc.args: - buildlog.error("'%s' failed" % taskdata.fn_index[fnid]) failures += len(exc.args) retval = False except SystemExit as exc:
@@ -1106,8 +1104,6 @@ class BBCooker: try: retval = rq.execute_runqueue() except runqueue.TaskFailure as exc: - for fnid in exc.args: - buildlog.error("'%s' failed" % taskdata.fn_index[fnid]) failures += len(exc.args) retval = False except SystemExit as exc:
bitbake/lib/bb/ui/knotty.py +22 -2
@@ -64,6 +64,12 @@ def new_progress(msg, maxval): else: return NonInteractiveProgress(msg, maxval) +def pluralise(singular, plural, qty): + if(qty == 1): + return singular % qty + else: + return plural % qty + def main(server, eventHandler): # Get values of variables which control our output
@@ -107,6 +113,7 @@ def main(server, eventHandler): return_value = 0 errors = 0 warnings = 0 + taskfailures = [] while True: try: event = eventHandler.waitEvent(0.25)
@@ -240,6 +247,7 @@ def main(server, eventHandler): continue if isinstance(event, bb.runqueue.runQueueTaskFailed): + taskfailures.append(event.taskstring) logger.error("Task %s (%s) failed with exit code '%s'", event.taskid, event.taskstring, event.exitcode) continue
@@ -272,8 +280,20 @@ def main(server, eventHandler): server.runCommand(["stateShutdown"]) shutdown = shutdown + 1 pass + + summary = "" + if taskfailures: + summary += pluralise("\nSummary: %s task failed:", + "\nSummary: %s tasks failed:", len(taskfailures)) + for failure in taskfailures: + summary += "\n %s" % failure if warnings: - print("Summary: There were %s WARNING messages shown.\n" % warnings) + summary += pluralise("\nSummary: There was %s WARNING message shown.", + "\nSummary: There were %s WARNING messages shown.", warnings) if return_value: - print("Summary: There were %s ERROR messages shown, returning a non-zero exit code.\n" % errors) + summary += pluralise("\nSummary: There was %s ERROR message shown, returning a non-zero exit code.", + "\nSummary: There were %s ERROR messages shown, returning a non-zero exit code.", errors) + if summary: + print(summary) + return return_value
Signature · 1 line
1.7.5.4
Richard Purdie
AppliedQuoted 11 lines · Paul Eggleton
A number of fixes to improve the readability of error messages, primarily for fetch errors, but will improve error output in other situations as well.
(This supersedes the set of patches I sent a couple of days ago.)
The changes (against Poky, but apply cleanly with -p2 against bitbake master) are available in the git repository at:
git://git.yoctoproject.org/poky-contribpaule/errorhandling
http://git.yoctoproject.org/cgit.cgi/poky-contrib/log/?h=paule/errorhandling
Quoted 10 lines
Paul Eggleton (8):
bitbake/knotty: don't count errors as warnings in summary bitbake/fetch2: improve error formatting for fetcher errors bitbake/runqueue: avoid "failed" in task summary if nothing did bitbake/fetch2: correctly decode exit signal/status bitbake/knotty: avoid printing full task log when error already
printed
bitbake/fetch2: reduce output for fetch failures bitbake/cooker: avoid printing stack trace for -b match error bitbake/knotty: print task failure summary
Merged to master, thanks. Some good improvements in there.
Cheers,
Richard