Make errors in called processes more evident and easier to debug.
Also trying to get unicode filenames right again.
Change-Id: I501c94921b92b8a8cd6a10441aff1595fc6d878e
Reviewed-on: https://pdfium-review.googlesource.com/10630
Commit-Queue: Henrique Nakashima <hnakashima@chromium.org>
Reviewed-by: Nicolás Peña <npm@chromium.org>
Reviewed-by: Ryan Harrison <rharrison@chromium.org>
diff --git a/testing/tools/common.py b/testing/tools/common.py
index 737169f..fc16004 100755
--- a/testing/tools/common.py
+++ b/testing/tools/common.py
@@ -3,6 +3,7 @@
# Use of this source code is governed by a BSD-style license that can be
# found in the LICENSE file.
+import datetime
import glob
import os
import re
@@ -26,6 +27,38 @@
except subprocess.CalledProcessError as e:
return e
+
+def RunCommandPropagateErr(cmd, stdout_has_errors=False,
+ exit_status_on_error=None):
+ """Run a command as a subprocess.
+
+ Errors in that subprocess are printed out if it returns an error exit code.
+
+ Args:
+ cmd: Command to run as a list of strings.
+ stdout_has_errors: Whether to print stdout instead of stderr on an error
+ exit.
+ exit_status_on_error: If specified, upon an error in the subprocess the
+ caller script exits immediately with the given status.
+ """
+ p = subprocess.Popen(cmd, stdout=subprocess.PIPE, stderr=subprocess.PIPE)
+ output, err = p.communicate()
+
+ if p.returncode:
+ PrintErr('\nError when invoking "%s"' % ' '.join(cmd))
+ if stdout_has_errors:
+ PrintErr(output)
+
+ PrintErr(err)
+
+ if exit_status_on_error is not None:
+ sys.exit(exit_status_on_error)
+
+ return None
+
+ return output
+
+
# RunCommandExtractHashedFiles returns a tuple: (raised_exception, hashed_files)
# It runs the given command. If it fails it will return an exception and None.
# If it succeeds it will return None and the list of processed files extracted
@@ -110,3 +143,14 @@
if verbose:
print >> sys.stderr, "Found '%s' for value of %s" % (arg_match_output, arg)
return arg_match_output == 'true'
+
+
+def PrintWithTime(s):
+ """Prints s prepended by a timestamp."""
+ print '[%s] %s' % (datetime.datetime.now().strftime("%Y%m%d %H:%M:%S"),
+ s)
+
+
+def PrintErr(s):
+ """Prints s to stderr."""
+ print >> sys.stderr, s
diff --git a/testing/tools/githelper.py b/testing/tools/githelper.py
index 021ed4e..2e94196 100644
--- a/testing/tools/githelper.py
+++ b/testing/tools/githelper.py
@@ -6,6 +6,8 @@
import subprocess
+from common import RunCommandPropagateErr
+
class GitHelper(object):
"""Issues git commands. Stateful."""
@@ -15,15 +17,17 @@
def Checkout(self, branch):
"""Checks out a branch."""
- subprocess.check_output(['git', 'checkout', branch])
+ RunCommandPropagateErr(['git', 'checkout', branch], exit_status_on_error=1)
def FetchOriginMaster(self):
"""Fetches new changes on origin/master."""
- subprocess.check_output(['git', 'fetch', 'origin', 'master'])
+ RunCommandPropagateErr(['git', 'fetch', 'origin', 'master'],
+ exit_status_on_error=1)
def StashPush(self):
"""Stashes uncommitted changes."""
- output = subprocess.check_output(['git', 'stash', '--include-untracked'])
+ output = RunCommandPropagateErr(['git', 'stash', '--include-untracked'],
+ exit_status_on_error=1)
if 'No local changes to save' in output:
return False
@@ -33,30 +37,30 @@
def StashPopAll(self):
"""Pops as many changes as this instance stashed."""
while self.stashed > 0:
- subprocess.check_output(['git', 'stash', 'pop'])
+ RunCommandPropagateErr(['git', 'stash', 'pop'], exit_status_on_error=1)
self.stashed -= 1
def GetCurrentBranchName(self):
"""Returns a string with the current branch name."""
- return subprocess.check_output(
- ['git', 'rev-parse', '--abbrev-ref', 'HEAD']).strip()
+ return RunCommandPropagateErr(
+ ['git', 'rev-parse', '--abbrev-ref', 'HEAD'],
+ exit_status_on_error=1).strip()
def GetCurrentBranchHash(self):
- return subprocess.check_output(
- ['git', 'rev-parse', 'HEAD']).strip()
+ return RunCommandPropagateErr(
+ ['git', 'rev-parse', 'HEAD'], exit_status_on_error=1).strip()
def IsCurrentBranchClean(self):
- output = subprocess.check_output(['git', 'status', '--porcelain'])
+ output = RunCommandPropagateErr(['git', 'status', '--porcelain'],
+ exit_status_on_error=1)
return not output
def BranchExists(self, branch_name):
"""Return whether a branch with the given name exists."""
- try:
- subprocess.check_output(['git', 'rev-parse', '--verify',
- branch_name])
- return True
- except subprocess.CalledProcessError:
- return False
+ output = RunCommandPropagateErr(['git', 'rev-parse', '--verify',
+ branch_name])
+ return output is not None
def CloneLocal(self, source_repo, new_repo):
- subprocess.check_call(['git', 'clone', source_repo, new_repo])
+ RunCommandPropagateErr(['git', 'clone', source_repo, new_repo],
+ exit_status_on_error=1)
diff --git a/testing/tools/safetynet_compare.py b/testing/tools/safetynet_compare.py
index 028dd02..d583312 100755
--- a/testing/tools/safetynet_compare.py
+++ b/testing/tools/safetynet_compare.py
@@ -17,6 +17,8 @@
import tempfile
from common import GetBooleanGnArg
+from common import PrintErr
+from common import RunCommandPropagateErr
from githelper import GitHelper
from safetynet_conclusions import ComparisonConclusions
from safetynet_conclusions import PrintConclusionsDictHumanReadable
@@ -24,11 +26,6 @@
from safetynet_conclusions import RATING_REGRESSION
-def PrintErr(s):
- """Prints s to stderr."""
- print >> sys.stderr, s
-
-
def RunSingleTestCaseParallel(this, run_label, build_dir, test_case):
result = this.RunSingleTestCase(run_label, build_dir, test_case)
return (test_case, result)
@@ -44,11 +41,13 @@
def _InitPaths(self):
if self.args.this_repo:
- measure_script_path = os.path.join(self.args.build_dir,
- 'safetynet_measure_current.py')
+ self.safe_script_dir = self.args.build_dir
else:
- measure_script_path = 'testing/tools/safetynet_measure.py'
- self.safe_measure_script_path = os.path.abspath(measure_script_path)
+ self.safe_script_dir = os.path.join('testing', 'tools')
+
+ self.safe_measure_script_path = os.path.abspath(
+ os.path.join(self.safe_script_dir,
+ 'safetynet_measure.py'))
input_file_re = re.compile('^.+[.]pdf$')
self.test_cases = []
@@ -115,8 +114,12 @@
This is needed to make sure we are comparing the pdfium library changes and
not script changes that may happen between the two branches.
"""
- subprocess.check_output(['cp', 'testing/tools/safetynet_measure.py',
- self.safe_measure_script_path])
+ self.__FreezeFile(os.path.join('testing', 'tools', 'safetynet_measure.py'))
+ self.__FreezeFile(os.path.join('testing', 'tools', 'common.py'))
+
+ def __FreezeFile(self, file):
+ RunCommandPropagateErr(['cp', file, self.safe_script_dir],
+ exit_status_on_error=1)
def _ProfileTwoOtherBranchesInThisRepo(self, before_branch, after_branch):
"""Profiles two branches that are not the current branch.
@@ -334,9 +337,10 @@
'https://pdfium.googlesource.com/pdfium.git']
if self.args.cache_dir:
cmd.append('--cache-dir=%s' % self.args.cache_dir)
- subprocess.check_output(cmd)
+ RunCommandPropagateErr(cmd, exit_status_on_error=1)
- subprocess.check_output(['gclient', 'sync'])
+ RunCommandPropagateErr(['gclient', 'sync'], exit_status_on_error=1)
+
PrintErr('Done.')
build_dir = os.path.join(src_dir, relative_build_dir)
@@ -347,7 +351,8 @@
dest_gn_args = os.path.join(build_dir, 'args.gn')
shutil.copy(source_gn_args, dest_gn_args)
- subprocess.check_output(['gn', 'gen', relative_build_dir])
+ RunCommandPropagateErr(['gn', 'gen', relative_build_dir],
+ exit_status_on_error=1)
os.chdir(cwd)
@@ -373,16 +378,14 @@
build_dir: String with path to build directory
"""
PrintErr('Syncing...')
- subprocess.check_output(['gclient', 'sync'])
+ RunCommandPropagateErr(['gclient', 'sync'], exit_status_on_error=1)
PrintErr('Done.')
+ PrintErr('Building...')
cmd = ['ninja', '-C', build_dir, 'pdfium_test']
-
if GetBooleanGnArg('use_goma', build_dir):
cmd.extend(['-j', '250'])
-
- PrintErr('Building...')
- subprocess.check_output(cmd)
+ RunCommandPropagateErr(cmd, stdout_has_errors=True, exit_status_on_error=1)
PrintErr('Done.')
def _MeasureCurrentBranch(self, run_label, build_dir):
@@ -480,13 +483,9 @@
if profile_file_path:
command.append('--output-path=%s' % profile_file_path)
- try:
- output = subprocess.check_output(command)
- except subprocess.CalledProcessError as e:
- PrintErr(e)
- PrintErr(35 * '=' + ' Output: ' + 34 * '=')
- PrintErr(e.output)
- PrintErr(80 * '=')
+ output = RunCommandPropagateErr(command)
+
+ if output is None:
return None
# Get the time number as output, making sure it's just a number
@@ -539,7 +538,7 @@
ComparisonConclusions.GetOutputDict().
"""
if self.args.machine_readable:
- print json.dumps(conclusions_dict, ensure_ascii=False)
+ print json.dumps(conclusions_dict)
else:
PrintConclusionsDictHumanReadable(
conclusions_dict, colored=True, key=self.args.case_order)
diff --git a/testing/tools/safetynet_conclusions.py b/testing/tools/safetynet_conclusions.py
index 112274e..5764ede 100644
--- a/testing/tools/safetynet_conclusions.py
+++ b/testing/tools/safetynet_conclusions.py
@@ -179,7 +179,7 @@
output_dict['params'] = {'threshold': self.threshold_significant}
output_dict['summary'] = self.summary.GetOutputDict()
output_dict['comparison_by_case'] = {
- cr.case_name: cr.GetOutputDict()
+ cr.case_name.decode('utf-8'): cr.GetOutputDict()
for cr in self.GetCaseResults().values()
}
return output_dict
@@ -264,17 +264,18 @@
for case_name, case_dict in case_pairs:
if case_dict['rating'] == RATING_FAILURE:
- print '%s to measure time for %s' % (
- RATING_TO_COLOR[RATING_FAILURE].format('Failed'), case_name)
+ print u'{} to measure time for {}'.format(
+ RATING_TO_COLOR[RATING_FAILURE].format('Failed'),
+ case_name).encode('utf-8')
continue
if colored:
color = RATING_TO_COLOR[case_dict['rating']]
- print '{0} {1:15,d} {2}' .format(
+ print u'{0} {1:15,d} {2}' .format(
color.format('{:+11.4%}'.format(case_dict['ratio'])),
case_dict['after'],
- case_name)
+ case_name).encode('utf-8')
# Print totals
totals = conclusions_dict['summary']
diff --git a/testing/tools/safetynet_job.py b/testing/tools/safetynet_job.py
index 09e6b75..5cb926a 100755
--- a/testing/tools/safetynet_job.py
+++ b/testing/tools/safetynet_job.py
@@ -17,6 +17,9 @@
import subprocess
import sys
+from common import PrintErr
+from common import PrintWithTime
+from common import RunCommandPropagateErr
from githelper import GitHelper
from safetynet_conclusions import PrintConclusionsDictHumanReadable
@@ -66,16 +69,15 @@
os.path.pardir)
os.chdir(pdfium_src_dir)
- if not self.git.IsCurrentBranchClean():
- print 'Current branch is not clean, aborting'
+ if not self.git.IsCurrentBranchClean() and not self.args.no_checkout:
+ PrintWithTime('Current branch is not clean, aborting')
return 1
branch_to_restore = self.git.GetCurrentBranchName()
- if not self.args.no_fetch:
+ if not self.args.no_checkout:
self.git.FetchOriginMaster()
-
- self.git.Checkout('origin/master')
+ self.git.Checkout('origin/master')
# Make sure results dir exists
if not os.path.exists(self.context.results_dir):
@@ -99,11 +101,12 @@
"""
current = self.git.GetCurrentBranchHash()
- print 'Initial run, current is %s' % current
+ PrintWithTime('Initial run, current is %s' % current)
self._WriteCheckpoint(current)
- print 'All set up, next runs will be incremental and perform comparisons'
+ PrintWithTime('All set up, next runs will be incremental and perform '
+ 'comparisons')
return 0
def _IncrementalRun(self, last_revision_covered):
@@ -117,11 +120,11 @@
"""
current = self.git.GetCurrentBranchHash()
- print ('Incremental run, current is %s, last is %s'
- % (current, last_revision_covered))
+ PrintWithTime('Incremental run, current is %s, last is %s'
+ % (current, last_revision_covered))
if current == last_revision_covered:
- print 'No changes seen, finishing job'
+ PrintWithTime('No changes seen, finishing job')
return 0
# Run compare
@@ -134,8 +137,10 @@
'--output-dir=%s' % self.context.run_output_dir]
cmd.extend(self.args.input_paths)
- p = subprocess.Popen(cmd, stdout=subprocess.PIPE)
- json_output, _ = p.communicate()
+ json_output = RunCommandPropagateErr(cmd)
+
+ if json_output is None:
+ return 1
output_info = json.loads(json_output)
PrintConclusionsDictHumanReadable(output_info,
@@ -145,15 +150,15 @@
status = 0
if output_info['summary']['improvement']:
- print 'Improvement detected.'
+ PrintWithTime('Improvement detected.')
status = 3
if output_info['summary']['regression']:
- print 'Regression detected.'
+ PrintWithTime('Regression detected.')
status = 2
if status == 0:
- print 'Nothing detected.'
+ PrintWithTime('Nothing detected.')
self._WriteCheckpoint(current)
@@ -172,9 +177,9 @@
parser.add_argument('input_paths', nargs='+',
help='pdf files or directories to search for pdf files '
'to run as test cases')
- parser.add_argument('--no-fetch', action='store_true',
- help='whether to skip the git fetch. Use for script '
- 'debugging.')
+ parser.add_argument('--no-checkout', action='store_true',
+ help='whether to skip checking out origin/master. Use '
+ 'for script debugging.')
parser.add_argument('--no-checkpoint', action='store_true',
help='whether to skip writing the new checkpoint. Use '
'for script debugging.')
diff --git a/testing/tools/safetynet_measure.py b/testing/tools/safetynet_measure.py
index 67c0734..7b5bd5f 100755
--- a/testing/tools/safetynet_measure.py
+++ b/testing/tools/safetynet_measure.py
@@ -14,6 +14,8 @@
import subprocess
import sys
+from common import PrintErr
+
CALLGRIND_PROFILER = 'callgrind'
PERFSTAT_PROFILER = 'perfstat'
@@ -30,12 +32,13 @@
def _CheckTools(self):
"""Returns whether the tool file paths are sane."""
if not os.path.exists(self.pdfium_test_path):
- print "FAILURE: Can't find test executable '%s'" % self.pdfium_test_path
- print 'Use --build-dir to specify its location.'
+ PrintErr("FAILURE: Can't find test executable '%s'"
+ % self.pdfium_test_path)
+ PrintErr('Use --build-dir to specify its location.')
return False
if not os.access(self.pdfium_test_path, os.X_OK):
- print ("FAILURE: Test executable '%s' lacks execution permissions"
- % self.pdfium_test_path)
+ PrintErr("FAILURE: Test executable '%s' lacks execution permissions"
+ % self.pdfium_test_path)
return False
return True
@@ -53,7 +56,7 @@
elif self.args.profiler == PERFSTAT_PROFILER:
time = self._RunPerfStat()
else:
- print 'profiler=%s not supported, aborting' % self.args.profiler
+ PrintErr('profiler=%s not supported, aborting' % self.args.profiler)
return 1
if time is None:
@@ -142,7 +145,7 @@
args = parser.parse_args()
if args.interesting_section and args.profiler != CALLGRIND_PROFILER:
- print '--interesting-section requires profiler to be callgrind.'
+ PrintErr('--interesting-section requires profiler to be callgrind.')
return 1
run = PerformanceRun(args)