nextstrain / augur

Pipeline components for real-time phylodynamic analysis
https://docs.nextstrain.org/projects/augur/
GNU Affero General Public License v3.0
268 stars 129 forks source link

Improve startup time #472

Open willingc opened 4 years ago

willingc commented 4 years ago

Context
Currently on MacOS 10.15.3, the CLI is slow to display after typing augur.

Description
Investigate if there is an optimization that can be made.

groutr commented 4 years ago

@willingc I'll dig into this.

jasongrout commented 4 years ago

Just curious, are you seeing it being slow on Linux too?

groutr commented 4 years ago

I guess the question is how slow is "slow"? Running my processor at 2.4Ghz, it takes 1.073s to run augur. How slow it is on Mac OS?

If my laptop processor is running with dynamic frequency scaling, the augur command can take between 1.5-2s.

EDIT: This is with Python 3.7, btw.

groutr commented 4 years ago

I notice that augur imports the entire library every time it is run or even imported. https://github.com/nextstrain/augur/blob/master/augur/__init__.py#L40

Ideally, all this code should live __main__.py. There is no need to be executing this in __init__.py

willingc commented 4 years ago

The specific start case that I was seeing was typing augur with no options after. It takes a long time on my Mac to present any information.

groutr commented 4 years ago

@willingc can you post the output of time <augur command>?

willingc commented 4 years ago

Hi @groutr,

Whelp in true software fashion it's not slow today. lol

Here's the output requested: augur 0.94s user 0.18s system 114% cpu 0.983 total

If you want feel free to close now.

jasongrout commented 4 years ago

As another data point, on macOS 2.4 GHz Intel Core i5: augur 1.27s user 0.23s system 106% cpu 1.415 total

groutr commented 4 years ago

Thanks @willingc and @jasongrout. I'm going to experiment with restructuring the cli to import things lazily.

groutr commented 4 years ago

Looks like the help pages are probably the worst case scenario. However, I would argue that if the help pages aren't fast, it gives the impression that the program itself is slow.

Fortunately, the help pages are easy to speed up. I was able to drop the time from >1s to about < .1s on my machine. The benefit of this reorganization is that we only import the module that is needed instead of all of them.

groutr commented 4 years ago

Example

(augur-dev) ❯ time python -m augur.__main__ version
augur 6.4.3
python -m augur.__main__ version  0.83s user 0.08s system 99% cpu 0.913 total
(augur-dev) ❯ time python -m augur.cli version
augur 6.4.3
python -m augur.cli version  0.05s user 0.00s system 98% cpu 0.048 total
corneliusroemer commented 3 years ago

I can confirm that the issue still exists. Using augur for the first time today and I was surprised at how unresponsive the CLI is. Very unusual for and potentially off-putting.

Really shouldn't be hard to fix for the common case of displaying help information.

Here's another data point

augur  1.32s user 0.38s system 109% cpu 1.548 total

with the following machine

Model Name: MacBook Pro
Model Identifier: MacBookPro15,1
Processor Name: 6-Core Intel Core i7
Processor Speed: 2.2 GHz
Memory: 16 GB
System Version: macOS 11.3.1 (20E241)