Hi,

This post is just to raise awareness.

Starting Sage-8.0 now takes **about 3s**  on the fastest possible disks
(below I'm using an nvme local SSD) with a warm cache.
With a cold cache on a slower disk (say something with only a few hundred
iops) it can take well over 30s.  This seems to even be a significant
regression compared to sage-7.6, though how much depends on your machine
(of course).

I remember writing a doctest in sage back in maybe 2010 that would only
pass if sage would startup on sage.math.washington.edu in less than 2s.
 Me, Robert Bradshaw, Volker and others have spent countless time over the
years trying to reduce or keep this startup time down in various ways.
However, all it really takes is one "import numpy" (or similar) in the
wrong place in any of the million lines of code of Sage, to add a full
second or more to the startup time for everybody.  It's sad when this
happens in code that most people will never actually use.

If anybody else finds this sad, I think Robert Bradshaw wrote "./sage
-startuptime".  If you try it on sage-8.0, you'll find the worst offenders
are:

    12.550    985.941          6  sage.all
    12.882     17.760          5  sage.schemes.elliptic_curves
    12.965     13.633        133  sage.categories.map
    13.273     25.204         90  sage.rings.ring
    13.299     13.425         35  sage.rings.finite_rings.integer_mod
    13.622     13.636          9  sage.structure.global_options
    15.155     15.227          2  sage.combinat.posets.hasse_diagram
    17.081     34.623          3  psutil
    19.495     22.573         11  sage.rings.qqbar
    20.169     54.545         18  sage.rings
    29.564     50.977         20  sage.libs.pynac.pynac

In particular pynac is horrible, and psutil (why is sage using that) is
pretty bad... hasse_diagram is pretty bad... and qqbar (which really
doesn't get used much right!) is taking a ton of time at startup...

Actual startup time...

Right after rebooting on a "super fast local nvme SSD":

root@kucalc-test-disk-ssd:/mnt/SageMath# time ./sage</dev/null
┌────────────────────────────────────────────────────────────────────┐
│ SageMath version 8.0, Release Date: 2017-07-21                     │
│ Type "notebook()" for the browser-based notebook interface.        │
│ Type "help()" for help.                                            │
└────────────────────────────────────────────────────────────────────┘
In [1]: Exiting Sage (CPU time 0m0.01s, Wall time 0m0.01s).

real    0m5.072s
user    0m2.752s
sys     0m0.404s

Do it again, now that cache is warm:

root@kucalc-test-disk-ssd:/mnt/SageMath# time ./sage </dev/null
┌────────────────────────────────────────────────────────────────────┐
│ SageMath version 8.0, Release Date: 2017-07-21                     │
│ Type "notebook()" for the browser-based notebook interface.        │
│ Type "help()" for help.                                            │
└────────────────────────────────────────────────────────────────────┘
In [1]: Exiting Sage (CPU time 0m0.01s, Wall time 0m0.01s).

real    0m3.051s
user    0m2.540s
sys     0m0.244s


Using a "really crappy" disk with a cold cache (53.5 seconds!):

/ext/sage/sage-dev$ time ./sage </dev/null
┌────────────────────────────────────────────────────────────────────┐
│ SageMath version 8.0.rc1, Release Date: 2017-07-05                 │
│ Enhanced for CoCalc.                                               │
└────────────────────────────────────────────────────────────────────┘
In [1]: Exiting Sage (CPU time 0m0.02s, Wall time 0m0.02s).
real    0m53.518s
user    0m4.072s
sys     0m3.164s
/ext/sage/sage-dev$

And now with warm cache it's back to 5.7s:

/ext/sage/sage-dev$ time ./sage </dev/null
┌────────────────────────────────────────────────────────────────────┐
│ SageMath version 8.0.rc1, Release Date: 2017-07-05                 │
│ Enhanced for CoCalc.                                               │
└────────────────────────────────────────────────────────────────────┘
In [1]: Exiting Sage (CPU time 0m0.01s, Wall time 0m0.06s).

real    0m5.704s
user    0m3.752s
sys     0m0.572s
/ext/sage/sage-dev$


One reason the filesystem matters so much is that Python does a LOT of
stats system calls when importing modules:

root@kucalc-test-disk-ssd:/mnt/SageMath# time strace ./sage </dev/null 2>&1
| grep stat |wc -l
37693

I have the impression startup time is not usually long due to actually
evaluating Python code...   I also don't think much actual data is
tranferred (i.g., the shear amount of MB of filesystem data needed to read
to start sage is pretty small -- on the order of 50MB at most.).

 -- William


-- 
-- William Stein

-- 
You received this message because you are subscribed to the Google Groups 
"sage-devel" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to sage-devel+unsubscr...@googlegroups.com.
To post to this group, send email to sage-devel@googlegroups.com.
Visit this group at https://groups.google.com/group/sage-devel.
For more options, visit https://groups.google.com/d/optout.

Reply via email to