Create a log file for each check.
Create a logger for each check. Add a FileHandler with level DEBUG to
these loggers. Since they're child loggers of the root logger, warn()
and error() send output to the log file and to stderr.
Make several changes to simplify passing these log objects around.
Add log statements to a few presubmit checks.
Change-Id: If13ad92da5c2abf9035e78c1cbe81d5025916888
Bug: 3
diff --git a/pw_cli/py/pw_cli/log.py b/pw_cli/py/pw_cli/log.py
index 2a802c5..7fc1c55 100644
--- a/pw_cli/py/pw_cli/log.py
+++ b/pw_cli/py/pw_cli/log.py
@@ -60,9 +60,18 @@
raise ValueError(
f'Invalid environment variable PW_SUBPROCESS={pw_subprocess}')
- logging.basicConfig(format=timestamp_fmt + '%(levelname)s %(message)s',
- datefmt='%Y%m%d %H:%M:%S',
- level=logging.INFO)
+ # Set log level on root logger to debug, otherwise any higher levels
+ # elsewhere are ignored.
+ root = logging.getLogger()
+ root.setLevel(logging.DEBUG)
+
+ # Skip debug-level statements when printing to the terminal.
+ stderr_handler = logging.StreamHandler()
+ stderr_handler.setLevel(logging.INFO)
+ stderr_handler.setFormatter(
+ logging.Formatter(timestamp_fmt + '%(levelname)s %(message)s',
+ '%Y%m%d %H:%M:%S'))
+ root.addHandler(stderr_handler)
# Shorten all the log levels to 3 characters for column-aligned logs.
# Color the logs using ANSI codes.
diff --git a/pw_presubmit/py/pw_presubmit/format_code.py b/pw_presubmit/py/pw_presubmit/format_code.py
index de1c070..9888f10 100755
--- a/pw_presubmit/py/pw_presubmit/format_code.py
+++ b/pw_presubmit/py/pw_presubmit/format_code.py
@@ -184,8 +184,10 @@
_yapf('--in-place', *files, check=True)
-def print_format_check(errors: Dict[str, str],
- show_fix_commands: bool) -> None:
+def print_format_check(
+ errors: Dict[str, str],
+ show_fix_commands: bool,
+) -> None:
"""Prints and returns the result of a check_*_format function."""
if not errors:
# Don't print anything in the all-good case.
@@ -214,8 +216,8 @@
class CodeFormat(NamedTuple):
language: str
extensions: Collection[str]
- check: Callable[[pw_presubmit.PresubmitContext], Dict[str, str]]
- fix: Callable[[pw_presubmit.PresubmitContext], None]
+ check: Callable[[Iterable], Dict[str, str]]
+ fix: Callable[[Iterable], None]
C_FORMAT: CodeFormat = CodeFormat(
diff --git a/pw_presubmit/py/pw_presubmit/pigweed_presubmit.py b/pw_presubmit/py/pw_presubmit/pigweed_presubmit.py
index 232cdfe..29c6180 100755
--- a/pw_presubmit/py/pw_presubmit/pigweed_presubmit.py
+++ b/pw_presubmit/py/pw_presubmit/pigweed_presubmit.py
@@ -38,7 +38,7 @@
from pw_presubmit.install_hook import install_hook
from pw_presubmit import call, filter_paths, log_run, plural, PresubmitFailure
-_LOG: logging.Logger = logging.getLogger(__name__)
+_LOG = logging.getLogger(__name__)
def run_python_module(*args, **kwargs):
@@ -97,12 +97,23 @@
return '--args=' + ' '.join(f'{arg}={val}' for arg, val in kwargs.items())
-def gn_gen(*args, path, repo):
- call('gn', 'gen', path, '--color=always', '--check', *args, cwd=repo)
+def gn_gen(*args, ctx, path=None, **kwargs):
+ call('gn',
+ 'gen',
+ path or ctx.output_directory,
+ '--color=always',
+ '--check',
+ *args,
+ cwd=ctx.repository_root,
+ **kwargs)
-def ninja(path, repo):
- call('ninja', '-C', path.absolute(), cwd=repo)
+def ninja(ctx, **kwargs):
+ call('ninja',
+ '-C',
+ ctx.output_directory,
+ cwd=ctx.repository_root,
+ **kwargs)
_CLANG_GEN_ARGS = gn_args(pw_target_config='"//targets/host/host.gni"',
@@ -110,20 +121,16 @@
def gn_clang_build(ctx: PresubmitContext):
- gn_gen('--export-compile-commands',
- _CLANG_GEN_ARGS,
- path=ctx.output_directory,
- repo=ctx.repository_root)
- ninja(path=ctx.output_directory, repo=ctx.repository_root)
+ gn_gen('--export-compile-commands', _CLANG_GEN_ARGS, ctx=ctx)
+ ninja(ctx=ctx)
@filter_paths(endswith=format_code.C_FORMAT.extensions)
def gn_gcc_build(ctx: PresubmitContext):
gn_gen(gn_args(pw_target_config='"//targets/host/host.gni"',
pw_target_toolchain='"//pw_toolchain:host_gcc_os"'),
- path=ctx.output_directory,
- repo=ctx.repository_root)
- ninja(path=ctx.output_directory, repo=ctx.repository_root)
+ ctx=ctx)
+ ninja(ctx=ctx)
_ARM_GEN_ARGS = gn_args(
@@ -132,8 +139,8 @@
@filter_paths(endswith=format_code.C_FORMAT.extensions)
def gn_arm_build(ctx: PresubmitContext):
- gn_gen(_ARM_GEN_ARGS, path=ctx.output_directory, repo=ctx.repository_root)
- ninja(path=ctx.output_directory, repo=ctx.repository_root)
+ gn_gen(_ARM_GEN_ARGS, ctx=ctx)
+ ninja(ctx=ctx)
GN = (
@@ -270,7 +277,7 @@
errors = []
for path in ctx.paths:
- path = ctx.repository_root.joinpath(path)
+ _LOG.debug('Checking %s', path)
with open(path) as file:
# Skip shebang and blank lines
line = file.readline()
@@ -279,6 +286,7 @@
first_line = COPYRIGHT_FIRST_LINE.match(line)
if not first_line:
+ _LOG.debug('%s: invalid first line %r', path, line)
errors.append(path)
continue
@@ -286,6 +294,8 @@
for expected, actual in zip(COPYRIGHT_LINES, file):
if comment + expected != actual:
+ _LOG.debug(' bad line: %r', actual)
+ _LOG.debug(' expected: %r', comment + expected)
errors.append(path)
break
@@ -302,19 +312,21 @@
#
-def _get_paths_from_command(*args, cwd: pathlib.Path, **kwargs):
+def _get_paths_from_command(*args, ctx: PresubmitContext, **kwargs):
"""Runs a command and reads Bazel or GN //-style paths from it."""
process = log_run(*args,
stdout=subprocess.PIPE,
stderr=subprocess.DEVNULL,
- cwd=cwd,
+ cwd=ctx.repository_root,
**kwargs)
files = set()
for line in process.stdout.splitlines():
+ _LOG.debug('processing line %r', line)
path = line.strip().lstrip(b'/').replace(b':', b'/').decode()
- path = cwd.joinpath(path)
+ path = ctx.repository_root.joinpath(path)
if path.is_file():
+ _LOG.debug(' file %s', path)
files.add(path)
return files
@@ -331,25 +343,17 @@
build_bazel = _get_paths_from_command('bazel',
'query',
'kind("source file", //...:*)',
- cwd=ctx.repository_root)
+ ctx=ctx)
# Collect all paths in the ARM and Clang GN builds.
arm_dir = ctx.output_directory.joinpath('arm')
- gn_gen(_ARM_GEN_ARGS, path=arm_dir, repo=ctx.repository_root)
- build_gn = _get_paths_from_command('gn',
- 'desc',
- arm_dir,
- '*',
- cwd=ctx.repository_root)
+ gn_gen(_ARM_GEN_ARGS, ctx=ctx, path=arm_dir)
+ build_gn = _get_paths_from_command('gn', 'desc', arm_dir, '*', ctx=ctx)
clang_dir = ctx.output_directory.joinpath('clang')
- gn_gen(_CLANG_GEN_ARGS, path=clang_dir, repo=ctx.repository_root)
+ gn_gen(_CLANG_GEN_ARGS, ctx=ctx, path=clang_dir)
build_gn.update(
- _get_paths_from_command('gn',
- 'desc',
- clang_dir,
- '*',
- cwd=ctx.repository_root))
+ _get_paths_from_command('gn', 'desc', clang_dir, '*', ctx=ctx))
missing_bazel = []
missing_gn = []
diff --git a/pw_presubmit/py/pw_presubmit/tools.py b/pw_presubmit/py/pw_presubmit/tools.py
index 25dc3bb..1ea4761 100644
--- a/pw_presubmit/py/pw_presubmit/tools.py
+++ b/pw_presubmit/py/pw_presubmit/tools.py
@@ -43,6 +43,7 @@
import argparse
from collections import Counter, defaultdict
+import contextlib
import dataclasses
import enum
import logging
@@ -58,6 +59,7 @@
from inspect import signature
_LOG: logging.Logger = logging.getLogger(__name__)
+_LOG.setLevel(logging.DEBUG)
def plural(items_or_count, singular: str, count_format='') -> str:
@@ -270,14 +272,30 @@
return not failed and not skipped
- def _create_context(self, name, paths):
+ @contextlib.contextmanager
+ def _context(self, name, paths):
+ # There are many characters banned from filenames on Windows. To
+ # simplify things, just strip everything that's not a letter, digit,
+ # or underscore.
sanitized_name = re.sub(r'[\W_]+', '_', name).lower()
output_directory = self._output_directory.joinpath(sanitized_name)
os.makedirs(output_directory, exist_ok=True)
- return PresubmitContext(
- repository_root=self._repository_root.absolute(),
- output_directory=output_directory.absolute(),
- paths=paths)
+
+ handler = logging.FileHandler(output_directory.joinpath(f'step.log'),
+ mode='w')
+ handler.setLevel(logging.DEBUG)
+
+ try:
+ _LOG.addHandler(handler)
+
+ yield PresubmitContext(
+ repository_root=self._repository_root.absolute(),
+ output_directory=output_directory.absolute(),
+ paths=paths,
+ )
+
+ finally:
+ _LOG.removeHandler(handler)
def _execute_checks(self, program,
keep_going: bool) -> Tuple[int, int, int]:
@@ -286,8 +304,8 @@
for i, (check, paths) in enumerate(program, 1):
paths = [self._repository_root.joinpath(p) for p in paths]
- ctx = self._create_context(check.name, paths=paths)
- result = check.run(ctx, i, len(program))
+ with self._context(check.name, paths) as ctx:
+ result = check.run(ctx, i, len(program))
if result is _Result.PASS:
passed += 1
@@ -523,6 +541,7 @@
_LOG.debug('%s %s', self.name, result.value)
print(_box(_BOTTOM, result.colorized(_LEFT), self.name, time_str))
+ _LOG.debug('%s duration:%s', self.name, time_str)
return result
@@ -582,22 +601,23 @@
def call(*args, **kwargs) -> None:
"""Optional subprocess wrapper that causes a PresubmitFailure on errors."""
+ _LOG.debug('call: %s %s', args, kwargs)
process = subprocess.run(args,
stdout=subprocess.PIPE,
stderr=subprocess.STDOUT,
**kwargs)
- log = _LOG.warning if process.returncode else _LOG.debug
+ logfunc = _LOG.warning if process.returncode else _LOG.debug
- log('[COMMAND] %s\n%s',
- ', '.join(f'{k}={v}' for k, v in sorted(kwargs.items())),
- ' '.join(shlex.quote(str(arg)) for arg in args))
+ logfunc('[COMMAND] %s\n%s',
+ ', '.join(f'{k}={v}' for k, v in sorted(kwargs.items())),
+ ' '.join(shlex.quote(str(arg)) for arg in args))
- log('[RESULT] %s with return code %d',
- 'Failed' if process.returncode else 'Passed', process.returncode)
+ logfunc('[RESULT] %s with return code %d',
+ 'Failed' if process.returncode else 'Passed', process.returncode)
output = process.stdout.decode(errors='backslashreplace')
if output:
- log('[OUTPUT]\n%s', output)
+ logfunc('[OUTPUT]\n%s', output)
if process.returncode:
raise PresubmitFailure
@@ -608,6 +628,7 @@
"""Presubmit check that ensures all header files contain '#pragma once'."""
for path in ctx.paths:
+ _LOG.debug('Checking %s', path)
with open(path) as file:
for line in file:
if line.startswith('#pragma once'):
