Hi again Pants dev team! I have been meaning to drop back in again to share our experience and where we aim to go from here now that we have been setup on Pants for about a month and have successfully started disting projects from our repo. Unfortunately, for the moment I'm here for help as our builds have recently started failing on production CI servers (still works locally). The error is traced to when Pants tries to install its requirements packages from PyPI. Each attempt results in the following error:

18:30:01 SHA256 fingerprint of file:///var/tmp/pjenkslv/jenkins/workspace/casper-codetree-release-lib-ANY/casper/codetree/codetree/src/pantsbuild/pex verified.
18:30:01 Preparinng bootstrap with initial requirements
18:30:01 /ms/dist/python/PROJ/core/3.7.5/exec/bin/python: can't find '__main__' module in '/var/tmp/emmdev/.pex/unzipped_pexes/478cc1fa371ca40aa3e7dafee735ca438d4a243f'

The specific line is:

"${python}" "${pex_path}" --cert="${PIP_CERT}" -r requirements.txt -c virtualenv -o virtualenv.pex --retries=1 --timeout=1 --index-url="${PIP_INDEX_URL}"

The extra arguments are our own to make downloading packages work, but this is in the boostrap_virtualenv function, and it has worked fine until just recently. It's very hard to diagnose problems on the CI host, so at the moment I can't tell if this is Pants/Pex related or some problem with the host...

Hrm, the 1st thing you'd want to do is inspect that host. If I

python .

and I have

__main__.py

in the current directory, it runs. If I rename it to

__not_main__.py

I get your error:

$ python .
Hello!
$ mv __main__.py __not_main__.py
$ python .
/home/jsirois/.pyenv/versions/3.10.2/bin/python: can't find '__main__' module in '/tmp/test/.'
$

Is it true that

/var/tmp/emmdev

is the CI user's home dir and that it is in-fact temporary and re-populated on each CI run?

Version is 2.9.0. The home directory /var/tmp/emmdev is set because the system id's home directory is not writeable (firm policy); but it is indeed writeable and is what we're told to use when we need temporary data storage (but it gets cleaned up, I'm not sure what the schedule is though, but we haven't worried about caching/performance yet, and were happy to let Pants rebootstrap itself, etc. on each build for now). I made some progress by explicitly deleting ~/.cache/pants and ~/.pex at the beginning of the build script. It now gets passed the part of getting all of its dependencies from PyPI. But now it fails when trying to invoke pip.

The Pex warning was fixed in Pex 2.1.44. If you re-curl your pants script you can pick up a fix for that (see: https://www.pantsbuild.org/docs/installation).

Indeed, it's not 2GB. I had some success by nuking the tmp homedir on each CI run. In retrospect, I wonder if the private PR job running simultaneously with the release job was causing problems (is there any references on best practices to using a tool like Pants for concurrent CI jobs, possibly pulling code from different branches and clashing with the cache?) But before I resorted to that, I created an NFS compile share for the system id running Pants. It seemed to be working, as Pants successfully bootstrapped itself and I could see its named cache folders. Running

./pants version

returned the expected result too. BUT! When it came time for

./pants package ::

bad things happened. I added some

echo

and

ls

statements in the pants script just before the pex execution line to debug. Seems Pants can in fact see the file its complaining about before the exec line, but not after (maybe in some subprocess?). But you can see below the

ls -la

shows emmdev created that file and that it has execute permissions. But the job ultimately fails for not seeing this file as reported in ProcessExecutionFailure error. I don't know what the significance of a fully resolved NFS file location is (with the server and all) versus the alias, if any, but the latter is the one it attempts to lookup.

19:40:07 /v/campus/ny/cs/casper/taymarti/emmdev/.cache/pants/setup/bootstrap-Linux-x86_64/2.9.0_py37
19:40:07 /v/campus/ny/cs/casper/taymarti/emmdev/.cache/pants/setup/bootstrap-Linux-x86_64/2.9.0_py37/bin/python
19:40:07 /v/campus/ny/cs/casper/taymarti/emmdev/.cache/pants/setup/bootstrap-Linux-x86_64/2.9.0_py37/bin/pants
19:40:07 /v/campus/ny/cs/casper/taymarti/emmdev/.cache/pants/setup/bootstrap-Linux-x86_64/2.9.0_py37/bin/python /v/campus/ny/cs/casper/taymarti/emmdev/.cache/pants/setup/bootstrap-Linux-x86_64/2.9.0_py37/bin/pants --pants-bin-name=./pants --pants-version=2.9.0 package ./proj/libs/clients/**
19:40:07 lrwxrwxrwx 1 emmdev ir_share 11 Feb 23 19:01 /a/stor118ncs2.new-york.ms.com/sc25317/s122015/taymarti/emmdev/.cache/pants/named_caches/pex_root/venvs/1d932cd3e82057d61e57c365b177aad9b535724c/9a128dacefb3843fa45de2c0dc225c7ee1cb4d0e/pex -> __main__.py
19:40:07 lrwxrwxrwx 1 emmdev ir_share 11 Feb 23 19:01 /v/campus/ny/cs/casper/taymarti/emmdev/.cache/pants/named_caches/pex_root/venvs/1d932cd3e82057d61e57c365b177aad9b535724c/9a128dacefb3843fa45de2c0dc225c7ee1cb4d0e/pex -> __main__.py
19:40:07 19:00:15.11 [INFO] Starting: Building build_backend.pex from setuptools_default_lockfile.txt
19:41:31 19:01:31.87 [INFO] Long running tasks:
19:41:31  76.76s  Building build_backend.pex from setuptools_default_lockfile.txt
19:41:36 19:01:36.06 [INFO] Completed: Building build_backend.pex from setuptools_default_lockfile.txt
19:41:36 19:01:36.14 [ERROR] 1 Exception encountered:
19:41:36
19:41:36  ProcessExecutionFailure: Process 'Building build_backend.pex from setuptools_default_lockfile.txt' failed with exit code 1.
19:41:36 stdout:
19:41:36
19:41:36 stderr:
19:41:36 Failed to spawn a job for DistributionTarget(interpreter=PythonInterpreter('/ms/dist/python/PROJ/core/3.7.5-0/.exec/@sys/bin/python3.7', PythonIdentity('/ms/dist/python/PROJ/core/3.7.5-0/.exec/@sys/bin/python3.7', 'cp37', 'cp37m', 'manylinux_2_17_x86_64', (3, 7, 5)))): [Errno 2] No such file or directory: '/a/stor118ncs2.new-york.ms.com/sc25317/s122015/taymarti/emmdev/.cache/pants/named_caches/pex_root/venvs/1d932cd3e82057d61e57c365b177aad9b535724c/9a128dacefb3843fa45de2c0dc225c7ee1cb4d0e/pex': '/a/stor118ncs2.new-york.ms.com/sc25317/s122015/taymarti/emmdev/.cache/pants/named_caches/pex_root/venvs/1d932cd3e82057d61e57c365b177aad9b535724c/9a128dacefb3843fa45de2c0dc225c7ee1cb4d0e/pex'
19:41:36
19:41:36
19:41:36
19:41:36 Use `--no-process-cleanup` to preserve process chroots for inspection.

I have not digested all this but, NFS. That's a huge variable. Thanks for adding that detail. All caches should be concurrency safe and this has been tested pretty well over a 2+ year period ... but definitely only in the context of local disks.

Indeed, seems NFS is a source of many difficulties 😞. I think I reported a problem here before after trying to run Pants locally, but pointing it to use an NFS location for its cache, and then having similar issues as now. I also recall the pantsd daemon did not function well w/ NFS because of issues with inotify there. Unfortunately, NFS is really the only permanent read/write storage solution currently offered at my firm. AFS solutions are read-only, and, even if we could somehow get our own dedicated CI server, local storage is regularly cleaned up and never guaranteed safe.

It does not. This model is really at the very core of things in Pants.

Ok, let me run this again w/ a stack trace and see if our infra guys can figure out if there's anything obvious going on in NFS land.

Ok, but I'm leery of putting folks to work due to my ignorance. I definitely have no clue what I'm talking about re NFS. I only know we mmap heavily in the one cache (an LMDB database used by Pants code) and use hardlinks and symlinks extensively in another. In that other I leverage a cooperative file lock heavily to deal with concurrency control (this is in Pex code). I have no clue how NFS / networked file systems handle this collection of file system operations. I need to educate myself.

I can't say for sure yet, but fairly certain

lockd

daemon is always running based on experience with poorly written programs dying when someone has the CSV file open they want to update! 🙂 As for the protocol,

nfsstat -c

is showing 8mm getattr requests on NFS3 and merely 50k on NFS2 for one of the hosts I am using. Testing on newer hosts that support NFS4, virtually all the file system operations are still NFS3. And

rpcinfo -p <http://stor118ncs2.new-york.ms.com|stor118ncs2.new-york.ms.com>

is saying this storage server only supports NFS3 and 4, so I think it's safe to say NFS3 is being used, but I will try to confirm that is really the case tomorrow, and also

netstat -c

the CI server as it might be using an older NFS protocol.

Ok - great. Thank you for that information. I'm still learning and reading up, but that helps focus things down.

Let me see if an NFS4 configuration is possible. It seems that would be a resolution as no extra protocol is needed? I had also realized I’ve been using NFS “locally” all this time w/ Pants and never had these issues. I have a suspicion that file permissions are not being properly inherited by the subprocess, resulting in not found and permission denied errors. In fact, when I pointed Pants to an NFS directory I do not own but have UNIX group based permissions to, I got similar errors running locally. So I tried creating a new compile share space for the CI system id with it as the “genuine” (whatever that turns out to mean) owner of that folder location (/v/campus/ny/cs/casper/emmdev instead of …/taymarti/emmdev where I owned the parent space but gave emmdev permissions to the sub-folder; I can’t even stat from my userid the new one now). And it WORKED! It wrote the caches as it did before, but this time the sub processes spawned by emmdev could also see those files. Unfortunately, we now have a new error. On any subsequent run I’m getting:

09:58:23 09:58:22.22 [ERROR] 1 Exception encountered:
09:58:23
09:58:23   Exception: Snapshot failed: Error storing Digest { hash: Fingerprint<827b11f107d720685bb9b013fafc76f126779197f63f9a831300554e714949ec>, size_bytes: 77 }: MDB_CURSOR_FULL: Internal error - cursor stack limit reached

Let me see if an NFS4 configuration is possible. It seems that would be a resolution as no extra protocol is needed?

Perhaps, but not a solution if the HA guess is right. For that class of problems, no matter the protocol used by clients, the multi-homed server / Byzantine Generals problem becomes the issue.

Do you want me to run the package cmd with any options for the issue ticket?

I haven't swung around to this yet, but what I'll want to gather is all the failure scenarios and separate them 1st. There are mode bits / perms issues and the MDB_CURSOR_FULL issue. If the mode bits / perms issues are still issues, I'll want output from those commands, but you may have already provided those in this thread - I need to re-read in detail.

pantsd=false in the configuration. Let me try to repeat w/ stack trace/debug flags on.

For all things "propagation to subprocesses", env vars is the 1st debugging stop since pants actively masks the environment except for very specific env vars.

Ah, it could indeed be Kerberos related. I’ll look more closely later and see if we can pinpoint. And not super helpful, but here is the full stack trace:

14:37:15 14:37:15.04 [DEBUG] Completed: `package` goal
14:37:15 14:37:15.04 [DEBUG] computed 1 nodes in 33.880423 seconds. there are 3957 total nodes.
14:37:15 14:37:15.04 [ERROR] 1 Exception encountered:
14:37:15
14:37:15 Engine traceback:
14:37:15   in select
14:37:15   in pants.core.goals.package.package_asset
14:37:15   in pants.backend.python.goals.setup_py.package_python_dist (proj/libs/clients:clients)
14:37:15   in pants.backend.python.util_rules.dists.run_pep517_build
14:37:15   in pants.backend.python.util_rules.pex.create_venv_pex (build_backend.pex)
14:37:15   in pants.backend.python.util_rules.pex.build_pex (build_backend.pex)
14:37:15   in pants.engine.process.fallible_to_exec_result_or_raise
14:37:15 Traceback (most recent call last):
14:37:15   File "/v/campus/ny/cs/casper/taymarti/emmdev/.cache/pants/setup/bootstrap-Linux-x86_64/2.9.0_py37/lib/python3.7/site-packages/pants/engine/process.py", line 287, in fallible_to_exec_result_or_raise
14:37:15     process_cleanup=process_cleanup.val,
14:37:15 pants.engine.process.ProcessExecutionFailure: Process 'Building build_backend.pex from setuptools_default_lockfile.txt' failed with exit code 1.
14:37:15 stdout:
14:37:15
14:37:15 stderr:
14:37:15 pex: Resolving interpreters
14:37:15 pex: Resolving interpreters: 0.5ms
14:37:15 pex: Building pex
14:37:15 pex: Building pex :: Resolving distributions (setuptools_default_lockfile.txt)
14:37:15 pex: Building pex :: Resolving distributions (setuptools_default_lockfile.txt) :: Resolving requirements.
14:37:15 pex: Building pex :: Resolving distributions (setuptools_default_lockfile.txt) :: Resolving requirements. :: Resolving for:
14:37:15   DistributionTarget(interpreter=PythonInterpreter('/ms/dist/python/PROJ/core/3.7.5-0/.exec/@sys/bin/python3.7', PythonIdentity('/ms/dist/python/PROJ/core/3.7.5-0/.exec/@sys/bin/python3.7', 'cp37', 'cp37m', 'manylinux_2_17_x86_64', (3, 7, 5))))
14:37:15 pex: Spawning a maximum of 4 parallel jobs to process:
14:37:15   DistributionTarget(interpreter=PythonInterpreter('/ms/dist/python/PROJ/core/3.7.5-0/.exec/@sys/bin/python3.7', PythonIdentity('/ms/dist/python/PROJ/core/3.7.5-0/.exec/@sys/bin/python3.7', 'cp37', 'cp37m', 'manylinux_2_17_x86_64', (3, 7, 5))))
14:37:15 pex: Hashing pex
14:37:15 pex: Hashing pex: 14657.6ms
14:37:15 pex: Isolating pex
14:37:15 pex: Isolating pex: 21.4ms
14:37:15 Failed to spawn a job for DistributionTarget(interpreter=PythonInterpreter('/ms/dist/python/PROJ/core/3.7.5-0/.exec/@sys/bin/python3.7', PythonIdentity('/ms/dist/python/PROJ/core/3.7.5-0/.exec/@sys/bin/python3.7', 'cp37', 'cp37m', 'manylinux_2_17_x86_64', (3, 7, 5)))): [Errno 2] No such file or directory: '/a/<http://stor118ncs2.new-york.ms.com/sc25317/s122015/taymarti/emmdev/.cache/pants/named_caches/pex_root/venvs/1d932cd3e82057d61e57c365b177aad9b535724c/9a128dacefb3843fa45de2c0dc225c7ee1cb4d0e/pex':|stor118ncs2.new-york.ms.com/sc25317/s122015/taymarti/emmdev/.cache/pants/named_caches/pex_root/venvs/1d932cd3e82057d61e57c365b177aad9b535724c/9a128dacefb3843fa45de2c0dc225c7ee1cb4d0e/pex':> '/a/<http://stor118ncs2.new-york.ms.com/sc25317/s122015/taymarti/emmdev/.cache/pants/named_caches/pex_root/venvs/1d932cd3e82057d61e57c365b177aad9b535724c/9a128dacefb3843fa45de2c0dc225c7ee1cb4d0e/pex'|stor118ncs2.new-york.ms.com/sc25317/s122015/taymarti/emmdev/.cache/pants/named_caches/pex_root/venvs/1d932cd3e82057d61e57c365b177aad9b535724c/9a128dacefb3843fa45de2c0dc225c7ee1cb4d0e/pex'>
14:37:15
14:37:15
14:37:15
14:37:15 Use `--no-process-cleanup` to preserve process chroots for inspection.

Completed, not succeeded. Unless I'm missing the success claim line.