https://pantsbuild.org/ logo
Join Slack
Powered by
Hello, I am starting to wonder if I have some sort...
# general
s
Hello, I am starting to wonder if I have some sort of misconfiguration in my setup, because even the simplest command takes a very long time.
Copy code
time pants run //helpers/utils:utils
Usage: utils.pex [OPTIONS] COMMAND [ARGS]...

  Utility commands for working with Pants build system.

Options:
  --help  Show this message and exit.

Commands:
  env    Generate PYTHONPATH environment variables from Pants roots.
  list   List targets in the repository.
  roots  Show the pants build roots.

real    0m9.211s
user    0m5.290s
sys     0m1.500s
this is not from cold, and it always takes around 10 seconds. is this expected?
I am running if within a "coder" instance (kubernetes pod) so I wonder if there are some mounts at play that might make things slower, in case not everything is contained within the mounted volume
one issue was that 
/tmp
wasnt't mounted properly, Slightly better now
Copy code
time pants run //helpers/utils:utils
Usage: utils.pex [OPTIONS] COMMAND [ARGS]...

  Utility commands for working with Pants build system.

Options:
  --help  Show this message and exit.

Commands:
  env    Generate PYTHONPATH environment variables from Pants roots.
  list   List targets in the repository.
  roots  Show the pants build roots.

real    0m7.468s
user    0m4.352s
sys     0m0.995s
if I only try "package" (to remove the pex extra run time) I get this:
Copy code
(venv) coder@sandrino:~/platform/helpers/utils$ time pants package //helpers/utils:utils
09:22:53.47 [INFO] Wrote dist/helpers.utils/utils.pex

real    0m5.706s
user    0m4.079s
sys     0m0.968s


(venv) coder@sandrino:~/platform/helpers/utils$ ls -l ~/platform/dist/helpers.utils/utils.pex
-rwxr-xr-x 1 coder coder 882189 Apr 28 09:22 /home/coder/platform/dist/helpers.utils/utils.pex
Copy code
(venv) coder@sandrino:~/platform/helpers/utils$ time pants package //helpers/utils:utils
09:24:32.28 [INFO] Wrote dist/helpers.utils/utils.pex

real    0m5.872s
user    0m4.138s
sys     0m1.063s
(venv) coder@sandrino:~/platform/helpers/utils$ ls -l ~/platform/dist/helpers.utils/utils.pex
-rwxr-xr-x 1 coder coder 882189 Apr 28 09:24 /home/coder/platform/dist/helpers.utils/utils.pex
Shouldn't this command return almost immediately with no changes to the source files? instead of rewriting the pex?
h
Well, it should still write the pex out to 
dist/
(since it can’t know if you’ve deleted it from there since it last ran) but it should copy it from cache, so this should be fast
do you see pantsd starting/running?
E.g., with 
ps -ef | grep pantsd
after the pants run?
s
But isn't the point of not "rebuilding"? maybe with "package" it makes sense, as I am asking to re-package it. But when I run, should't it detect there hasn't been a change and re-run from the last one? Yes it is running
Copy code
ps -ef | grep pantsd
coder      20306       1  0 08:46 ?        00:02:07 pantsd [/home/coder/platform]
wouldn't it be possible to "link" from the cache, to avoid the copy?
(or any other strategy that would work)
h
Yes, I was talking about 
package
. For 
run
it should rerun immediately with no extra work
Hrm
s
Also, if you make pants "authoritative" for dist, it could also "manage" it and perhaps checksum the packages to avoid unnecessary copy
(just trying to reason around it to understand better, don't take me wrong please 🙂 )
h
Perhaps, but that’s not how it works today, and typically copying files from the cache into 
dist
is very fast
So that isn’t the source of this issue
which happens even with just 
run
anyway
But are you sure work is happening? You didn’t post any pants output to that effect. It could be really slow for some other reason…
👀 1
Something specific to the coder environment that we should try and discover
s
how can I check all directories that pants is using? i discoveret /tmp by running
Copy code
pants help-advanced global | grep tmp
09:35:35.75 [INFO] waiting for pantsd to start...
09:35:38.65 [INFO] pantsd started
09:35:39.62 [INFO] Initializing scheduler...
09:35:43.86 [INFO] Scheduler initialized.
09:35:44.22 [WARN] BUILD file symbol `docker_image` conflict. Name already defined.
      default: <tmp_dir>
      current value: /tmp
absolutely, this is what I am trying to understand! thank you
will send you the ldebug output
h
Yeah, that will be helpful for that 
BUILD file symbol docker_image conflict. Name already defined.
part at any rate
s
(oh nah that's me messing things up with replacing the docker_image in a non proper way 🙂 )
h
Pants uses 
.pants.d
under the build root for internal stuff, typically 
~/cache/pants
for caches and 
dist/
for user-facing output.
Have a look at the current value of. 
--local-store-dir
in 
pants help-advanced global
👀 1
s
Copy code
default: /home/coder/.cache/pants/lmdb_store
      current value: /home/coder/.cache/pants/lmdb_store
lol. apparently running
Copy code
time pants run //helpers/utils:utils  -ldebug
vs
Copy code
pants run //helpers/utils:utils  -ldebug
makes pants restart for some reason, so some of my timings were affected by it
Copy code
(venv) coder@sandrino:~/platform$ time pants run //helpers/utils:utils  -ldebug
[2025-04-28T10:20:22Z DEBUG pantsd] Looking for pantsd metadata in /home/coder/platform/.pants.d/pids as specified by [GLOBAL] pants_subprocessdir = .pants.d/pids via Default.
[2025-04-28T10:20:22Z DEBUG pantsd] Parsed port 43937 from /home/coder/platform/.pants.d/pids/c32cbc6701f7/pantsd/socket.
10:20:24.55 [DEBUG] acquiring lock: <pants.pantsd.lock.OwnerPrintingInterProcessFileLock object at 0x7f2a7c19d6d0>
10:20:24.55 [DEBUG] terminating pantsd
10:20:24.55 [DEBUG] sending signal 15 to pid 34065
10:20:24.76 [DEBUG] successfully terminated pid 34065
10:20:24.76 [DEBUG] purging metadata directory: /home/coder/platform/.pants.d/pids/c32cbc6701f7/pantsd
10:20:24.76 [DEBUG] Launching pantsd
10:20:24.76 [DEBUG] purging metadata directory: /home/coder/platform/.pants.d/pids/c32cbc6701f7/pantsd
10:20:24.76 [DEBUG] pantsd command is: PANTS_DAEMON_ENTRYPOINT=pants.pantsd.pants_daemon:launch_new_pantsd_instance PYTHONPATH=/home/coder/.cache/nce/6d61748cea187199dc28418157b2121ccbbb44e4af2ee6fddf8c04bbed73f76d/bindings/venvs/2.25.1/bin:/home/coder/.cache/nce/78b1c16a9fd032997ba92a60f46a64f795cd18ff335659dfdf6096df277b24d5/cpython-3.11.9+20240415-x86_64-unknown-linux-gnu-install_only.tar.gz/python/lib/python311.zip:/home/coder/.cache/nce/78b1c16a9fd032997ba92a60f46a64f795cd18ff335659dfdf6096df277b24d5/cpython-3.11.9+20240415-x86_64-unknown-linux-gnu-install_only.tar.gz/python/lib/python3.11:/home/coder/.cache/nce/78b1c16a9fd032997ba92a60f46a64f795cd18ff335659dfdf6096df277b24d5/cpython-3.11.9+20240415-x86_64-unknown-linux-gnu-install_only.tar.gz/python/lib/python3.11/lib-dynload:/home/coder/.cache/nce/6d61748cea187199dc28418157b2121ccbbb44e4af2ee6fddf8c04bbed73f76d/bindings/venvs/2.25.1/lib/python3.11/site-packages /home/coder/.cache/nce/6d61748cea187199dc28418157b2121ccbbb44e4af2ee6fddf8c04bbed73f76d/bindings/venvs/2.25.1/bin/python3.11 /home/coder/.cache/nce/6d61748cea187199dc28418157b2121ccbbb44e4af2ee6fddf8c04bbed73f76d/bindings/venvs/2.25.1/bin/pants run //helpers/utils:utils -ldebug
10:20:29.77 [INFO] waiting for pantsd to start...
10:20:32.27 [INFO] pantsd started
10:20:32.27 [DEBUG] pantsd is running at pid 34698, pailgun port is 41687
Copy code
pants run //helpers/utils:utils 
10:21:51.02 [INFO] waiting for pantsd to start...
10:21:53.43 [INFO] pantsd started
10:21:54.23 [INFO] Initializing scheduler...
10:21:58.84 [INFO] Scheduler initialized.
Copy code
(venv) coder@sandrino:~/platform$ pants run //helpers/utils:utils -ldebug
[2025-04-28T10:22:31Z DEBUG pantsd] Looking for pantsd metadata in /home/coder/platform/.pants.d/pids as specified by [GLOBAL] pants_subprocessdir = .pants.d/pids via Default.
[2025-04-28T10:22:31Z DEBUG pantsd] Parsed port 38987 from /home/coder/platform/.pants.d/pids/c32cbc6701f7/pantsd/socket.
10:22:33.90 [DEBUG] acquiring lock: <pants.pantsd.lock.OwnerPrintingInterProcessFileLock object at 0x7f2e945e5b10>
10:22:33.91 [DEBUG] terminating pantsd
10:22:33.91 [DEBUG] sending signal 15 to pid 35969
10:22:34.11 [DEBUG] successfully terminated pid 35969
10:22:34.11 [DEBUG] purging metadata directory: /home/coder/platform/.pants.d/pids/c32cbc6701f7/pantsd
10:22:34.11 [DEBUG] Launching pantsd
10:22:34.11 [DEBUG] purging metadata directory: /home/coder/platform/.pants.d/pids/c32cbc6701f7/pantsd
10:22:34.12 [DEBUG] pantsd command is: PANTS_DAEMON_ENTRYPOINT=pants.pantsd.pants_daemon:launch_new_pantsd_instance PYTHONPATH=/home/coder/.cache/nce/6d61748cea187199dc28418157b2121ccbbb44e4af2ee6fddf8c04bbed73f76d/bindings/venvs/2.25.1/bin:/home/coder/.cache/nce/78b1c16a9fd032997ba92a60f46a64f795cd18ff335659dfdf6096df277b24d5/cpython-3.11.9+20240415-x86_64-unknown-linux-gnu-install_only.tar.gz/python/lib/python311.zip:/home/coder/.cache/nce/78b1c16a9fd032997ba92a60f46a64f795cd18ff335659dfdf6096df277b24d5/cpython-3.11.9+20240415-x86_64-unknown-linux-gnu-install_only.tar.gz/python/lib/python3.11:/home/coder/.cache/nce/78b1c16a9fd032997ba92a60f46a64f795cd18ff335659dfdf6096df277b24d5/cpython-3.11.9+20240415-x86_64-unknown-linux-gnu-install_only.tar.gz/python/lib/python3.11/lib-dynload:/home/coder/.cache/nce/6d61748cea187199dc28418157b2121ccbbb44e4af2ee6fddf8c04bbed73f76d/bindings/venvs/2.25.1/lib/python3.11/site-packages /home/coder/.cache/nce/6d61748cea187199dc28418157b2121ccbbb44e4af2ee6fddf8c04bbed73f76d/bindings/venvs/2.25.1/bin/python3.11 /home/coder/.cache/nce/6d61748cea187199dc28418157b2121ccbbb44e4af2ee6fddf8c04bbed73f76d/bindings/venvs/2.25.1/bin/pants run //helpers/utils:utils -ldebug
10:22:39.12 [INFO] waiting for pantsd to start...
10:22:41.83 [INFO] pantsd started
10:22:41.83 [DEBUG] pantsd is running at pid 36641, pailgun port is 40717
10:22:41.83 [DEBUG] releasing lock: <pants.pantsd.lock.OwnerPrintingInterProcessFileLock object at 0x7f2e945e5b10>
10:22:41.83 [DEBUG] Connecting to pantsd on port 40717
10:22:41.83 [DEBUG] Connecting to pantsd on port 40717 attempt 1/3
10:22:41.84 [DEBUG] Connected to pantsd
(these are all subsequent commands with no changes between them other than the arguments passed)
I also notice this:
Copy code
10:22:49.31 [DEBUG] /home/coder/.cache/pants/lmdb_store/immutable/files -> /tmp hardlinkable: false
After this last change, time is down to
Copy code
Usage: utils.pex [OPTIONS] COMMAND [ARGS]...

  Utility commands for working with Pants build system.

Options:
  --help  Show this message and exit.

Commands:
  env    Generate PYTHONPATH environment variables from Pants roots.
  list   List targets in the repository.
  roots  Show the pants build roots.
10:38:18.08 [DEBUG] Completed: interactive_process
10:38:18.08 [DEBUG] Completed: `run` goal
10:38:18.08 [DEBUG] computed 1 nodes in 1.757824 seconds. there are 6857 total nodes.

real    0m7.784s
user    0m4.754s
sys     0m0.710s
and things look a little snappier. Now I think this is the time for pex running. The actual build is sub 2s
Copy code
10:38:18.08 [DEBUG] computed 1 nodes in 1.757824 seconds. there are 6857 total nodes.
Thank you ! Although I would still appreciate some help on why pantsd is restarting frequently
h
time
won’t make pantsd restart but 
-ldebug
will (since it affects the daemon’s own log levels)
Pantsd can restart if it isn’t allocated enough memory, for example
BTW even that 1.75s seems slow to me for a no-op build, but given all the virtualization layers, and the effect on the filesystem, I can see how that could happen
👀 1
s
How can I detect the reason for pantsd restarting? My team also said they see it a lot Perhaps not enough paths ignored on pants_ignore?
h
That could be, or not enough memory. Have you looked in 
.pants.d/workdir/pants.log
?
s
according to claude: 1. SIGTERM errors with Tokio runtime panics I count about 12 instances of the SIGTERM + Tokio panic error sequence in the logs. These typically follow this pattern:
Copy code
Signal 15 (SIGTERM) was raised. Exiting with failure.
[WARN] Executor was not shut down explicitly.
[ERROR] panic at 'Cannot drop a runtime in a context where blocking is not allowed...
[ERROR] panic at 'A Tokio 1.x context was found, but it is being shutdown.'
These errors appear to be distributed fairly evenly throughout the log timespan, averaging roughly once every 30-40 minutes of operation. 2. File watcher shutdowns I count approximately 45 file watcher shutdown warnings in the logs. These appear as:
Copy code
[WARN] File watcher exiting with: The watcher was shut down.
These often occur in clusters (2-3 warnings together) and are particularly frequent after service failures or when the pantsd daemon is restarting. They seem to happen roughly every 10-15 minutes on average but become more concentrated during periods of high activity or after configuration changes. 3. Service failures There are about 10 distinct scheduler service failures in the logs, appearing as:
Copy code
[ERROR] service failure for <pants.pantsd.service.scheduler_service.SchedulerService object at 0x...>
These seem to occur less frequently than the file watcher issues but often precede them. They're distributed throughout the log timeline, appearing approximately once per hour of operation.
b
(It's not helping with the specific issues here, but I also see hard-to-explain pantsd restarts that'd be nice to optimise. I've filed https://github.com/pantsbuild/pants/issues/22224 about potentially surfacing more diagnostics/explanations to aid debugging.)
❤️ 1
21 Views
Open in Slack
PreviousNext
Powered by