Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

replace pkg_resources with importlib_metadata and packaging #5790

Merged
merged 2 commits into from
Nov 8, 2023

Conversation

oliver-sanders
Copy link
Member

@oliver-sanders oliver-sanders commented Oct 25, 2023

  • Closes Replace pkg_resources #5775
  • Replace the pkg_resources library (deprecated) with newer alternatives.
  • This resolves an efficiency issue due to the high import time of pkg_resources. This import time hits every single Cylc command including cylc message.

Test Import Time

The pkg_resources library can take a glacial age to import. To see this for yourself and test the difference try this:

# test.py

# the imports required to call the cylc message script
from cylc.flow.scripts import cylc
from cylc.flow.scripts import message
$ python -X importtime test.py 2> import.log
$ pip install tuna
$ tuna import.log

Results:

Before

Screenshot from 2023-10-25 13-58-25

After

Screenshot from 2023-10-25 13-58-36

Test CLI Time

To measure the impact of this change on end-to-end performance, I used this diff to turn off the actual work of cylc message:

diff --git a/cylc/flow/task_message.py b/cylc/flow/task_message.py
index 3ea753e73..e4b96f5bf 100644
--- a/cylc/flow/task_message.py
+++ b/cylc/flow/task_message.py
@@ -81,6 +81,7 @@ def record_messages(workflow: str, job_id: str, messages: List[list]) -> None:
         job_id: Job identifier "CYCLE/TASK_NAME/SUBMIT_NUM".
         messages: List of messages "[[severity, message], ...]".
     """
+    return
     # Record the event time, in case the message is delayed in some way.
     event_time = get_current_time_string(
         override_use_utc=(os.getenv('CYLC_UTC') == 'True'))

Note, without this diff, execution times vary wildly due to IO.

Results (average of 5 calls):

  • Before: 0.832s
  • After: 0.516s

So a ~0.3 second difference, which is good, but less of a saving than the ~1s indicated by python -X importtime.

I don't understand the disparity between the two, but at least the number is heading in the right direction.

Check List

  • I have read CONTRIBUTING.md and added my name as a Code Contributor.
  • Contains logically grouped changes (else tidy your branch by rebase).
  • Does not contain off-topic changes (use other PRs for other changes).
  • Applied any dependency changes to both setup.cfg (and conda-environment.yml if present).
  • Tests are included (or explain why tests are not needed).
  • CHANGES.md entry included if this is a change that can affect users
  • Cylc-Doc pull request opened if required at cylc/cylc-doc/pull/XXXX.
  • If this is a bug fix, PR should be raised against the relevant ?.?.x branch.

@oliver-sanders oliver-sanders added this to the cylc-8.3.0 milestone Oct 25, 2023
@oliver-sanders oliver-sanders self-assigned this Oct 25, 2023
@oliver-sanders oliver-sanders marked this pull request as ready for review October 25, 2023 13:43
@oliver-sanders oliver-sanders added the efficiency For notable efficiency improvements label Oct 26, 2023
@oliver-sanders oliver-sanders force-pushed the 5775 branch 3 times, most recently from c74f642 to 575fb13 Compare October 26, 2023 11:57
cylc/flow/scripts/cylc.py Outdated Show resolved Hide resolved
cylc/flow/__init__.py Outdated Show resolved Hide resolved
setup.cfg Show resolved Hide resolved
@hjoliver
Copy link
Member

This resolves an efficiency issue due to the high import time of pkg_resources. This import time hits every single Cylc command including cylc message.

Great. Cylc 8 command start-up time on our HPC can be pretty dire.

@oliver-sanders
Copy link
Member Author

oliver-sanders commented Oct 30, 2023

Great. Cylc 8 command start-up time on our HPC can be pretty dire.

This combined with #5770 could see a saving of up to 2s on cylc message calls which were taking way too long.

They now take ~1.5s for me (results and savings may differ wildly based on FS characteristics):

$ /usr/bin/time -v cylc message generic 1234 foo whatever 2>&1 | grep Elapsed
	Elapsed (wall clock) time (h:mm:ss or m:ss): 0:01.53
$ /usr/bin/time -v cylc message generic 1234 foo whatever 2>&1 | grep Elapsed
	Elapsed (wall clock) time (h:mm:ss or m:ss): 0:01.69
$ /usr/bin/time -v cylc message generic 1234 foo whatever 2>&1 | grep Elapsed
	Elapsed (wall clock) time (h:mm:ss or m:ss): 0:01.19

Of which ~0.6 seconds is the actual work of sending / writing messages. The remainder being overheads including the time taken to import the required code. So it should be possible to bring this number down further.

I think the main low-hanging fruit is in splitting up overgrown modules to prevent CLI commands from importing more than they need to (e.g. #5369).

@MetRonnie
Copy link
Member

MetRonnie commented Oct 30, 2023

$ cylc help all
Traceback (most recent call last):
  File "~/.conda/envs/cylc8/bin/cylc", line 8, in <module>
    sys.exit(main())
  File "~/github/cylc-flow-8/cylc/flow/scripts/cylc.py", line 663, in main
    print_command_list()
  File "~/github/cylc-flow-8/cylc/flow/scripts/cylc.py", line 453, in print_command_list
    contents = [
  File "~/github/cylc-flow-8/cylc/flow/scripts/cylc.py", line 453, in <listcomp>
    contents = [
  File "~/github/cylc-flow-8/cylc/flow/scripts/cylc.py", line 420, in iter_commands
    module = __import__(entry_point.module_name, fromlist=[''])
AttributeError: 'EntryPoint' object has no attribute 'module_name'

image

@oliver-sanders
Copy link
Member Author

(fixed and added test)

@MetRonnie
Copy link
Member

MetRonnie commented Oct 30, 2023

IMO we should move the (GH Actions) linkcheck step into the lint workflow too

Copy link
Member

@MetRonnie MetRonnie left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

👍

@oliver-sanders
Copy link
Member Author

oliver-sanders commented Oct 30, 2023

(may need to fiddle the lint timeout, let's see what it does)

run: |
bandit -r --ini .bandit cylc/flow
pytest cylc/flow tests/unit
Copy link
Member

@MetRonnie MetRonnie Oct 30, 2023

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If you're consolidating these into one step, it would be good to set -q for quiet in PYTEST_ADDOPTS, to prevent us having to scroll thousands of log lines to get to the test failures. Note that when CI=true Pytest always outputs full diffs in assertion failures regardless of the verbosity option.

Also -l for displaying the value of locals in traceback might be handy.

Copy link
Member Author

@oliver-sanders oliver-sanders Oct 31, 2023

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't see combining these sections as a reason for reducing verbosity, better to have the required information than to hide it?

(It didn't really make sense to separate doc and unit tests they are all unit tests and splitting them just slows things down)

Copy link
Member

@MetRonnie MetRonnie Oct 31, 2023

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm talking about hiding these (4000!) lines without reducing the verbosity of failed assertion output

image

Copy link
Member Author

@oliver-sanders oliver-sanders Oct 31, 2023

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't really see a problem with this and seeing the test output is helpful for debugging timeouts. Unrelated either way.

@MetRonnie
Copy link
Member

MetRonnie commented Oct 31, 2023

_remote_background_indep_tcp failure looks genuine

====== /home/runner/cylc-run/_remote_background_indep_tcp/cylctb-20231031T104705Z-KzdI/f/broadcast/09-remote/log/job/19990101T0000Z/t1/01/job.err ======
Sending DEBUG MODE xtrace to job.xtrace
"cylc broadcast" requires "cylc-flow"

ModuleNotFoundError: No module named 'packaging'
Traceback (most recent call last):
  File "/cylc/cylc/flow/task_message.py", line 108, in send_messages
    pclient = get_client(workflow)
              ^^^^^^^^^^^^^^^^^^^^
  File "/cylc/cylc/flow/network/client_factory.py", line 63, in get_client
    return get_runtime_client(get_comms_method(), workflow, timeout=timeout)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/cylc/cylc/flow/network/client_factory.py", line 54, in get_runtime_client
    from cylc.flow.network.client import (  # type: ignore[assignment]
  File "/cylc/cylc/flow/network/client.py", line 45, in <module>
    from cylc.flow.network.server import PB_METHOD_MAP
  File "/cylc/cylc/flow/network/server.py", line 31, in <module>
    from cylc.flow.network.graphql import (
  File "/cylc/cylc/flow/network/graphql.py", line 42, in <module>
    from cylc.flow.network.schema import NODE_MAP, get_type_str
  File "/cylc/cylc/flow/network/schema.py", line 41, in <module>
    from cylc.flow.broadcast_mgr import ALL_CYCLE_POINTS_STRS, addict
  File "/cylc/cylc/flow/broadcast_mgr.py", line 30, in <module>
    from cylc.flow.cfgspec.workflow import SPEC
  File "/cylc/cylc/flow/cfgspec/workflow.py", line 26, in <module>
    from cylc.flow.cfgspec.globalcfg import (
  File "/cylc/cylc/flow/cfgspec/globalcfg.py", line 25, in <module>
    from packaging.version import parse as parse_version, Version
ModuleNotFoundError: No module named 'packaging'
2023-10-31T10:47:15Z CRITICAL - failed/ERR

* Closes cylc#5775
* Replace the pkg_resources library (deprecated) with newer alternatives.
* This resolves an efficiency issue due to the high import time of
  pkg_resources. This import time hits every single Cylc command
  including `cylc message`.
@oliver-sanders
Copy link
Member Author

I had missed packaging off of the conda file, added it now, should pass.

@oliver-sanders oliver-sanders requested review from hjoliver and wxtim and removed request for hjoliver November 1, 2023 10:19
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
dependencies efficiency For notable efficiency improvements
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Replace pkg_resources
4 participants