pantsbuild / pants

The Pants Build System
https://www.pantsbuild.org
Apache License 2.0
3.33k stars 638 forks source link

Issues using mypy plugin for protobuf when using remote execution. #11742

Closed charlesoconor closed 3 years ago

charlesoconor commented 3 years ago
./mypy_protobuf.pex_bin_protoc-gen-mypy_shim.sh: line 13: /worker/build/e841d0f337b8996a/root/.cache/pex_root/venvs/3bc7ec2539a56272ae35134b048039e4682f9a44/800ae8ef047bd783543e8282c22bfdbee7b7fca8/bin/protoc-gen-mypy: No such file or directory
--mypy_out: protoc-gen-mypy: Plugin failed with status code 127.

Looks like bin/protoc-gen-mypy isn't being copied over. Everything works well when

[python-protobuf]
mypy_plugin = false

I'm using pants 2.3.0rc3 but I believe I had the same issue with 2.2.0

I'm using build barn for doing remote execution.

The feature works correctly without running remotely.

jsirois commented 3 years ago

@charlesoconor I'm guessing you have a PEX_PYTHON_PATH or [python-setup] interpreter_search_paths that has changed since the 1st time the mypy plugin PEX was built for linux. It's not yet clear to me how this is leaking through to Pex from Pants - but assuming it is then the following logic does lead to this bug:

The path that can't be found has 2 hashes amongst its components. The 1st is the PEX file hash - which is constant. The second is a hash of variables that can affect interpreter selection for that PEX file:

.cache/pex_root/venvs/3bc7ec2539a56272ae35134b048039e4682f9a44/800ae8ef047bd783543e8282c22bfdbee7b7fca8/bin/protoc-gen-mypy

The script in question is here and line 13 is the last line: https://github.com/pantsbuild/pants/blob/e4a00eb2750d00371cfe1d438c872ec3ea926369/src/python/pants/backend/python/util_rules/pex.py#L688-L704

You can see above, the path that's turning up not found is checked for existence and re-generated in an if block above. The re-generation though must have a different PEX_PYTHON_PATH from when the script was generated: https://github.com/pantsbuild/pex/blob/4619b107b1e6c37cfd98a1b0f43bb4f7a33d3945/pex/variables.py#L667-L675

Looking into this made me realize there is a bug in that Pex code. It should be hashing the contents of PATH too since that also influences interpreter selection: https://github.com/pantsbuild/pex/issues/1282. That bug is not in play here.

tom--pollard commented 3 years ago

Also seeing this issue in reapis-testing https://gitlab.com/remote-apis-testing/remote-apis-testing/-/merge_requests/231 for 2.3.0rc3 (building https://github.com/pantsbuild/example-python/ against RE server implementations, working with 2.2.0)

jsirois commented 3 years ago

Excellent - that's super helpful to know and narrows the bug search space. Thanks @tom--pollard.

jsirois commented 3 years ago

Alright - https://gitlab.com/remote-apis-testing/remote-apis-testing/-/blob/master/docker-compose/run.sh was invaluable here.

With:

$ git diff
diff --git a/matrix.yml b/matrix.yml
index e8ece49..0aa8829 100644
--- a/matrix.yml
+++ b/matrix.yml
@@ -82,7 +82,7 @@ projects:
     filename: docker-compose-pants.jinja2_template
     version_refs:
       PANTS_COMMIT:
-        value: 5e76f94ccabddac74b622dbb9087fc7fd2d8ba17
+        value: 37d7d99a66d28f05be1e84b41871a3a9f806de0c
         update_function: get_latest_commit_hash_from_git_repo
         update_args:
           repo: https://github.com/pantsbuild/example-python.git

The failure is:

$ cd docker-compose
$ ./create_docker_compose_yaml.py 
docker-compose-remote_asset.yml
docker-compose-bazel.yml
docker-compose-goma.yml
docker-compose-pants.yml
docker-compose-recc.yml
docker-compose-buildbarn.yml
docker-compose-buildfarm.yml
docker-compose-buildgrid.yml
$ ./run.sh -c docker-compose-pants.yml -s docker-compose-buildbarn.yml
...
client_1  | 20:26:58.29 [INFO] Completed: Building mypy_protobuf.pex with 1 requirement: mypy-protobuf==1.23
client_1  | 20:26:58.29 [DEBUG] Completed: (Waiting) Building mypy_protobuf.pex with 1 requirement: mypy-protobuf==1.23
client_1  | 20:26:58.29 [DEBUG] Completed: local_cache_read
client_1  | 20:26:58.29 [DEBUG] Starting: load_bytes_with(remote-execution/blobs/1453e497ea5ce6a08fa8ce7c0564c642b67c695215d3f36b90e40933dd510b53/144)
client_1  | 20:26:58.29 [DEBUG] Completed: load_bytes_with(remote-execution/blobs/1453e497ea5ce6a08fa8ce7c0564c642b67c695215d3f36b90e40933dd510b53/144)
client_1  | 20:26:58.29 [DEBUG] Completed: pants.backend.python.util_rules.pex.build_pex
client_1  | 20:26:58.29 [DEBUG] Starting: local_cache_read
client_1  | 20:26:58.29 [DEBUG] Starting: (Waiting) Generating Python sources from helloworld/util/proto/config.proto.
client_1  | 20:26:58.29 [DEBUG] Running Generating Python sources from helloworld/util/proto/config.proto. under semaphore with concurrency id: 29
client_1  | 20:26:58.29 [DEBUG] Starting: Generating Python sources from helloworld/util/proto/config.proto.
client_1  | 20:26:58.29 [DEBUG] Remote execution: Generating Python sources from helloworld/util/proto/config.proto.
client_1  | 20:26:58.29 [DEBUG] built REv2 request (build_id=pants_run_2021_03_20_20_26_34_672_33d2494dcc62437ab7f038405b459c0b): action=Action { command_digest: Some(Digest { hash: "a2ed73bfcbb72655e392824f237aa924a846787fc7f342602ee551b77d6127d6", size_bytes: 266 }), input_root_digest: Some(Digest { hash: "d6ae97b0f5dc9433049fe045aed5b1f1408c071c209d5b23f6f023a8d03025fc", size_bytes: 852 }), timeout: None, do_not_cache: false }; command=Command { arguments: ["./bin/protoc", "--python_out", "_generated_files", "--plugin=protoc-gen-mypy=./mypy_protobuf.pex_bin_protoc-gen-mypy_shim.sh", "--mypy_out", "_generated_files", "helloworld/util/proto/config.proto"], environment_variables: [EnvironmentVariable { name: "PANTS_CACHE_KEY_TARGET_PLATFORM", value: "none" }], output_files: [], output_directories: ["_generated_files"], output_paths: [], platform: Some(Platform { properties: [Property { name: "OSFamily", value: "linux" }] }), working_directory: "", output_node_properties: [] }; execute_request=ExecuteRequest { instance_name: "remote-execution", skip_cache_lookup: false, action_digest: Some(Digest { hash: "f3fd3c2742ee5e86ee82295d02384656127555f58d4d9dd10e1e2d8cd273cf25", size_bytes: 142 }), execution_policy: None, results_cache_policy: None }
client_1  | 20:26:58.29 [DEBUG] Starting: ensure_action_stored_locally
client_1  | 20:26:58.29 [DEBUG] Completed: ensure_action_stored_locally
client_1  | 20:26:58.29 [DEBUG] Starting: check_action_cache
client_1  | 20:26:58.29 [DEBUG] Completed: check_action_cache
client_1  | 20:26:58.29 [DEBUG] action cache response: build_id=pants_run_2021_03_20_20_26_34_672_33d2494dcc62437ab7f038405b459c0b; digest=Digest { hash: Fingerprint<f3fd3c2742ee5e86ee82295d02384656127555f58d4d9dd10e1e2d8cd273cf25>, size_bytes: 142 }: None
client_1  | 20:26:58.29 [DEBUG] Starting: ensure_action_uploaded
client_1  | 20:26:58.29 [DEBUG] Starting: list_missing_digests(remote-execution)
client_1  | 20:26:58.29 [DEBUG] Completed: list_missing_digests(remote-execution)
client_1  | 20:26:58.29 [DEBUG] Starting: store_bytes(remote-execution/uploads/84152385-3e2c-4e84-82f0-b3c7621aba1b/blobs/24461212fe00596848ce495412db4ef49b6d72fd63beb1641ed0ff6cc32def1f/85)
client_1  | 20:26:58.29 [DEBUG] Starting: store_bytes(remote-execution/uploads/bda6e8d9-370d-483b-b352-e4fd2effdd0e/blobs/f3fd3c2742ee5e86ee82295d02384656127555f58d4d9dd10e1e2d8cd273cf25/142)
client_1  | 20:26:58.29 [DEBUG] Starting: store_bytes(remote-execution/uploads/7bcdc03c-55f9-499f-b69e-5205f6bb7239/blobs/860a046fbd01f7dcd7d5ee1a7ff66f33bbf4ca8bb6683971761caa0e0468295a/1054)
client_1  | 20:26:58.29 [DEBUG] Starting: store_bytes(remote-execution/uploads/accc2b70-1cda-4352-b78d-3d522175e8c6/blobs/61438db8843cbff0a3dcba5555ac97dd56ef82ef2e5ff2221fae6cf544ec649f/249)
client_1  | 20:26:58.29 [DEBUG] Starting: store_bytes(remote-execution/uploads/a825deeb-ba05-425e-828d-8ca47a1d39af/blobs/98ad1a580ac91795d8ae133c5ae1ebc0bb710e6dfeb91a3d58c761d8fcbe9b5a/87)
client_1  | 20:26:58.29 [DEBUG] Starting: store_bytes(remote-execution/uploads/1821baa3-e491-4261-bbfa-9ee1677651e7/blobs/a2ed73bfcbb72655e392824f237aa924a846787fc7f342602ee551b77d6127d6/266)
client_1  | 20:26:58.30 [DEBUG] Starting: store_bytes(remote-execution/uploads/5fd59841-443d-4434-a8b0-fab397c3dc62/blobs/b1d518e0e78492774d95a61e5bada0c740c39033d031919df71ca5fed1f61852/879)
client_1  | 20:26:58.30 [DEBUG] Starting: store_bytes(remote-execution/uploads/1b1961c3-c803-4e00-b935-160487d37355/blobs/9c040bb6243cdfd2b7b97c5afcb23629ee534c6135f9dae5b6a9726a1602c893/893)
client_1  | 20:26:58.29 [DEBUG] Starting: store_bytes(remote-execution/uploads/8c4e354f-8f6d-474f-981e-4ec89cebe815/blobs/ab6ec310309779e5d08e078fdcea2fbc258f684ff0c5104081030669aafcdb4f/87)
client_1  | 20:26:58.30 [DEBUG] Starting: store_bytes(remote-execution/uploads/b17ccf17-a16b-403e-a7e3-c5b2d0f3629a/blobs/fb461a8949e55ec7ffc92c34a31b8a61679417283b7be3e0317115b9584af2f5/80)
client_1  | 20:26:58.30 [DEBUG] Starting: store_bytes(remote-execution/uploads/4286edf1-1e39-466f-9b13-b32073f351f0/blobs/10827eb0a25f76abb375719fa47749554bfd4252854aa167da56b799fb93ea99/83)
client_1  | 20:26:58.30 [DEBUG] Starting: store_bytes(remote-execution/uploads/210403f9-7e1d-4b9e-8d48-03e89cdb2a71/blobs/d6ae97b0f5dc9433049fe045aed5b1f1408c071c209d5b23f6f023a8d03025fc/852)
client_1  | 20:26:58.30 [DEBUG] Completed: store_bytes(remote-execution/uploads/1821baa3-e491-4261-bbfa-9ee1677651e7/blobs/a2ed73bfcbb72655e392824f237aa924a846787fc7f342602ee551b77d6127d6/266)
client_1  | 20:26:58.30 [DEBUG] Completed: store_bytes(remote-execution/uploads/bda6e8d9-370d-483b-b352-e4fd2effdd0e/blobs/f3fd3c2742ee5e86ee82295d02384656127555f58d4d9dd10e1e2d8cd273cf25/142)
client_1  | 20:26:58.30 [DEBUG] Starting: store_bytes(remote-execution/uploads/3a5479ba-f5a6-42a5-b762-0d2aa3ccbdb4/blobs/757487a61bf7eba5b703922f6e32b508ab653298e9fb98e998a266b2112c54c5/78)
client_1  | 20:26:58.30 [DEBUG] Completed: store_bytes(remote-execution/uploads/84152385-3e2c-4e84-82f0-b3c7621aba1b/blobs/24461212fe00596848ce495412db4ef49b6d72fd63beb1641ed0ff6cc32def1f/85)
client_1  | 20:26:58.30 [DEBUG] Starting: store_bytes(remote-execution/uploads/7684d25b-4d1c-43ba-b67d-22b356a74d42/blobs/26b7be0918ae210fc8c08339bbe387df0a0d7b4e00ab2485b27b92bb46c24bab/911)
client_1  | 20:26:58.30 [DEBUG] Completed: store_bytes(remote-execution/uploads/7bcdc03c-55f9-499f-b69e-5205f6bb7239/blobs/860a046fbd01f7dcd7d5ee1a7ff66f33bbf4ca8bb6683971761caa0e0468295a/1054)
client_1  | 20:26:58.30 [DEBUG] Starting: store_bytes(remote-execution/uploads/d2e88533-493e-4939-8821-eb5d009016ef/blobs/e29acc1fe46c4ecfa0adb48c99890f95f0cdf33fb3f0284c3222e0efacc42d31/79)
client_1  | 20:26:58.30 [DEBUG] Completed: store_bytes(remote-execution/uploads/accc2b70-1cda-4352-b78d-3d522175e8c6/blobs/61438db8843cbff0a3dcba5555ac97dd56ef82ef2e5ff2221fae6cf544ec649f/249)
client_1  | 20:26:58.30 [DEBUG] Completed: store_bytes(remote-execution/uploads/b17ccf17-a16b-403e-a7e3-c5b2d0f3629a/blobs/fb461a8949e55ec7ffc92c34a31b8a61679417283b7be3e0317115b9584af2f5/80)
client_1  | 20:26:58.30 [DEBUG] Completed: store_bytes(remote-execution/uploads/210403f9-7e1d-4b9e-8d48-03e89cdb2a71/blobs/d6ae97b0f5dc9433049fe045aed5b1f1408c071c209d5b23f6f023a8d03025fc/852)
client_1  | 20:26:58.30 [DEBUG] Completed: store_bytes(remote-execution/uploads/4286edf1-1e39-466f-9b13-b32073f351f0/blobs/10827eb0a25f76abb375719fa47749554bfd4252854aa167da56b799fb93ea99/83)
client_1  | 20:26:58.30 [DEBUG] Completed: store_bytes(remote-execution/uploads/8c4e354f-8f6d-474f-981e-4ec89cebe815/blobs/ab6ec310309779e5d08e078fdcea2fbc258f684ff0c5104081030669aafcdb4f/87)
client_1  | 20:26:58.30 [DEBUG] Completed: store_bytes(remote-execution/uploads/a825deeb-ba05-425e-828d-8ca47a1d39af/blobs/98ad1a580ac91795d8ae133c5ae1ebc0bb710e6dfeb91a3d58c761d8fcbe9b5a/87)
client_1  | 20:26:58.30 [DEBUG] Completed: store_bytes(remote-execution/uploads/1b1961c3-c803-4e00-b935-160487d37355/blobs/9c040bb6243cdfd2b7b97c5afcb23629ee534c6135f9dae5b6a9726a1602c893/893)
client_1  | 20:26:58.30 [DEBUG] Completed: store_bytes(remote-execution/uploads/3a5479ba-f5a6-42a5-b762-0d2aa3ccbdb4/blobs/757487a61bf7eba5b703922f6e32b508ab653298e9fb98e998a266b2112c54c5/78)
client_1  | 20:26:58.30 [DEBUG] Completed: store_bytes(remote-execution/uploads/d2e88533-493e-4939-8821-eb5d009016ef/blobs/e29acc1fe46c4ecfa0adb48c99890f95f0cdf33fb3f0284c3222e0efacc42d31/79)
client_1  | 20:26:58.30 [DEBUG] Completed: store_bytes(remote-execution/uploads/5fd59841-443d-4434-a8b0-fab397c3dc62/blobs/b1d518e0e78492774d95a61e5bada0c740c39033d031919df71ca5fed1f61852/879)
client_1  | 20:26:58.30 [DEBUG] Completed: store_bytes(remote-execution/uploads/7684d25b-4d1c-43ba-b67d-22b356a74d42/blobs/26b7be0918ae210fc8c08339bbe387df0a0d7b4e00ab2485b27b92bb46c24bab/911)
client_1  | 20:26:58.30 [DEBUG] Completed: ensure_action_uploaded
client_1  | 20:26:58.30 [DEBUG] Starting: run_execute_request
client_1  | 20:26:58.30 [DEBUG] no current operation: submitting execute request: build_id=pants_run_2021_03_20_20_26_34_672_33d2494dcc62437ab7f038405b459c0b; execute_request=ExecuteRequest { instance_name: "remote-execution", skip_cache_lookup: false, action_digest: Some(Digest { hash: "f3fd3c2742ee5e86ee82295d02384656127555f58d4d9dd10e1e2d8cd273cf25", size_bytes: 142 }), execution_policy: None, results_cache_policy: None }
worker_1            | 2021/03/20 20:26:58 Action: /action/remote-execution/f3fd3c2742ee5e86ee82295d02384656127555f58d4d9dd10e1e2d8cd273cf25/142/
worker_1            | 2021/03/20 20:26:59 ExecuteResponse: {"result":{"outputDirectories":[{"path":"_generated_files","treeDigest":{"hash":"102b51b9765a56a3e899f7cf0ee38e5251f9c503b357b330a49183eb7b155604","sizeBytes":"2"}}],"exitCode":1,"stderrDigest":{"hash":"0d444252ef5e76a27906edf6037fe5f0cac598a0883393603cec57c7bc8ab486","sizeBytes":"310"},"executionMetadata":{"worker":"{\"datacenter\":\"paris\",\"hostname\":\"ubuntu-worker.example.com\",\"rack\":\"4\",\"slot\":\"15\",\"thread\":\"0\"}","queuedTimestamp":"2021-03-20T20:26:58.308439798Z","workerStartTimestamp":"2021-03-20T20:26:58.308718663Z","workerCompletedTimestamp":"2021-03-20T20:26:59.713592052Z","inputFetchStartTimestamp":"2021-03-20T20:26:58.308811928Z","inputFetchCompletedTimestamp":"2021-03-20T20:26:58.381566985Z","executionStartTimestamp":"2021-03-20T20:26:58.381566985Z","executionCompletedTimestamp":"2021-03-20T20:26:59.711983990Z","outputUploadStartTimestamp":"2021-03-20T20:26:59.711983990Z","outputUploadCompletedTimestamp":"2021-03-20T20:26:59.713592052Z","auxiliaryMetadata":[{"@type":"type.googleapis.com/buildbarn.resourceusage.POSIXResourceUsage","userTime":"1.208410s","systemTime":"0.114137s","maximumResidentSetSize":"35065856","pageReclaims":"38043","pageFaults":"7","blockInputOperations":"536","blockOutputOperations":"25912","voluntaryContextSwitches":"30","involuntaryContextSwitches":"43"},{"@type":"type.googleapis.com/buildbarn.resourceusage.FilePoolResourceUsage"}]}},"message":"Action details (uncached result): /uncached_action_result/remote-execution/5f8ffa284017031fb4ff2935bde97ce5d54feef517f8ac389809a0dab9978d6b/644/"}
client_1  | 20:26:59.71 [DEBUG] Got (nested) execute response: ExecuteResponse { result: Some(ActionResult { output_files: [], output_file_symlinks: [], output_symlinks: [], output_directories: [OutputDirectory { path: "_generated_files", tree_digest: Some(Digest { hash: "102b51b9765a56a3e899f7cf0ee38e5251f9c503b357b330a49183eb7b155604", size_bytes: 2 }) }], output_directory_symlinks: [], exit_code: 1, stdout_raw: b"", stdout_digest: None, stderr_raw: b"", stderr_digest: Some(Digest { hash: "0d444252ef5e76a27906edf6037fe5f0cac598a0883393603cec57c7bc8ab486", size_bytes: 310 }), execution_metadata: Some(ExecutedActionMetadata { worker: "{\"datacenter\":\"paris\",\"hostname\":\"ubuntu-worker.example.com\",\"rack\":\"4\",\"slot\":\"15\",\"thread\":\"0\"}", queued_timestamp: Some(Timestamp { seconds: 1616272018, nanos: 308439798 }), worker_start_timestamp: Some(Timestamp { seconds: 1616272018, nanos: 308718663 }), worker_completed_timestamp: Some(Timestamp { seconds: 1616272019, nanos: 713592052 }), input_fetch_start_timestamp: Some(Timestamp { seconds: 1616272018, nanos: 308811928 }), input_fetch_completed_timestamp: Some(Timestamp { seconds: 1616272018, nanos: 381566985 }), execution_start_timestamp: Some(Timestamp { seconds: 1616272018, nanos: 381566985 }), execution_completed_timestamp: Some(Timestamp { seconds: 1616272019, nanos: 711983990 }), output_upload_start_timestamp: Some(Timestamp { seconds: 1616272019, nanos: 711983990 }), output_upload_completed_timestamp: Some(Timestamp { seconds: 1616272019, nanos: 713592052 }) }) }), cached_result: false, status: None, server_logs: {}, message: "Action details (uncached result): /uncached_action_result/remote-execution/5f8ffa284017031fb4ff2935bde97ce5d54feef517f8ac389809a0dab9978d6b/644/" }
client_1  | 20:26:59.71 [DEBUG] Completed: remote execution action scheduling
client_1  | 20:26:59.71 [DEBUG] Completed: remote execution worker input fetching
client_1  | 20:26:59.71 [DEBUG] Completed: remote execution worker command executing
client_1  | 20:26:59.71 [DEBUG] Completed: remote execution worker output uploading
client_1  | 20:26:59.71 [DEBUG] Starting: load_bytes_with(remote-execution/blobs/102b51b9765a56a3e899f7cf0ee38e5251f9c503b357b330a49183eb7b155604/2)
client_1  | 20:26:59.71 [DEBUG] Completed: load_bytes_with(remote-execution/blobs/102b51b9765a56a3e899f7cf0ee38e5251f9c503b357b330a49183eb7b155604/2)
client_1  | 20:26:59.71 [DEBUG] Completed: run_execute_request
client_1  | 20:26:59.71 [DEBUG] Completed: Generating Python sources from helloworld/util/proto/config.proto.
client_1  | 20:26:59.71 [DEBUG] Completed: (Waiting) Generating Python sources from helloworld/util/proto/config.proto.
client_1  | 20:26:59.71 [DEBUG] Completed: local_cache_read
client_1  | 20:26:59.71 [DEBUG] Starting: load_bytes_with(remote-execution/blobs/0d444252ef5e76a27906edf6037fe5f0cac598a0883393603cec57c7bc8ab486/310)
client_1  | 20:26:59.71 [DEBUG] Completed: load_bytes_with(remote-execution/blobs/0d444252ef5e76a27906edf6037fe5f0cac598a0883393603cec57c7bc8ab486/310)
client_1  | 20:26:59.71 [DEBUG] Completed: Generate Python from Protobuf
client_1  | 20:26:59.71 [DEBUG] Completed: pants.backend.python.util_rules.python_sources.prepare_python_sources
client_1  | 20:26:59.71 [DEBUG] Completed: pants.backend.python.goals.pytest_runner.setup_pytest_for_target
client_1  | 20:26:59.71 [DEBUG] Completed: Run Pytest
client_1  | 20:26:59.71 [DEBUG] Completed: `test` goal
client_1  | 20:26:59.71 [DEBUG] Canceled: Run Pytest
client_1  | 20:26:59.71 [DEBUG] Canceled: pants.backend.python.goals.pytest_runner.setup_pytest_for_target
client_1  | 20:26:59.71 [DEBUG] Canceled: Run Pytest
client_1  | 20:26:59.71 [DEBUG] Canceled: pants.backend.python.goals.pytest_runner.setup_pytest_for_target
client_1  | 20:26:59.71 [DEBUG] Canceled: pants.backend.python.util_rules.pex.build_pex
client_1  | 20:26:59.71 [DEBUG] Canceled: run_execute_request
client_1  | 20:26:59.71 [INFO] Canceled: Resolving constraints.txt
client_1  | 20:26:59.71 [DEBUG] Canceled: (Waiting) Resolving constraints.txt
client_1  | 20:26:59.71 [DEBUG] Canceled: local_cache_read
client_1  | 20:26:59.71 [DEBUG] computed 1 nodes in 24.708786 seconds. there are 557 total nodes.
client_1  | 20:26:59.71 [ERROR] Exception caught: (pants.engine.internals.scheduler.ExecutionError)
client_1  |   File "/root/.cache/pants/setup/bootstrap-Linux-x86_64/2.3.0_py38/lib/python3.8/site-packages/pants/bin/local_pants_runner.py", line 246, in run
client_1  |     engine_result = self._perform_run(goals)
client_1  |   File "/root/.cache/pants/setup/bootstrap-Linux-x86_64/2.3.0_py38/lib/python3.8/site-packages/pants/bin/local_pants_runner.py", line 167, in _perform_run
client_1  |     return self._perform_run_body(goals, poll=False)
client_1  |   File "/root/.cache/pants/setup/bootstrap-Linux-x86_64/2.3.0_py38/lib/python3.8/site-packages/pants/bin/local_pants_runner.py", line 184, in _perform_run_body
client_1  |     return self.graph_session.run_goal_rules(
client_1  |   File "/root/.cache/pants/setup/bootstrap-Linux-x86_64/2.3.0_py38/lib/python3.8/site-packages/pants/init/engine_initializer.py", line 130, in run_goal_rules
client_1  |     exit_code = self.scheduler_session.run_goal_rule(
client_1  |   File "/root/.cache/pants/setup/bootstrap-Linux-x86_64/2.3.0_py38/lib/python3.8/site-packages/pants/engine/internals/scheduler.py", line 568, in run_goal_rule
client_1  |     self._raise_on_error([t for _, t in throws])
client_1  |   File "/root/.cache/pants/setup/bootstrap-Linux-x86_64/2.3.0_py38/lib/python3.8/site-packages/pants/engine/internals/scheduler.py", line 536, in _raise_on_error
client_1  |     raise ExecutionError(
client_1  | 
client_1  | Exception message: 1 Exception encountered:
client_1  | 
client_1  |   ProcessExecutionFailure: Process 'Generating Python sources from helloworld/util/proto/config.proto.' failed with exit code 1.
client_1  | stdout:
client_1  | 
client_1  | stderr:
client_1  | ./mypy_protobuf.pex_bin_protoc-gen-mypy_shim.sh: line 13: /worker/build/60df18d1b19e3d53/root/.cache/pex_root/venvs/25392aa217b5ea036240dae0218c7a0ccd170999/800ae8ef047bd783543e8282c22bfdbee7b7fca8/bin/protoc-gen-mypy: No such file or directory
client_1  | --mypy_out: protoc-gen-mypy: Plugin failed with status code 127.
client_1  | 
client_1  | 
client_1  | 
client_1  | (Use --print-stacktrace to see more error details.)
...

Looking at the worker cache, the shim script has:

$ $ cat -n worker/cache/26b7be0918ae210fc8c08339bbe387df0a0d7b4e00ab2485b27b92bb46c24bab-911+x
     1  #!/usr/bin/bash
     2  set -euo pipefail
     3  
     4  export PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin PEX_INHERIT_PATH=false PEX_IGNORE_RCFILES=true PEX_ROOT=/root/.cache/pants/named_caches/pex_root LC_CTYPE=C.UTF-8
     5  
     6  # If the seeded venv has been removed from the PEX_ROOT, we re-seed from the original
     7  # `--venv` mode PEX file.
     8  if [ ! -e /worker/build/60df18d1b19e3d53/root/.cache/pex_root/venvs/25392aa217b5ea036240dae0218c7a0ccd170999/800ae8ef047bd783543e8282c22bfdbee7b7fca8/bin/protoc-gen-mypy ]; then
     9      rm -rf /worker/build/60df18d1b19e3d53/root/.cache/pex_root/venvs/25392aa217b5ea036240dae0218c7a0ccd170999/800ae8ef047bd783543e8282c22bfdbee7b7fca8 || true
    10      PEX_INTERPRETER=1 /usr/bin/python3.8 mypy_protobuf.pex -c ''
    11  fi
    12  
    13  exec /worker/build/60df18d1b19e3d53/root/.cache/pex_root/venvs/25392aa217b5ea036240dae0218c7a0ccd170999/800ae8ef047bd783543e8282c22bfdbee7b7fca8/bin/protoc-gen-mypy "$@"

So, the failure shows an expected PEX_ROOT of /worker/build/60df18d1b19e3d53/root/.cache/pex_root and the shim script has an embedded PEX_ROOT of /root/.cache/pants/named_caches/pex_root. The means when the venv is re-generated on line 10, it ends up at /root/... instaed of /worker/build/60df18d1b19e3d53/root/....

jsirois commented 3 years ago

The issue is over here: https://github.com/pantsbuild/pants/pull/11040#discussion_r598157608 Shouldn't be too bad to fix.

jsirois commented 3 years ago

I broke out #11753 with the targeted fix. The simple rule here is we can never store files in the CAS that contain absolute paths - which was already known. The corollary is we should never be setting environment variables for processes that likewise contain absolute paths, except maybe PATH itself as a hack around not yet being able to bootstrap all binaries.

jsirois commented 3 years ago

The cherry pick of the needed fixes to get 2.3.x working with remote execution is in #11765.

jsirois commented 3 years ago

This fix will go out in the 2.3.1 series.

jsirois commented 3 years ago

@charlesoconor the fix is now available in 2.3.1rc0: https://pypi.org/project/pantsbuild.pants/2.3.1rc0/

tom--pollard commented 3 years ago

Thanks @jsirois!

charlesoconor commented 3 years ago

Thank you!

jsirois commented 3 years ago

@charlesoconor if you get a chance to try out 2.3.1rc0 and report back, that would be great. Although we have confirmation of a fix via the remote-apis-testing project, confirmation your issue is fixed would be good to have prior to cutting 2.3.1 final.