Poll for updates only in start command

[danielhollas]

There is a noticeable lag when launching aiidalab-launch. On my machine the plain invocation takes about 200ms. I thought that this is a Python's fault, but then I noticed that we also curl on every invocation!

https://github.com/aiidalab/aiidalab-launch/blob/621f4cea3263bcd144055af6199d52302bafed18/aiidalab_launch/__main__.py#L105

For simple invocations that seems to take almost half the time (and perhaps even more in python 3.11, which supposedly should improve startup times).

I propose to only poll for updates when running the start command since

1. this command takes a long time anyway
2. start command is the command of this packages, so it's not like users would miss on updates.

If there's an agreement on this I am happy to submit a PR. Thanks!

[csadorf]

Hi, thank you for the suggestion and the analysis!

While we run the request on each invocation, it actually only performs a network request once an hour, because all requests are cached: https://github.com/aiidalab/aiidalab-launch/blob/621f4cea3263bcd144055af6199d52302bafed18/aiidalab_launch/util.py#L28-L34

This means that in theory, the first use of aiidalab-launch in a session, would be slightly delayed (although by maximal 0.1 seconds), but every subsequent invocation should only be limited by the filesystem cache.

Did you profile the code? If yes, how? Can you confirm that completely disabling the request noticeably accelerates the launch time?

[danielhollas]

Thanks, that's interesting! I did not do a very thorough profiling, a simply used time python -m aiidalab_launch and then commented out the get_latest_version call. If I remember correctly I saw differences upon multiple invocations, but I'll do a more thorough analysis to make sure. I am interested to see how fast the cache lookup is.

[danielhollas]

Just some quick timings using hyperfine.

$ conda install -c conda-forge hyperfine
$ hyperfine aiidalab-launch
Benchmark 1: aiidalab-launch
  Time (mean ± σ):     227.2 ms ±  40.7 ms    [User: 198.1 ms, System: 23.2 ms]
  Range (min … max):   202.3 ms … 341.0 ms    10 runs

  Warning: The first benchmarking run for this command was significantly slower than the rest (341.0 ms). This could be caused by (filesystem) caches that were not filled until after the first run. You should consider using the '--warmup' option to fill those caches before the actual benchmark. Alternatively, use the '--prepare' option to clear the caches before each timing run.
# Second invocation
$ hyperfine aiidalab-launch
Benchmark 1: aiidalab-launch
  Time (mean ± σ):     211.3 ms ±  14.8 ms    [User: 192.5 ms, System: 19.0 ms]
  Range (min … max):   187.9 ms … 230.6 ms    12 runs

So the cache definitely works and saves around 120 ms!

Invocation from the repo.

$ hyperfine "-m aiidalab_launch"
enchmark 1: python -m aiidalab_launch
  Time (mean ± σ):     426.0 ms ± 104.0 ms    [User: 351.9 ms, System: 59.7 ms]
  Range (min … max):   355.1 ms … 717.1 ms    10 runs

  Warning: The first benchmarking run for this command was significantly slower than the rest (717.1 ms). This could be caused by (filesystem) caches that were not filled until after the first run. You should consider using the '--warmup' option to fill those caches before the actual benchmark. Alternatively, use the '--prepare' option to clear the caches before each timing run.
$ hyperfine "-m aiidalab_launch"
Benchmark 1: python -m aiidalab_launch
  Time (mean ± σ):     387.9 ms ±  25.2 ms    [User: 343.6 ms, System: 47.3 ms]
  Range (min … max):   361.0 ms … 421.8 ms    10 runs

And now results with get_latest_version commented out.

  Time (mean ± σ):     381.1 ms ±  34.2 ms    [User: 332.8 ms, System: 50.5 ms]
  Range (min … max):   347.4 ms … 442.0 ms    10 runs

TL;DR: The difference does not seem significant. I am not sure what I saw yesterday, sorry for false alarm. :flushed: I'll do a bit more profiling tomorrow and close this.

[danielhollas]

Just to close this off, here's part of the output from cProfile with Python 3.10.5

$ python3 -m cProfile -s cumtime -m aiidalab_launch
         484704 function calls (467861 primitive calls) in 0.444 seconds

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
       66    0.002    0.000    1.602    0.024 __init__.py:1(<module>)
    537/1    0.002    0.000    0.444    0.444 {built-in method builtins.exec}
        1    0.000    0.000    0.444    0.444 <string>:1(<module>)
        1    0.000    0.000    0.444    0.444 runpy.py:199(run_module)
        1    0.000    0.000    0.443    0.443 runpy.py:63(_run_code)
        1    0.000    0.000    0.443    0.443 __main__.py:1(<module>)
   620/10    0.003    0.000    0.441    0.044 <frozen importlib._bootstrap>:1022(_find_and_load)
   619/10    0.002    0.000    0.441    0.044 <frozen importlib._bootstrap>:987(_find_and_load_unlocked)
   578/11    0.003    0.000    0.440    0.040 <frozen importlib._bootstrap>:664(_load_unlocked)
   521/11    0.001    0.000    0.439    0.040 <frozen importlib._bootstrap_external>:877(exec_module)
   703/11    0.001    0.000    0.438    0.040 <frozen importlib._bootstrap>:233(_call_with_frames_removed)
        3    0.000    0.000    0.314    0.105 client.py:1(<module>)
   136/54    0.000    0.000    0.281    0.005 {built-in method builtins.__import__}
  363/216    0.001    0.000    0.252    0.001 <frozen importlib._bootstrap>:1053(_handle_fromlist)
  613/451    0.005    0.000    0.218    0.000 <frozen importlib._bootstrap>:921(_find_spec)
        8    0.000    0.000    0.190    0.024 utils.py:1(<module>)
        2    0.000    0.000    0.180    0.090 auth.py:1(<module>)
  615/476    0.001    0.000    0.172    0.000 __init__.py:89(find_spec)
        1    0.000    0.000    0.172    0.172 store.py:1(<module>)
      2/1    0.000    0.000    0.171    0.171 __init__.py:99(spec_for_distutils)
      7/2    0.000    0.000    0.171    0.086 __init__.py:108(import_module)
      8/2    0.000    0.000    0.171    0.086 <frozen importlib._bootstrap>:1038(_gcd_import)
        9    0.000    0.000    0.138    0.015 version.py:1(<module>)
      442    0.002    0.000    0.094    0.000 re.py:288(_compile)
      176    0.000    0.000    0.093    0.001 re.py:249(compile)
      163    0.001    0.000    0.091    0.001 sre_compile.py:783(compile)
1443/1414    0.019    0.000    0.079    0.000 {built-in method builtins.__build_class__}
        5    0.000    0.000    0.076    0.015 config.py:1(<module>)
        1    0.000    0.000    0.075    0.075 application_state.py:1(<module>)
        3    0.000    0.000    0.068    0.023 util.py:1(<module>)
      522    0.004    0.000    0.068    0.000 <frozen importlib._bootstrap_external>:950(get_code)
        1    0.000    0.000    0.068    0.068 profile.py:1(<module>)
  578/546    0.001    0.000    0.061    0.000 <frozen importlib._bootstrap>:564(module_from_spec)
      163    0.001    0.000    0.055    0.000 sre_parse.py:944(parse)
  703/163    0.002    0.000    0.054    0.000 sre_parse.py:436(_parse_sub)
  994/181    0.020    0.000    0.053    0.000 sre_parse.py:494(_parse)
        1    0.000    0.000    0.051    0.051 requirements.py:1(<module>)
        2    0.000    0.000    0.050    0.025 base.py:1(<module>)
        6    0.000    0.000    0.050    0.008 exceptions.py:1(<module>)
        2    0.000    0.000    0.042    0.021 __init__.py:3233(_call_aside)
        1    0.000    0.000    0.042    0.042 __init__.py:3259(_initialize_master_working_set)
       12    0.000    0.000    0.039    0.003 __init__.py:609(add_entry)
        9    0.000    0.000    0.039    0.004 __init__.py:51(create_module)
        9    0.000    0.000    0.039    0.004 __init__.py:29(load_module)
      166    0.000    0.000    0.037    0.000 __init__.py:2065(find_on_path)
        6    0.000    0.000    0.037    0.006 core.py:1(<module>)
      608    0.001    0.000    0.037    0.000 <frozen importlib._bootstrap_external>:1431(find_spec)
      608    0.002    0.000    0.036    0.000 <frozen importlib._bootstrap_external>:1399(_get_spec)
      522    0.001    0.000    0.036    0.000 <frozen importlib._bootstrap_external>:670(_compile_bytecode)
        1    0.000    0.000    0.035    0.035 connectionpool.py:1(<module>)
      163    0.000    0.000    0.035    0.000 sre_compile.py:622(_code)
      522    0.033    0.000    0.033    0.000 {built-in method marshal.loads}
        2    0.000    0.000    0.032    0.016 connection.py:1(<module>)
        1    0.000    0.000    0.031    0.031 base_events.py:1(<module>)