feat: add debug logging of repo sub processes (#1735)
Debugging what the repo rules are up to can be difficult because Bazel
doesn't provide many facilities to inspect what they're up to. This adds
an environment variable, `RULES_PYTHON_REPO_DEBUG`, that, when set, will
make our repo rules print out detailed information about the
subprocesses they are running.
This also makes failed commands dump much more comprehensive
information.
This was driven by the recent report of failures on Windows during a
repo rule.
diff --git a/CHANGELOG.md b/CHANGELOG.md
index 01e7c07..51c7c6f 100644
--- a/CHANGELOG.md
+++ b/CHANGELOG.md
@@ -61,6 +61,11 @@
rely on toolchain configuration and how the latest version takes precedence
if e.g. `3.8` is selected. That also simplifies `.bazelrc` for any users
that set the default `python_version` string flag in that way.
+
+* (repo rules) The environment variable `RULES_PYTHON_REPO_DEBUG=1` can be
+ set to make repository rules log detailed information about what they're
+ up to.
+
## 0.29.0 - 2024-01-22
[0.29.0]: https://github.com/bazelbuild/rules_python/releases/tag/0.29.0
diff --git a/python/BUILD.bazel b/python/BUILD.bazel
index 1ab59d5..cc6348a 100644
--- a/python/BUILD.bazel
+++ b/python/BUILD.bazel
@@ -203,8 +203,8 @@
"//python/private:coverage_deps_bzl",
"//python/private:full_version_bzl",
"//python/private:internal_config_repo_bzl",
+ "//python/private:repo_utils_bzl",
"//python/private:toolchains_repo_bzl",
- "//python/private:which_bzl",
],
)
diff --git a/python/pip_install/BUILD.bazel b/python/pip_install/BUILD.bazel
index d90fb2c..e794075 100644
--- a/python/pip_install/BUILD.bazel
+++ b/python/pip_install/BUILD.bazel
@@ -35,8 +35,8 @@
"//python/private:parse_whl_name_bzl",
"//python/private:patch_whl_bzl",
"//python/private:render_pkg_aliases_bzl",
+ "//python/private:repo_utils_bzl",
"//python/private:toolchains_repo_bzl",
- "//python/private:which_bzl",
"//python/private:whl_target_platforms_bzl",
"@bazel_skylib//lib:sets",
],
diff --git a/python/pip_install/pip_repository.bzl b/python/pip_install/pip_repository.bzl
index 382855c..110ade1 100644
--- a/python/pip_install/pip_repository.bzl
+++ b/python/pip_install/pip_repository.bzl
@@ -27,8 +27,8 @@
load("//python/private:parse_whl_name.bzl", "parse_whl_name")
load("//python/private:patch_whl.bzl", "patch_whl")
load("//python/private:render_pkg_aliases.bzl", "render_pkg_aliases")
+load("//python/private:repo_utils.bzl", "REPO_DEBUG_ENV_VAR", "repo_utils")
load("//python/private:toolchains_repo.bzl", "get_host_os_arch")
-load("//python/private:which.bzl", "which_with_fail")
load("//python/private:whl_target_platforms.bzl", "whl_target_platforms")
CPPFLAGS = "CPPFLAGS"
@@ -115,7 +115,11 @@
if not rctx.os.name.lower().startswith("mac os"):
return []
- xcode_sdk_location = rctx.execute([which_with_fail("xcode-select", rctx), "--print-path"])
+ xcode_sdk_location = repo_utils.execute_unchecked(
+ rctx,
+ op = "GetXcodeLocation",
+ arguments = [repo_utils.which_checked(rctx, "xcode-select"), "--print-path"],
+ )
if xcode_sdk_location.return_code != 0:
return []
@@ -144,14 +148,16 @@
if not is_standalone_interpreter(rctx, python_interpreter):
return []
- er = rctx.execute([
- python_interpreter,
- "-c",
- "import sys; print(f'{sys.version_info[0]}.{sys.version_info[1]}', end='')",
- ])
- if er.return_code != 0:
- fail("could not get python version from interpreter (status {}): {}".format(er.return_code, er.stderr))
- _python_version = er.stdout
+ stdout = repo_utils.execute_checked_stdout(
+ rctx,
+ op = "GetPythonVersionForUnixCflags",
+ arguments = [
+ python_interpreter,
+ "-c",
+ "import sys; print(f'{sys.version_info[0]}.{sys.version_info[1]}', end='')",
+ ],
+ )
+ _python_version = stdout
include_path = "{}/include/python{}".format(
python_interpreter.dirname,
_python_version,
@@ -406,6 +412,7 @@
common_env = [
"RULES_PYTHON_PIP_ISOLATED",
+ REPO_DEBUG_ENV_VAR,
]
common_attrs = {
@@ -526,7 +533,7 @@
You can also target a specific Python version by using `cp3<minor_version>_<os>_<arch>`.
If multiple python versions are specified as target platforms, then select statements
-of the `lib` and `whl` targets will include usage of version aware toolchain config
+of the `lib` and `whl` targets will include usage of version aware toolchain config
settings like `@rules_python//python/config_settings:is_python_3.y`.
Special values: `host` (for generating deps for the host platform only) and
@@ -753,28 +760,14 @@
# Manually construct the PYTHONPATH since we cannot use the toolchain here
environment = _create_repository_execution_environment(rctx, python_interpreter)
- result = rctx.execute(
- args,
+ repo_utils.execute_checked(
+ rctx,
+ op = "whl_library.ResolveRequirement({}, {})".format(rctx.attr.name, rctx.attr.requirement),
+ arguments = args,
environment = environment,
quiet = rctx.attr.quiet,
timeout = rctx.attr.timeout,
)
- if result.return_code:
- fail((
- "whl_library '{name}' wheel_installer failed:\n" +
- " command: {cmd}\n" +
- " environment:\n{env}\n" +
- " return code: {return_code}\n" +
- "===== stdout start ====\n{stdout}\n===== stdout end===\n" +
- "===== stderr start ====\n{stderr}\n===== stderr end===\n"
- ).format(
- name = rctx.attr.name,
- cmd = " ".join([str(a) for a in args]),
- env = "\n".join(["{}={}".format(k, v) for k, v in environment.items()]),
- return_code = result.return_code,
- stdout = result.stdout,
- stderr = result.stderr,
- ))
whl_path = rctx.path(json.decode(rctx.read("whl_file.json"))["whl_file"])
if not rctx.delete("whl_file.json"):
@@ -807,8 +800,10 @@
for p in whl_target_platforms(parsed_whl.platform_tag)
]
- result = rctx.execute(
- args + [
+ repo_utils.execute_checked(
+ rctx,
+ op = "whl_library.ExtractWheel({}, {})".format(rctx.attr.name, whl_path),
+ arguments = args + [
"--whl-file",
whl_path,
] + ["--platform={}".format(p) for p in target_platforms],
@@ -817,9 +812,6 @@
timeout = rctx.attr.timeout,
)
- if result.return_code:
- fail("whl_library %s failed: %s (%s) error code: '%s'" % (rctx.attr.name, result.stdout, result.stderr, result.return_code))
-
metadata = json.decode(rctx.read("metadata.json"))
rctx.delete("metadata.json")
diff --git a/python/private/BUILD.bazel b/python/private/BUILD.bazel
index 20e260d..221c3b7 100644
--- a/python/private/BUILD.bazel
+++ b/python/private/BUILD.bazel
@@ -209,6 +209,11 @@
)
bzl_library(
+ name = "repo_utils_bzl",
+ srcs = ["repo_utils.bzl"],
+)
+
+bzl_library(
name = "stamp_bzl",
srcs = ["stamp.bzl"],
visibility = ["//:__subpackages__"],
@@ -223,7 +228,7 @@
name = "toolchains_repo_bzl",
srcs = ["toolchains_repo.bzl"],
deps = [
- ":which_bzl",
+ ":repo_utils_bzl",
"//python:versions_bzl",
],
)
@@ -243,15 +248,6 @@
)
bzl_library(
- name = "which_bzl",
- srcs = ["which.bzl"],
- visibility = [
- "//docs:__subpackages__",
- "//python:__subpackages__",
- ],
-)
-
-bzl_library(
name = "whl_target_platforms_bzl",
srcs = ["whl_target_platforms.bzl"],
visibility = ["//:__subpackages__"],
diff --git a/python/private/repo_utils.bzl b/python/private/repo_utils.bzl
new file mode 100644
index 0000000..4d8b408
--- /dev/null
+++ b/python/private/repo_utils.bzl
@@ -0,0 +1,230 @@
+# Copyright 2024 The Bazel Authors. All rights reserved.
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+# http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+
+"""Functionality shared only by repository rule phase code.
+
+This code should only be loaded and used during the repository phase.
+"""
+
+REPO_DEBUG_ENV_VAR = "RULES_PYTHON_REPO_DEBUG"
+
+def _is_repo_debug_enabled(rctx):
+ """Tells if debbugging output is requested during repo operatiosn.
+
+ Args:
+ rctx: repository_ctx object
+
+ Returns:
+ True if enabled, False if not.
+ """
+ return rctx.os.environ.get(REPO_DEBUG_ENV_VAR) == "1"
+
+def _debug_print(rctx, message_cb):
+ """Prints a message if repo debugging is enabled.
+
+ Args:
+ rctx: repository_ctx
+ message_cb: Callable that returns the string to print. Takes
+ no arguments.
+ """
+ if _is_repo_debug_enabled(rctx):
+ print(message_cb()) # buildifier: disable=print
+
+def _execute_internal(
+ rctx,
+ *,
+ op,
+ fail_on_error = False,
+ arguments,
+ environment = {},
+ **kwargs):
+ """Execute a subprocess with debugging instrumention.
+
+ Args:
+ rctx: repository_ctx object
+ op: string, brief description of the operation this command
+ represents. Used to succintly describe it in logging and
+ error messages.
+ fail_on_error: bool, True if fail() should be called if the command
+ fails (non-zero exit code), False if not.
+ arguments: list of arguments; see rctx.execute#arguments.
+ environment: optional dict of the environment to run the command
+ in; see rctx.execute#environment.
+ **kwargs: additional kwargs to pass onto rctx.execute
+
+ Returns:
+ exec_result object, see repository_ctx.execute return type.
+ """
+ _debug_print(rctx, lambda: (
+ "repo.execute: {op}: start\n" +
+ " command: {cmd}\n" +
+ " working dir: {cwd}\n" +
+ " timeout: {timeout}\n" +
+ " environment:{env_str}\n"
+ ).format(
+ op = op,
+ cmd = _args_to_str(arguments),
+ cwd = _cwd_to_str(rctx, kwargs),
+ timeout = _timeout_to_str(kwargs),
+ env_str = _env_to_str(environment),
+ ))
+
+ result = rctx.execute(arguments, environment = environment, **kwargs)
+
+ if fail_on_error and result.return_code != 0:
+ fail((
+ "repo.execute: {op}: end: failure:\n" +
+ " command: {cmd}\n" +
+ " return code: {return_code}\n" +
+ " working dir: {cwd}\n" +
+ " timeout: {timeout}\n" +
+ " environment:{env_str}\n" +
+ "{output}"
+ ).format(
+ op = op,
+ cmd = _args_to_str(arguments),
+ return_code = result.return_code,
+ cwd = _cwd_to_str(rctx, kwargs),
+ timeout = _timeout_to_str(kwargs),
+ env_str = _env_to_str(environment),
+ output = _outputs_to_str(result),
+ ))
+ elif _is_repo_debug_enabled(rctx):
+ # buildifier: disable=print
+ print((
+ "repo.execute: {op}: end: {status}\n" +
+ " return code: {return_code}\n" +
+ "{output}"
+ ).format(
+ op = op,
+ status = "success" if result.return_code == 0 else "failure",
+ return_code = result.return_code,
+ output = _outputs_to_str(result),
+ ))
+
+ return result
+
+def _execute_unchecked(*args, **kwargs):
+ """Execute a subprocess.
+
+ Additional information will be printed if debug output is enabled.
+
+ Args:
+ *args: see _execute_internal
+ **kwargs: see _execute_internal
+
+ Returns:
+ exec_result object, see repository_ctx.execute return type.
+ """
+ return _execute_internal(fail_on_error = False, *args, **kwargs)
+
+def _execute_checked(*args, **kwargs):
+ """Execute a subprocess, failing for a non-zero exit code.
+
+ If the command fails, then fail() is called with detailed information
+ about the command and its failure.
+
+ Args:
+ *args: see _execute_internal
+ **kwargs: see _execute_internal
+
+ Returns:
+ exec_result object, see repository_ctx.execute return type.
+ """
+ return _execute_internal(fail_on_error = True, *args, **kwargs)
+
+def _execute_checked_stdout(*args, **kwargs):
+ """Calls execute_checked, but only returns the stdout value."""
+ return _execute_checked(*args, **kwargs).stdout
+
+def _which_checked(rctx, binary_name):
+ """Tests to see if a binary exists, and otherwise fails with a message.
+
+ Args:
+ binary_name: name of the binary to find.
+ rctx: repository context.
+
+ Returns:
+ rctx.Path for the binary.
+ """
+ binary = rctx.which(binary_name)
+ if binary == None:
+ fail(("Unable to find the binary '{binary_name}' on PATH.\n" +
+ " PATH = {path}".format(rctx.os.environ.get("PATH"))))
+ return binary
+
+def _args_to_str(arguments):
+ return " ".join([_arg_repr(a) for a in arguments])
+
+def _arg_repr(value):
+ if _arg_should_be_quoted(value):
+ return repr(value)
+ else:
+ return str(value)
+
+_SPECIAL_SHELL_CHARS = [" ", "'", '"', "{", "$", "("]
+
+def _arg_should_be_quoted(value):
+ # `value` may be non-str, such as ctx.path objects
+ value_str = str(value)
+ for char in _SPECIAL_SHELL_CHARS:
+ if char in value_str:
+ return True
+ return False
+
+def _cwd_to_str(rctx, kwargs):
+ cwd = kwargs.get("working_directory")
+ if not cwd:
+ cwd = "<default: {}>".format(rctx.path(""))
+ return cwd
+
+def _env_to_str(environment):
+ if not environment:
+ env_str = " <default environment>"
+ else:
+ env_str = "\n".join(["{}={}".format(k, repr(v)) for k, v in environment.items()])
+ env_str = "\n" + env_str
+ return env_str
+
+def _timeout_to_str(kwargs):
+ return kwargs.get("timeout", "<default timeout>")
+
+def _outputs_to_str(result):
+ lines = []
+ items = [
+ ("stdout", result.stdout),
+ ("stderr", result.stderr),
+ ]
+ for name, content in items:
+ if content:
+ lines.append("===== {} start =====".format(name))
+
+ # Prevent adding an extra new line, which makes the output look odd.
+ if content.endswith("\n"):
+ lines.append(content[:-1])
+ else:
+ lines.append(content)
+ lines.append("===== {} end =====".format(name))
+ else:
+ lines.append("<{} empty>".format(name))
+ return "\n".join(lines)
+
+repo_utils = struct(
+ execute_checked = _execute_checked,
+ execute_unchecked = _execute_unchecked,
+ execute_check_stdout = _execute_checked_stdout,
+ is_repo_debug_enabled = _is_repo_debug_enabled,
+ debug_print = _debug_print,
+ which_checked = _which_checked,
+)
diff --git a/python/private/toolchains_repo.bzl b/python/private/toolchains_repo.bzl
index 17ef1a3..c586208 100644
--- a/python/private/toolchains_repo.bzl
+++ b/python/private/toolchains_repo.bzl
@@ -30,7 +30,7 @@
"PLATFORMS",
"WINDOWS_NAME",
)
-load(":which.bzl", "which_with_fail")
+load("//python/private:repo_utils.bzl", "REPO_DEBUG_ENV_VAR", "repo_utils")
def get_repository_name(repository_workspace):
dummy_label = "//:_"
@@ -226,6 +226,7 @@
),
"_rules_python_workspace": attr.label(default = Label("//:WORKSPACE")),
},
+ environ = [REPO_DEBUG_ENV_VAR],
)
def _host_toolchain_impl(rctx):
@@ -363,7 +364,11 @@
os_name = WINDOWS_NAME
else:
# This is not ideal, but bazel doesn't directly expose arch.
- arch = rctx.execute([which_with_fail("uname", rctx), "-m"]).stdout.strip()
+ arch = repo_utils.execute_unchecked(
+ rctx,
+ op = "GetUname",
+ arguments = [repo_utils.which_checked(rctx, "uname"), "-m"],
+ ).stdout.strip()
# Normalize the os_name.
if "mac" in os_name.lower():
diff --git a/python/repositories.bzl b/python/repositories.bzl
index 1a6c0e5..aab68eb 100644
--- a/python/repositories.bzl
+++ b/python/repositories.bzl
@@ -25,6 +25,7 @@
load("//python/private:coverage_deps.bzl", "coverage_dep")
load("//python/private:full_version.bzl", "full_version")
load("//python/private:internal_config_repo.bzl", "internal_config_repo")
+load("//python/private:repo_utils.bzl", "REPO_DEBUG_ENV_VAR", "repo_utils")
load(
"//python/private:toolchains_repo.bzl",
"host_toolchain",
@@ -32,7 +33,6 @@
"toolchain_aliases",
"toolchains_repo",
)
-load("//python/private:which.bzl", "which_with_fail")
load(
":versions.bzl",
"DEFAULT_RELEASE_BASE_URL",
@@ -86,13 +86,17 @@
return False
# This is a rules_python provided toolchain.
- return rctx.execute([
- "ls",
- "{}/{}".format(
- python_interpreter_path.dirname,
- STANDALONE_INTERPRETER_FILENAME,
- ),
- ]).return_code == 0
+ return repo_utils.execute_unchecked(
+ rctx,
+ op = "IsStandaloneInterpreter",
+ arguments = [
+ "ls",
+ "{}/{}".format(
+ python_interpreter_path.dirname,
+ STANDALONE_INTERPRETER_FILENAME,
+ ),
+ ],
+ ).return_code == 0
def _python_repository_impl(rctx):
if rctx.attr.distutils and rctx.attr.distutils_content:
@@ -125,35 +129,32 @@
)
working_directory = "zstd-{version}".format(version = rctx.attr.zstd_version)
- make_result = rctx.execute(
- [which_with_fail("make", rctx), "--jobs=4"],
+ repo_utils.execute_checked(
+ rctx,
+ op = "python_repository.MakeZstd",
+ arguments = [
+ repo_utils.which_checked(rctx, "make"),
+ "--jobs=4",
+ ],
timeout = 600,
quiet = True,
working_directory = working_directory,
)
- if make_result.return_code:
- fail_msg = (
- "Failed to compile 'zstd' from source for use in Python interpreter extraction. " +
- "'make' error message: {}".format(make_result.stderr)
- )
- fail(fail_msg)
zstd = "{working_directory}/zstd".format(working_directory = working_directory)
unzstd = "./unzstd"
rctx.symlink(zstd, unzstd)
- exec_result = rctx.execute([
- which_with_fail("tar", rctx),
- "--extract",
- "--strip-components=2",
- "--use-compress-program={unzstd}".format(unzstd = unzstd),
- "--file={}".format(release_filename),
- ])
- if exec_result.return_code:
- fail_msg = (
- "Failed to extract Python interpreter from '{}'. ".format(release_filename) +
- "'tar' error message: {}".format(exec_result.stderr)
- )
- fail(fail_msg)
+ repo_utils.execute_checked(
+ rctx,
+ op = "python_repository.ExtractRuntime",
+ arguments = [
+ repo_utils.which_checked(rctx, "tar"),
+ "--extract",
+ "--strip-components=2",
+ "--use-compress-program={unzstd}".format(unzstd = unzstd),
+ "--file={}".format(release_filename),
+ ],
+ )
else:
rctx.download_and_extract(
url = urls,
@@ -183,20 +184,23 @@
if "windows" not in rctx.os.name:
lib_dir = "lib" if "windows" not in platform else "Lib"
- exec_result = rctx.execute([which_with_fail("chmod", rctx), "-R", "ugo-w", lib_dir])
- if exec_result.return_code != 0:
- fail_msg = "Failed to make interpreter installation read-only. 'chmod' error msg: {}".format(
- exec_result.stderr,
- )
- fail(fail_msg)
- exec_result = rctx.execute([which_with_fail("touch", rctx), "{}/.test".format(lib_dir)])
+ repo_utils.execute_checked(
+ rctx,
+ op = "python_repository.MakeReadOnly",
+ arguments = [repo_utils.which_checked(rctx, "chmod"), "-R", "ugo-w", lib_dir],
+ )
+ exec_result = repo_utils.execute_unchecked(
+ rctx,
+ op = "python_repository.TestReadOnly",
+ arguments = [repo_utils.which_checked(rctx, "touch"), "{}/.test".format(lib_dir)],
+ )
if exec_result.return_code == 0:
- exec_result = rctx.execute([which_with_fail("id", rctx), "-u"])
- if exec_result.return_code != 0:
- fail("Could not determine current user ID. 'id -u' error msg: {}".format(
- exec_result.stderr,
- ))
- uid = int(exec_result.stdout.strip())
+ stdout = repo_utils.execute_checked_stdout(
+ rctx,
+ op = "python_repository.GetUserId",
+ arguments = [repo_utils.which_checked(rctx, "id"), "-u"],
+ )
+ uid = int(stdout.strip())
if uid == 0:
fail("The current user is root, please run as non-root when using the hermetic Python interpreter. See https://github.com/bazelbuild/rules_python/pull/713.")
else:
@@ -485,6 +489,7 @@
default = "1.5.2",
),
},
+ environ = [REPO_DEBUG_ENV_VAR],
)
# Wrapper macro around everything above, this is the primary API.
