https://pantsbuild.org/ logo
#general
Title
# general
b

breezy-window-26318

09/23/2022, 1:33 PM
Hi, I am facing with a very slow
run
goal completion time. Right now we have a python project with ~50 dependencies and 35-40k LOC. When I run
./pants --level=debug --pex-verbosity=9 run /path/to/folder:binary
it takes a whopping 70-80 secs to complete. And when I add a print statement to the entry file it takes the same time 70-80 seconds. I tried using
execution_mode=venv
and
pex.venv_use_symlinks=true
options but they didn’t help. Here is the timing details:
Copy code
pex: Building pex: 8413.4ms
pex:   Laying out PEX zipfile local_dists.pex: 0.1ms
pex:   Searching dependency cache: /Users/serhat/.cache/pants/named_caches/pex_root/unzipped_pexes/53b03e2e28c1a38ab2a682f3a8d615cd2ba49035/.deps: 0.0ms
pex:   Resolving distributions (...): 8325.8ms
pex:     Parsing lock third_party/requirements_macos_arm64.lock: 335.4ms
pex:     Resolving requirements from lock file third_party/requirements_macos_arm64.lock: 7974.6ms
pex:       Parsing requirements: 7.3ms
pex:       Resolving urls to fetch for 48 requirements from lock third_party/requirements_macos_arm64.lock: 113.1ms
pex:       Hashing pex: 161.1ms
pex:       Isolating pex: 0.1ms
pex:       Downloading 131 distributions to satisfy 48 requirements: 43.7ms
pex:       Categorizing 131 downloaded artifacts: 1.0ms
pex:       Building 27 artifacts and installing 393: 7641.5ms
pex:         Building distributions for:
...
pex:         Installing 131 distributions: 7594.7ms
pex: Vendoring attr from VendorSpec(key='attrs', requirement='git+<https://github.com/python-attrs/attrs@947bfb542104209a587280701d8cb389c813459d#egg=attrs>', rewrite=True, constrain=False, constraints=None) @ /Users/serhat/.cache/pants/named_caches/pex_root/installed_wheels/6a3c9545f9bc666f039874243789bf4ba5cc4fbde5a945eca40a651de360568b/pex-2.1.103-py2.py3-none-any.whl/pex/vendor/_vendored/attrs
pex: Vendoring packaging from VendorSpec(key='packaging', requirement='packaging==20.9', rewrite=True, constrain=True, constraints=('pyparsing<3',)) @ /Users/serhat/.cache/pants/named_caches/pex_root/installed_wheels/6a3c9545f9bc666f039874243789bf4ba5cc4fbde5a945eca40a651de360568b/pex-2.1.103-py2.py3-none-any.whl/pex/vendor/_vendored/packaging
pex: Vendoring pyparsing from VendorSpec(key='packaging', requirement='packaging==20.9', rewrite=True, constrain=True, constraints=('pyparsing<3',)) @ /Users/serhat/.cache/pants/named_caches/pex_root/installed_wheels/6a3c9545f9bc666f039874243789bf4ba5cc4fbde5a945eca40a651de360568b/pex-2.1.103-py2.py3-none-any.whl/pex/vendor/_vendored/packaging
pex: Vendoring pkg_resources from PreparedGit(key='setuptools', requirement='git+<https://github.com/pantsbuild/setuptools@3acb925dd708430aeaf197ea53ac8a752f7c1863#egg=setuptools>', rewrite=True, constrain=False, constraints=None) @ /Users/serhat/.cache/pants/named_caches/pex_root/installed_wheels/6a3c9545f9bc666f039874243789bf4ba5cc4fbde5a945eca40a651de360568b/pex-2.1.103-py2.py3-none-any.whl/pex/vendor/_vendored/setuptools
pex: Vendoring setuptools from PreparedGit(key='setuptools', requirement='git+<https://github.com/pantsbuild/setuptools@3acb925dd708430aeaf197ea53ac8a752f7c1863#egg=setuptools>', rewrite=True, constrain=False, constraints=None) @ /Users/serhat/.cache/pants/named_caches/pex_root/installed_wheels/6a3c9545f9bc666f039874243789bf4ba5cc4fbde5a945eca40a651de360568b/pex-2.1.103-py2.py3-none-any.whl/pex/vendor/_vendored/setuptools
pex: Vendoring wheel from VendorSpec(key='wheel', requirement='wheel==0.37.1', rewrite=False, constrain=True, constraints=None) @ /Users/serhat/.cache/pants/named_caches/pex_root/installed_wheels/6a3c9545f9bc666f039874243789bf4ba5cc4fbde5a945eca40a651de360568b/pex-2.1.103-py2.py3-none-any.whl/pex/vendor/_vendored/wheel
Saving PEX file to <http://src.python.app/app.pex|src.python.app/app.pex>
pex: Zipping PEX file.
pex: Zipping PEX file.: 53163.6ms
16:22:24.36 [DEBUG] Completed: pants.backend.python.util_rules.pex.build_pex
16:22:24.36 [DEBUG] Dependency @rule(pants.backend.python.util_rules.pex.create_pex()) of Some("@rule(pants.backend.python.goals.package_pex_binary.package_pex_binary(<http://src.python.app/app.pex|src.python.app/app.pex>))") changed.
16:22:24.36 [DEBUG] Completed: pants.backend.python.goals.package_pex_binary.package_pex_binary
16:22:24.36 [DEBUG] Dependency @rule(pants.backend.python.goals.package_pex_binary.package_pex_binary(<http://src.python.app/app.pex|src.python.app/app.pex>)) of Some("@rule(pants.backend.python.goals.run_pex_binary.create_pex_binary_run_request(<http://src.python.app/app.pex|src.python.app/app.pex>))") changed.
16:22:24.37 [DEBUG] Completed: pants.backend.python.goals.run_pex_binary.create_pex_binary_run_request
16:22:24.76 [DEBUG] Completed: setup_sandbox
...
16:22:37.42 [DEBUG] Completed: `run` goal
16:22:37.42 [DEBUG] computed 1 nodes in 78.639370 seconds. there are 12360 total nodes.
Is this normal? It’s my first time working and trying to adopt pants in our monorepo. We use bazel right now.
1
h

happy-kitchen-89482

09/23/2022, 1:50 PM
Hi! Is this happening every time you
./pants run
? Or just the first time for a given target?
b

breezy-window-26318

09/23/2022, 1:51 PM
It happens every time
h

happy-kitchen-89482

09/23/2022, 1:51 PM
Even if you make no changes at all?
E.g., if you run
./pants run /path/to/folder:binary
twice in a row with no changes?
b

breezy-window-26318

09/23/2022, 1:52 PM
No, if I make no changes it runs immediately
h

happy-kitchen-89482

09/23/2022, 1:53 PM
And which version of Pants is this?
b

breezy-window-26318

09/23/2022, 1:53 PM
2.14.0rc1
h

happy-kitchen-89482

09/23/2022, 1:54 PM
OK, so I think this is because
run
on a
pex_binary
target now has the behavior of “build the full pex and then run it” so it exactly emulates doing those two things separately.
But you can also
./pants run path/to/folder/binary.py
And that, I believe, doesn’t build a full pex but runs directly from your source tree
ccing @bitter-ability-32190 to confirm
And in that case no pex rebuilding happens when only first-party sources change
It looks like maybe your 3rdparty deps are large, so pex rebuilding is taking some time?
Are you using a lockfile? That pushes the resolve to lockfile generation time, and then pex rebuilding should be a lot faster.
So two things to try: 1) Using a lockfile, if you’re not already 2) Running the file, not the target
b

breezy-window-26318

09/23/2022, 1:59 PM
It worked immediately thank you!
I am using lockfile too
b

bitter-ability-32190

09/23/2022, 2:02 PM
I can pretty much guarantee the majority of the time is spent zipping the PEX. That's what I've seen. Benjy is right though, I'd just run the py file
b

breezy-window-26318

09/23/2022, 2:03 PM
Yes, thank you. I never thought about just running the py file. It’s old bazel habits 🙂
💯 1
b

bitter-ability-32190

09/23/2022, 2:03 PM
If you need to run the binary, I suggest using a different layout
No worries, it's a fairly new change 🙂
Also to confirm my suspicion:
Copy code
pex: Zipping PEX file.: 53163.6ms
b

breezy-window-26318

09/23/2022, 2:04 PM
🙂
h

happy-kitchen-89482

09/23/2022, 2:04 PM
@breezy-window-26318 If you
./pants package
that target, how big is the resulting .pex file?
b

breezy-window-26318

09/23/2022, 2:04 PM
Around 500mbs
h

happy-kitchen-89482

09/23/2022, 2:04 PM
OK, so it taking some time just to zip up makes sense
e

enough-analyst-54434

09/23/2022, 2:59 PM
It says on the tin ~50s to zip in the OP output. Have you tried
layout="packed"
b

bitter-ability-32190

09/23/2022, 4:09 PM
Oh by the way @breezy-window-26318 one cool thing about being able to run Python files now is you likely need very few
pex_binary
targets. Only for things you really want to package.
b

busy-vase-39202

09/23/2022, 4:15 PM
Since other people accustomed to Bazel may share these expectations, may I suggest adding more clarification to the docs about the significant perf difference between running the file vs the target?
b

breezy-window-26318

09/23/2022, 6:56 PM
Ah, thank you. This is great to know. I will try packed option too.
2 Views