5c6366432eadc33cfdc7c48c1308bce156479905 lrnassar Wed Aug 5 17:24:23 2026 -0700 Harden error handling in trackCountsParse per CR feedback. refs #37975 The report pipeline had no pipefail, so it reported awk's exit status rather than makeUsageReport's. awk is happy with truncated input, so a report that died partway through produced a non-empty partial count file with a success status, and the v2 cache then reused that partial file on every later run. The empty-file check only caught a total failure. Adds pipefail, and removes the partial file when the command fails so a failed run cannot leave something behind for the cache to pick up. The mergeStderr=False path added in the last commit dropped stderr from the error message, since CalledProcessError reports stdout in e.output. That is the one call site using the flag, the bulk tdbQuery, so a failure there lost its reason entirely. The RuntimeError now carries stderr too. Also aborts when tdbQuery returns no trackDb entries at all. tdbQuery exits 0 and prints nothing for a database it does not know, so a mistyped db name used to run to completion treating every track as notInTrackDb before failing with a message that blamed the usage logs. Pins the subshell to bash, which pipefail needs and which the existing sort -t $'\t' already quietly relied on. diff --git src/utils/qa/trackCountsParse src/utils/qa/trackCountsParse index 1e401b2e48d..4a2291329d5 100755 --- src/utils/qa/trackCountsParse +++ src/utils/qa/trackCountsParse @@ -65,39 +65,45 @@ if options.singleReport: if options.asOfDate: parser.error("-a/--asOfDate does not apply in -r/--singleReport mode, use -s and -e") if not options.startDate or not options.endDate: parser.error("-r/--singleReport needs both -s/--startDate and -e/--endDate") if options.asOfDate: try: datetime.strptime(options.asOfDate, '%Y-%m') except ValueError: parser.error("-a/--asOfDate must be formatted as YYYY-MM, got '"+options.asOfDate+"'") if options.numOfMonthsToCompare < 1: parser.error("-n/--numOfMonthsToCompare must be at least 1") return options def bash(cmd,mergeStderr=True): - """Run the cmd in bash subprocess. Callers that parse the output should pass - mergeStderr=False so that a warning cannot splice itself into a data line.""" + """Run the cmd in a bash subprocess. Callers that parse the output should pass + mergeStderr=False so that a warning cannot splice itself into a data line, a + failing command still reports its stderr either way. executable is pinned to bash + because the commands here use bash features, 'set -o pipefail' and ANSI-C quoting + in the sort, that plain sh does not have.""" try: - rawBashOutput = subprocess.run(cmd, check=True, shell=True,\ + rawBashOutput = subprocess.run(cmd, check=True, shell=True, executable="/bin/bash",\ stdout=subprocess.PIPE, universal_newlines=True,\ stderr=subprocess.STDOUT if mergeStderr else subprocess.PIPE) bashStdoutt = rawBashOutput.stdout except subprocess.CalledProcessError as e: - raise RuntimeError("command '{}' return with error (code {}): {}".format(e.cmd, e.returncode, e.output)) + errorText = e.output if e.output else "" + if e.stderr: + errorText += e.stderr + raise RuntimeError("command '{}' return with error (code {}): {}".format(e.cmd, e.returncode, errorText)) return(bashStdoutt) def file_exists(filepath): return os.path.isfile(filepath) #Tracks whose parent chain loops, so the warning is printed once and not once per month per track loopsAlreadyWarnedAbout = set() def buildTrackDbCache(dbs): """ Dump the whole trackDb for a db in a single tdbQuery call and return a dictionary of trackName -> {'shortLabel','group','parentName'}. Querying tdbQuery once per track takes hours on a large assembly, one dump takes under a second. A track with no 'parentName' key is top level. """ @@ -118,30 +124,35 @@ #for begins a new setting, anything else is the rest of the previous value. if key in selectedKeys and key not in settings: settings[key] = field[len(key)+1:] lastKey = key elif lastKey: settings[lastKey] += "|" + field trackName = settings["track"] trackDbCache[trackName] = {'shortLabel':settings.get("shortLabel",trackName), 'group':settings.get("group","No group")} #A subtrack points at its container with 'parent', a member of a superTrack points #at it with 'superTrack <name>'. A superTrack itself carries 'superTrack on'. if "parent" in settings: trackDbCache[trackName]['parentName'] = settings["parent"].split(" ")[0] elif "superTrack" in settings and settings["superTrack"].split(" ")[0] != "on": trackDbCache[trackName]['parentName'] = settings["superTrack"].split(" ")[0] + #tdbQuery exits 0 and prints nothing for a database it does not know, so an empty cache + #means a bad db name. Without this the run carries on, treats every track as notInTrackDb, + #and only fails later with a message blaming the usage logs. + if not trackDbCache: + sys.exit("Error: tdbQuery returned no trackDb entries for '"+dbs+"'. Check the database name.") print("trackDb entries cached for "+dbs+": "+str(len(trackDbCache))) return(trackDbCache) def findTopLevelTrack(trackDbCache,trackName): """ Walk up the parent chain and return the track at the top. Tracks with no parent, and tracks that are no longer in trackDb at all, are their own top level. This is a loop rather than a fixed number of hops so that adding another layer of nesting to trackDb does not silently strand counts on a middle container. """ currentTrack = trackName visited = set() while currentTrack in trackDbCache and 'parentName' in trackDbCache[currentTrack]: if currentTrack in visited: if currentTrack not in loopsAlreadyWarnedAbout: @@ -157,38 +168,48 @@ #Format date format is XXXX-XX-XX, e.g. 2023-11-01 #The v2 in the name marks counts made with the field anchored awk filter below. Older #.trackCounts.txt files were filtered differently, and since this function reuses any #file it finds, sharing the name would silently serve the old filtering forever. outputFileName = workDir+dbs+"."+startDate+"to"+endDate+".trackCounts.v2.txt" #Run the script and remove the ct lines (ct_), hub lines (hub_), dup lines (dup_) #and header line (^#), as well as remove the first column of repeating database. #The track name is the second column, so the prefixes are matched against the start #of that field only. Matching them anywhere on the line, as this used to, also drops #real tracks whose names merely contain the string, such as dbVar_conflict_pathogenic #containing 'ct_'. This is awk rather than grep because grep -P silently failed to #drop a few dozen hub_ lines out of the 650k that makeUsageReport emits for a month, #while awk field matching is exact. The awk also does what the old 'cut -f2-' did. awkFilter = "awk -F'\\t' 'BEGIN{OFS=\"\\t\"} $1!~/^#/ && $2!~/^(hub_|ct_|dup_)/ " + \ "{out=$2; for(i=3;i<=NF;i++) out=out OFS $i; print out}'" - reportCmd = "/hive/users/chmalee/logs/byDate/makeUsageReport -t -db " + dbs + \ + #pipefail so that makeUsageReport dying partway through counts as a failure. Without it + #the pipeline reports awk's status, awk is perfectly happy with truncated input, and the + #half written file would be treated as a valid cache by every later run. + reportCmd = "set -o pipefail; /hive/users/chmalee/logs/byDate/makeUsageReport -t -db " + dbs + \ " --bin-months -s " + startDate + " -e " + endDate + \ " | " + awkFilter + " > " + outputFileName if not file_exists(outputFileName): print("Generating new file") print(reportCmd) + try: bash(reportCmd) + except RuntimeError: + #A run that died partway still leaves what it managed to write, so clear it out + #rather than leave a partial file for the next run to pick up as cached. + if file_exists(outputFileName): + os.remove(outputFileName) + raise else: print("File already generated: " + outputFileName) #An empty report means the log data does not cover these dates. Leaving the file behind #would cache that emptiness, and an empty month aborts later on an out of range index. if os.path.getsize(outputFileName) == 0: os.remove(outputFileName) sys.exit("Error: no track counts for "+startDate+" to "+endDate+". The usage logs may " + \ "not reach back that far, or the weekly files for those dates may not be built yet. " + \ "Check /hive/users/chmalee/logs/byDate/result/*/ for the dates you asked for.") return(outputFileName) def createDicFromTrackCountsFile(trackCountsFilePath): """