[7.2.0rc2 regression] testpath.assert_calls (python package) can't mock subprocess calls for deeply nested files

[dougthor42]

Description of the bug:

Short-short version:
The level of nesting of a python file seems to impact whether or not the test runs successfully.

Slightly longer version:
We use the python testpath library to mock out subprocess calls for testing. In 7.2.0rc1, this worked just fine. In rc2, the test would fail.

An attempt to reproduce the error shows that things only fail if the python code is deeply nested.

I'm sorry I didn't notice this when rc2 was first released!

Error Text:

$ bazel test //...
Starting local Bazel server and connecting to it...
INFO: Analyzed 2 targets (97 packages loaded, 3244 targets configured).
FAIL: //src/one/two/three:test_foo (see /usr/local/google/home/dthor/.cache/bazel/_bazel_dthor/30f7ca8609c3fb68597eb6a26b820cba/execroot/_main/bazel-out/k8-fastbuild/testlogs/src/one/two/three/test_foo/test.log)
INFO: From Testing //src/one/two/three:test_foo:
==================== Test output for //src/one/two/three:test_foo:
E
======================================================================
ERROR: test_foo (__main__.TestFoo.test_foo)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/usr/local/google/home/dthor/.cache/bazel/_bazel_dthor/30f7ca8609c3fb68597eb6a26b820cba/sandbox/linux-sandbox/1/execroot/_main/bazel-out/k8-fastbuild/bin/src/one/two/three/test_foo.runfiles/_main/src/one/two/three/test_foo.py", line 14, in test_foo
    foo()
  File "/usr/local/google/home/dthor/.cache/bazel/_bazel_dthor/30f7ca8609c3fb68597eb6a26b820cba/sandbox/linux-sandbox/1/execroot/_main/bazel-out/k8-fastbuild/bin/src/one/two/three/test_foo.runfiles/_main/src/one/two/three/test_foo.py", line 8, in foo
    subprocess.run(["foo", "bar"])
  File "/usr/local/google/home/dthor/.cache/bazel/_bazel_dthor/30f7ca8609c3fb68597eb6a26b820cba/execroot/_main/external/rules_python~~python~python_3_11_x86_64-unknown-linux-gnu/lib/python3.11/subprocess.py", line 548, in run
    with Popen(*popenargs, **kwargs) as process:
         ^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/google/home/dthor/.cache/bazel/_bazel_dthor/30f7ca8609c3fb68597eb6a26b820cba/execroot/_main/external/rules_python~~python~python_3_11_x86_64-unknown-linux-gnu/lib/python3.11/subprocess.py", line 1026, in __init__
    self._execute_child(args, executable, preexec_fn, close_fds,
  File "/usr/local/google/home/dthor/.cache/bazel/_bazel_dthor/30f7ca8609c3fb68597eb6a26b820cba/execroot/_main/external/rules_python~~python~python_3_11_x86_64-unknown-linux-gnu/lib/python3.11/subprocess.py", line 1955, in _execute_child
    raise child_exception_type(errno_num, err_msg, err_filename)
OSError: [Errno 8] Exec format error: 'foo'

----------------------------------------------------------------------
Ran 1 test in 0.004s

FAILED (errors=1)
================================================================================
INFO: Found 1 target and 1 test target...
Target //src/one/two/three:test_foo up-to-date:
  bazel-bin/src/one/two/three/test_foo
INFO: Elapsed time: 8.860s, Critical Path: 0.67s
INFO: 4 processes: 2 internal, 2 linux-sandbox.
INFO: Build completed, 1 test FAILED, 4 total actions
//src/one/two/three:test_foo                                             FAILED in 0.4s
  /usr/local/google/home/dthor/.cache/bazel/_bazel_dthor/30f7ca8609c3fb68597eb6a26b820cba/execroot/_main/bazel-out/k8-fastbuild/testlogs/src/one/two/three/test_foo/test.log

Executed 1 out of 1 test: 1 fails locally.

Which category does this issue belong to?

Core, Python Rules

What's the simplest, easiest way to reproduce this bug? Please provide a minimal example if possible.

I was able to recreate the issue with the following config and dir structure:

.
├── .bazelrc
├── .bazelversion
├── BUILD.bazel
├── MODULE.bazel
├── requirements.txt
└── src
    └── one
        └── two
            └── three
                ├── BUILD.bazel
                └── test_foo.py

The key thing to note is that the issue doesn't happen if test_foo.py and BUILD.bazel are in src/one/two/ or shallower, only if they're in src/one/two/three/ or deeper.

Toggle .bazelversion between rc1 and rc2 to see the issue.

# src/one/two/three/BUILD.bazel
py_test(
    name = "test_foo",
    srcs = ["test_foo.py"],
    deps = ["@pypi//testpath"],
)

# src/one/two/three/test_foo.py
import subprocess
import unittest

import testpath


def foo():
    subprocess.run(["foo", "bar"])


class TestFoo(unittest.TestCase):
    def test_foo(self):
        with testpath.assert_calls("foo", args=["bar"]):
            foo()


if __name__ == "__main__":
    unittest.main()

# requirements.txt
--index-url https://pypi.org/simple

testpath==0.6.0 \
    --hash=sha256:2f1b97e6442c02681ebe01bd84f531028a7caea1af3825000f52345c30285e0f \
    --hash=sha256:8ada9f80a2ac6fb0391aa7cdb1a7d11cfa8429f693eda83f74dde570fe6fa639

# .bazelrc
common --enable_bzlmod
common --nolegacy_external_runfiles
test --test_output=errors

# .bazelversion
7.2.0rc2  # change between rc1 and rc2 to see the error

# MODULE.bazel
module(
    name = "bazelrc2-testpath-issue",
    version = "0.0.0",
    compatibility_level = 1,
)

bazel_dep(name = "bazel_skylib", version = "1.6.1")
bazel_dep(name = "rules_python", version = "0.31.0")

# Use a pre-release version of rules_python and the gazelle plugin. This mostly
# provides additional gazelle directives, but also allows the use of the bazel
# downloader for pip packages, which greatly increases caching.
git_override(
    module_name = "rules_python",
    commit = "ae1e1a014d88a9862c232daafcb6b1025b2928ae",
    remote = "https://github.com/bazelbuild/rules_python",
)

python = use_extension("@rules_python//python/extensions:python.bzl", "python")
python.toolchain(
    configure_coverage_tool = True,
    python_version = "3.11",
)

pip = use_extension("@rules_python//python/extensions:pip.bzl", "pip")
pip.parse(
    experimental_index_url = "https://pypi.org/simple",
    hub_name = "pypi",
    python_version = "3.11",
    requirements_lock = "//:requirements.txt",
)

use_repo(pip, "pypi")

# BUILD.bazel
filegroup(
    name = "python_requirements_lockfile",
    srcs = ["requirements.txt"],
)

Which operating system are you running Bazel on?

gLinux

What is the output of bazel info release?

release 7.2.0rc2

If bazel info release returns development version or (@non-git), tell us how you built Bazel.

No response

What's the output of git remote get-url origin; git rev-parse HEAD ?

No response

Is this a regression? If yes, please try to identify the Bazel commit where the bug was introduced.

Yes.

Things were fine in 7.2.0rc1.

Have you found anything relevant by searching the web?

No response

Any other information, logs, or outputs that you want to share?

No response

[dougthor42]

Two other things I forgot to mention:

• this also happens in rc3
• No additional info in the Google Bazel Users chat yet.

[fmeum]

I can't reproduce this on regular Ubuntu. Could you post the output of running with --announce_rc?

You could also bisect the failure by running Bazelisk with --bisect=7.2.0rc1..7.2.0rc2.

[meteorcloudy]

I also couldn't reproduce on macOS

pcloudy@pcloudy-macbookpro2:~/workspace/tmp/gh-22664
$ bazel --version
2024/06/07 10:33:52 Downloading https://releases.bazel.build/7.2.0/rc2/bazel-7.2.0rc2-darwin-arm64...
Downloading: 63 MB out of 63 MB (100%)
bazel 7.2.0rc2
pcloudy@pcloudy-macbookpro2:~/workspace/tmp/gh-22664
$ bazel test //...
Extracting Bazel installation...
Starting local Bazel server and connecting to it...
INFO: Invocation ID: f6e06514-a6d7-4e1e-8368-716ee44fd328
INFO: Options provided by the client:
  Inherited 'common' options: --isatty=1 --terminal_columns=210
INFO: Reading rc options for 'test' from /Users/pcloudy/workspace/tmp/gh-22664/.bazelrc:
  Inherited 'common' options: --enable_bzlmod --nolegacy_external_runfiles
INFO: Reading rc options for 'test' from /Users/pcloudy/.bazelrc:
  Inherited 'build' options: --verbose_failures --announce_rc --disk_cache=/tmp/bazel_disk_cache --repository_cache=/tmp/bazel_repository_cache --experimental_stats_summary
INFO: Reading rc options for 'test' from /Users/pcloudy/workspace/tmp/gh-22664/.bazelrc:
  'test' options: --test_output=errors
INFO: Reading rc options for 'test' from /Users/pcloudy/.bazelrc:
  'test' options: -k --test_output=errors
INFO: Analyzed 2 targets (98 packages loaded, 3159 targets configured).
INFO: Found 1 target and 1 test target...
Target //src/one/two/three:test_foo up-to-date:
  bazel-bin/src/one/two/three/test_foo
INFO: 6 processes: 4 internal, 2 darwin-sandbox.
INFO: Total action wall time 1.10s
INFO: Execution critical path 1.55s (setup 0.00s, action wall time 0.99s)
INFO: Elapsed time 34.98s (preparation 7.84s, execution 27.14s)
INFO: Build completed successfully, 6 total actions
//src/one/two/three:test_foo                                             PASSED in 1.0s

Executed 1 out of 1 test: 1 test passes.
There were tests whose specified size is too big. Use the --test_verbose_timeout_warnings command line option to see which ones these are.

[meisterT]

I was able to repro and bisect, culprit is d98b02e

[meisterT]

cc @oquenchil

[meisterT]

I can't reproduce this on regular Ubuntu. Could you post the output of running with --announce_rc?

$ bazelisk test --announce_rc //...
INFO: Options provided by the client:
  Inherited 'common' options: --isatty=1 --terminal_columns=282
INFO: Reading rc options for 'test' from /usr/local/google/home/twerth/t/.bazelrc:
  Inherited 'common' options: --enable_bzlmod --nolegacy_external_runfiles
INFO: Reading rc options for 'test' from /usr/local/google/home/twerth/t/.bazelrc:
  'test' options: --test_output=errors
INFO: Analyzed 2 targets (97 packages loaded, 3244 targets configured).
FAIL: //src/one/two/three:test_foo (see /usr/local/google/home/twerth/.cache/bazel/_bazel_twerth/8160046761d3783ee70008ffde0e375e/execroot/_main/bazel-out/k8-fastbuild/testlogs/src/one/two/three/test_foo/test.log)
...

[fmeum]

@meisterT Could you share the failure with --sandbox_debug?

[fmeum]

I can repro if I make the path of the containing package longer. Are we having long path issues on Unix now? Will investigate.

[fmeum]

testpath emits the path to the Python interpreter into a shebang, which is subject to length limitations set by the kernel at build time. Sandboxed paths happened to be shorter in Bazel 7.0.0 through 7.2.0rc1 due to the bind mounting scheme used by --incompatible_sandbox_hermetic_tmp, but I can reproduce the same failure if I just make the path a bit longer.

I will send a fix to testpath as other Bazel users may run into this, but it's not a bug in Bazel.

[fmeum]

I sent jupyter/testpath#28.

[meteorcloudy]

@fmeum Thanks for investigating!

[dougthor42]

Wow you people are good! Thanks so much! 💚

Also, TIL about bazelisk --bisect. Handy! (though now I see that it's part of the Bug instructions... my bad! 😬 )

[meteorcloudy]

@dougthor42 No worry! I'm updating the bug template to make it more prominent! Thanks for the report again!