Measurements of ChimeraX startup-time

[goddard@…]

The following bug report has been submitted:
Platform:        macOS-10.15.7-x86_64-i386-64bit
ChimeraX Version: 1.2.dev202103162155 (2021-03-16 21:55:33 UTC)
Description
Testing how fast ChimeraX starts on this Mac laptop.
Here are some results.

All tests are with splash screen turned off in preferences.

I use time.time() to record times, with the start time recorded at the first line of ChimeraX_main.py (so python has already started and is not included), and the end time when the first exposeEvent() call on the graphics window is made.  I am not sure this perfectly captures the time to when the GUI is fully drawn, but it looks close.

Typical ChimeraX start: 1.35 seconds.

In about 10 tries maybe 1 or 2 will randomly take about 2.1 seconds and the rest around 1.33-1.4

After "sudo purge" to clear the disk cache: 2.8 seconds.

With no tools at startup (Log, Model Panel, Command Line, Toolbar not autostarted) and file history commented out in code:  0.95 seconds with one in 10 starts taking up to 2 seconds.

Just disabling file history and all usual panels shown: 1.04 seconds
So it looks like file history adds about 0.3 seconds, probably from reading the 100 thumbnail images.

Just not auto-starting toolbar with other panels and file history shown: 1.33 seconds
So toolbar has negligible effect.

Just not auto-starting log panel: 1.34 seconds
So log has negligible effect on startup time.

Just not auto-starting model panel: 1.34 seconds
No effect.

Just not auto-starting command-line: 1.35 seeconds
No effect

Log:
UCSF ChimeraX version: 1.2.dev202103162155 (2021-03-16)  
© 2016-2020 Regents of the University of California. All rights reserved.  
How to cite UCSF ChimeraX  




OpenGL version: 4.1 INTEL-14.7.8
OpenGL renderer: Intel(R) UHD Graphics 630
OpenGL vendor: Intel Inc.Hardware:

    Hardware Overview:

      Model Name: MacBook Pro
      Model Identifier: MacBookPro15,3
      Processor Name: 8-Core Intel Core i9
      Processor Speed: 2.4 GHz
      Number of Processors: 1
      Total Number of Cores: 8
      L2 Cache (per Core): 256 KB
      L3 Cache: 16 MB
      Hyper-Threading Technology: Enabled
      Memory: 32 GB
      Boot ROM Version: 1037.147.4.0.0 (iBridge: 17.16.16610.0.0,0)

Software:

    System Software Overview:

      System Version: macOS 10.15.7 (19H2)
      Kernel Version: Darwin 19.6.0
      Time since boot: 92 days 17:44

Graphics/Displays:

    Intel UHD Graphics 630:

      Chipset Model: Intel UHD Graphics 630
      Type: GPU
      Bus: Built-In
      VRAM (Dynamic, Max): 1536 MB
      Vendor: Intel
      Device ID: 0x3e9b
      Revision ID: 0x0002
      Automatic Graphics Switching: Supported
      gMux Version: 5.0.0
      Metal: Supported, feature set macOS GPUFamily2 v1
      Displays:
        Color LCD:
          Display Type: Built-In Retina LCD
          Resolution: 2880 x 1800 Retina
          Framebuffer Depth: 24-Bit Color (ARGB8888)
          Main Display: Yes
          Mirror: Off
          Online: Yes
          Automatically Adjust Brightness: No
          Connection Type: Internal

    Radeon Pro Vega 20:

      Chipset Model: Radeon Pro Vega 20
      Type: GPU
      Bus: PCIe
      PCIe Lane Width: x8
      VRAM (Total): 4 GB
      Vendor: AMD (0x1002)
      Device ID: 0x69af
      Revision ID: 0x00c0
      ROM Revision: 113-D2060I-087
      VBIOS Version: 113-D20601MA0T-016
      Option ROM Version: 113-D20601MA0T-016
      EFI Driver Version: 01.01.087
      Automatic Graphics Switching: Supported
      gMux Version: 5.0.0
      Metal: Supported, feature set macOS GPUFamily2 v1

Locale: ('en_US', 'UTF-8')
PyQt5 5.15.2, Qt 5.15.2
Installed Packages:
    alabaster: 0.7.12
    appdirs: 1.4.4
    appnope: 0.1.2
    Babel: 2.9.0
    backcall: 0.2.0
    biopython: 1.78
    blockdiag: 2.0.1
    certifi: 2020.12.5
    cftime: 1.4.1
    chardet: 3.0.4
    ChimeraX-AddCharge: 1.0
    ChimeraX-AddH: 2.1.4
    ChimeraX-AlignmentAlgorithms: 2.0
    ChimeraX-AlignmentHdrs: 3.2
    ChimeraX-AlignmentMatrices: 2.0
    ChimeraX-Alignments: 2.1
    ChimeraX-AmberInfo: 1.0
    ChimeraX-Arrays: 1.0
    ChimeraX-Atomic: 1.11.2
    ChimeraX-AtomicLibrary: 2.0
    ChimeraX-AtomSearch: 2.0
    ChimeraX-AtomSearchLibrary: 1.0
    ChimeraX-AxesPlanes: 2.0
    ChimeraX-BasicActions: 1.1
    ChimeraX-BILD: 1.0
    ChimeraX-BlastProtein: 1.1
    ChimeraX-BondRot: 2.0
    ChimeraX-BugReporter: 1.0
    ChimeraX-BuildStructure: 2.5
    ChimeraX-Bumps: 1.0
    ChimeraX-BundleBuilder: 1.1
    ChimeraX-ButtonPanel: 1.0
    ChimeraX-CageBuilder: 1.0
    ChimeraX-CellPack: 1.0
    ChimeraX-Centroids: 1.1
    ChimeraX-ChemGroup: 2.0
    ChimeraX-Clashes: 2.1
    ChimeraX-ColorActions: 1.0
    ChimeraX-ColorGlobe: 1.0
    ChimeraX-ColorKey: 1.1
    ChimeraX-CommandLine: 1.1.3
    ChimeraX-ConnectStructure: 2.0
    ChimeraX-Contacts: 1.0
    ChimeraX-Core: 1.2.dev202103162155
    ChimeraX-CoreFormats: 1.0
    ChimeraX-coulombic: 1.0.3
    ChimeraX-Crosslinks: 1.0
    ChimeraX-Crystal: 1.0
    ChimeraX-CrystalContacts: 1.0
    ChimeraX-DataFormats: 1.1
    ChimeraX-Dicom: 1.0
    ChimeraX-DistMonitor: 1.1
    ChimeraX-DistUI: 1.0
    ChimeraX-Dssp: 2.0
    ChimeraX-EMDB-SFF: 1.0
    ChimeraX-ExperimentalCommands: 1.0
    ChimeraX-FileHistory: 1.0
    ChimeraX-FunctionKey: 1.0
    ChimeraX-Geometry: 1.1
    ChimeraX-gltf: 1.0
    ChimeraX-Graphics: 1.0
    ChimeraX-Hbonds: 2.1
    ChimeraX-Help: 1.1
    ChimeraX-HKCage: 1.3
    ChimeraX-IHM: 1.0
    ChimeraX-ImageFormats: 1.1
    ChimeraX-IMOD: 1.0
    ChimeraX-IO: 1.0.1
    ChimeraX-Label: 1.0
    ChimeraX-ListInfo: 1.1
    ChimeraX-Log: 1.1.1
    ChimeraX-LookingGlass: 1.1
    ChimeraX-Maestro: 1.8.1
    ChimeraX-Map: 1.0.2
    ChimeraX-MapData: 2.0
    ChimeraX-MapEraser: 1.0
    ChimeraX-MapFilter: 2.0
    ChimeraX-MapFit: 2.0
    ChimeraX-MapSeries: 2.0
    ChimeraX-Markers: 1.0
    ChimeraX-Mask: 1.0
    ChimeraX-MatchMaker: 1.1
    ChimeraX-MDcrds: 2.2
    ChimeraX-MedicalToolbar: 1.0.1
    ChimeraX-Meeting: 1.0
    ChimeraX-MLP: 1.1
    ChimeraX-mmCIF: 2.2
    ChimeraX-MMTF: 2.0
    ChimeraX-Modeller: 1.0
    ChimeraX-ModelPanel: 1.0.1
    ChimeraX-ModelSeries: 1.0
    ChimeraX-Mol2: 2.0
    ChimeraX-Morph: 1.0
    ChimeraX-MouseModes: 1.1
    ChimeraX-Movie: 1.0
    ChimeraX-Neuron: 1.0
    ChimeraX-Nucleotides: 2.0
    ChimeraX-OpenCommand: 1.5
    ChimeraX-PDB: 2.3
    ChimeraX-PDBBio: 1.0
    ChimeraX-PDBLibrary: 1.0
    ChimeraX-PDBMatrices: 1.0
    ChimeraX-PickBlobs: 1.0
    ChimeraX-Positions: 1.0
    ChimeraX-PresetMgr: 1.0.1
    ChimeraX-PubChem: 2.0.1
    ChimeraX-ReadPbonds: 1.0
    ChimeraX-Registration: 1.1
    ChimeraX-RemoteControl: 1.0
    ChimeraX-ResidueFit: 1.0
    ChimeraX-RestServer: 1.1
    ChimeraX-RNALayout: 1.0
    ChimeraX-RotamerLibMgr: 2.0
    ChimeraX-RotamerLibsDunbrack: 2.0
    ChimeraX-RotamerLibsDynameomics: 2.0
    ChimeraX-RotamerLibsRichardson: 2.0
    ChimeraX-SaveCommand: 1.4
    ChimeraX-SchemeMgr: 1.0
    ChimeraX-SDF: 2.0
    ChimeraX-Segger: 1.0
    ChimeraX-Segment: 1.0
    ChimeraX-SeqView: 2.3
    ChimeraX-Shape: 1.0.1
    ChimeraX-Shell: 1.0
    ChimeraX-Shortcuts: 1.0
    ChimeraX-ShowAttr: 1.0
    ChimeraX-ShowSequences: 1.0
    ChimeraX-SideView: 1.0
    ChimeraX-Smiles: 2.0.1
    ChimeraX-SmoothLines: 1.0
    ChimeraX-SpaceNavigator: 1.0
    ChimeraX-StdCommands: 1.3
    ChimeraX-STL: 1.0
    ChimeraX-Storm: 1.0
    ChimeraX-Struts: 1.0
    ChimeraX-Surface: 1.0
    ChimeraX-SwapAA: 2.0
    ChimeraX-SwapRes: 2.1
    ChimeraX-TapeMeasure: 1.0
    ChimeraX-Test: 1.0
    ChimeraX-Toolbar: 1.0.1
    ChimeraX-ToolshedUtils: 1.1
    ChimeraX-Tug: 1.0
    ChimeraX-UI: 1.7
    ChimeraX-uniprot: 2.1
    ChimeraX-UnitCell: 1.0
    ChimeraX-ViewDockX: 1.0
    ChimeraX-Vive: 1.1
    ChimeraX-VolumeMenu: 1.0
    ChimeraX-VTK: 1.0
    ChimeraX-WavefrontOBJ: 1.0
    ChimeraX-WebCam: 1.0
    ChimeraX-WebServices: 1.0
    ChimeraX-Zone: 1.0
    colorama: 0.4.3
    comtypes: 1.1.7
    cxservices: 1.0
    cycler: 0.10.0
    Cython: 0.29.21
    decorator: 4.4.2
    distlib: 0.3.1
    docutils: 0.16
    filelock: 3.0.12
    funcparserlib: 0.3.6
    grako: 3.16.5
    h5py: 2.10.0
    html2text: 2020.1.16
    idna: 2.10
    ihm: 0.17
    imagecodecs: 2020.5.30
    imagesize: 1.2.0
    ipykernel: 5.3.4
    ipython: 7.18.1
    ipython-genutils: 0.2.0
    jedi: 0.17.2
    Jinja2: 2.11.2
    jupyter-client: 6.1.7
    jupyter-core: 4.7.1
    kiwisolver: 1.3.1
    line-profiler: 2.1.2
    lxml: 4.6.2
    lz4: 3.1.0
    MarkupSafe: 1.1.1
    matplotlib: 3.3.2
    MolecularDynamicsViewer: 1.1
    msgpack: 1.0.0
    netCDF4: 1.5.4
    networkx: 2.5
    numexpr: 2.7.3
    numpy: 1.19.2
    numpydoc: 1.1.0
    openvr: 1.14.1501
    packaging: 20.9
    ParmEd: 3.2.0
    parso: 0.7.1
    pexpect: 4.8.0
    pickleshare: 0.7.5
    Pillow: 7.2.0
    pip: 21.0.1
    pkginfo: 1.5.0.1
    prompt-toolkit: 3.0.16
    psutil: 5.7.2
    ptyprocess: 0.7.0
    pycollada: 0.7.1
    pydicom: 2.0.0
    Pygments: 2.7.1
    PyOpenGL: 3.1.5
    PyOpenGL-accelerate: 3.1.5
    pyparsing: 2.4.7
    PyQt5: 5.15.2
    PyQt5-sip: 12.8.1
    PyQtWebEngine: 5.15.2
    python-dateutil: 2.8.1
    pytz: 2021.1
    pyzmq: 22.0.3
    qtconsole: 4.7.7
    QtPy: 1.9.0
    RandomWords: 0.3.0
    requests: 2.24.0
    scipy: 1.5.2
    Send2Trash: 1.5.0
    setuptools: 50.3.2
    sfftk-rw: 0.6.7.dev1
    six: 1.15.0
    snowballstemmer: 2.1.0
    sortedcontainers: 2.2.2
    Sphinx: 3.2.1
    sphinxcontrib-applehelp: 1.0.2
    sphinxcontrib-blockdiag: 2.0.0
    sphinxcontrib-devhelp: 1.0.2
    sphinxcontrib-htmlhelp: 1.0.3
    sphinxcontrib-jsmath: 1.0.1
    sphinxcontrib-qthelp: 1.0.3
    sphinxcontrib-serializinghtml: 1.1.4
    suds-jurko: 0.6
    tables: 3.6.1
    tifffile: 2020.9.3
    tinyarray: 1.2.3
    tornado: 6.1
    traitlets: 5.0.5
    urllib3: 1.25.11
    wcwidth: 0.2.5
    webcolors: 1.11.1
    wheel: 0.36.0
    wheel-filename: 1.2.0

[Tom Goddard]

Summarizing results on 2019 Mac laptop with no splash screen:

ChimeraX startup: 1.35 seconds
After disk cache purge: 2.8 seconds
Without file history: 1.04 seconds
With no auto-start of toolbar, model panel, log, command-line, file-history: 0.95 seconds

The normal startup time feels quite fast, similar to starting Safari or Mac Mail which take ~1 second. Adding the splash screen just creates an visual flicker, a fractional second team image flash.

[Tom Goddard]

Startup timing for 2018 Windows 10 laptop, MSI GS65 8RF, SSD drive.

With splash screen, 5 tries: 2.35 seconds
No splash screen, 5 tries: 2.00 seconds
After reboot: 7.53 seconds

Although the 7.5 seconds was a bit of a wait it felt sadly normal for a Windows fist time app start.

[Tom Goddard]

Linux, Ubuntu 20.04, ChimeraX daily
Intel NUC 5i5RYK, 2015 low-power 15 Watt (Intel i5-5250U CPU), with SSD

Startup with splash: 1.40 seconds
Startup no splash: 1.65 seconds
After reboot: 2.34 seconds

Strangely startup with splash screen is faster(!) than without.
I think that is an artifact of the way the timing is done -- without
splash screen the timing is reported in the log while with splash
screen it is reported to the shell, suggesting that the expose
event on the graphics is happening before the Log is ready without
splash screen. The times very closely match the visual appearance
of the window though.

[Tom Goddard]

The previous timing results on Mac, Linux, and Windows all have ChimeraX starting within 2 seconds, even on a slow 2015 Linux system (15 Watt Intel NUC).

These are the slowest 3 of my 5 home development machines that are from 2 to 6 years old. The other two are iMac and Windows desktops. All 5 of these machines have only solid state drives, no spinning drives. That is an important factor in the fast startup after reboot.

I suspect the majority of our users are on laptops so also are using SSD drives.

[pett]

Attaching the three timings after a cold reboot on my 2015 iMac. The non-indented times are cumulative from the start of the init() routine in ChimeraX_main.py. Indented lines are calls being made into subroutines, again cumulative from the start of the subroutine.

[pett]

timings after reboot on 2015 iMac

[pett]

timings after reboot on 2015 iMac

[pett]

timings after reboot on 2015 iMac

[Tom Goddard]

I guess your ChimeraX is installed on a spinning disk drive, not a solid state drive, on your 2015 iMac.

[pett]

APPLE SSD AP0032H

[Tom Goddard]

Supposedly that Apple drive is a "fusion" drive with a 24 GB SSD (yes just 24 gigabytes!) that holds the operating system and a 1 Tbyte spinning drive that holds applications and data, described here

​https://www.ifixit.com/Answers/View/663118/Upgrading+Fusion+Drive+to+SSD,+With+added+RAM+-+How+and+What+Parts

You report 7 - 9 second cold start times.

My 2017 iMac (iMac18,3, macOS 11.2.1) with 1 TB SSD (APPLE SSD SM1024L) and no spinning drive takes 10.3 seconds ChimeraX cold start, and after that 1.41 seconds to start, then after "sudo purge" to purge the disk cache took 3.27 seconds to start. With the very slow 10.3 seconds to start the splash screen did not appear for the first 8 seconds. I wonder if this cold start is spending lots of time loading generic macOS system stuff. Surprisingly Safari took 5 seconds to draw its UI after a cold-start although the blank window appeared in about 1 second. Emacs which is very lightweight by modern standards took 7 seconds to cold-start and then less than 0.5 seconds to start a second time. I rebooted again and tried ChimeraX, cold start 10.12 seconds, splash screen did not appear for first 8 seconds.

So it appears macOS (Big Sur in my tests) has horrible cold-start times compared to Linux (2.34 seconds) and even worse than Windows (7.53 seconds). I have not tried the cold-start on my laptop with macOS Catalina (I shut that machine down only every few months). I believe typical ChimeraX use involves tens to hundreds of ChimeraX starts for each single cold-start (after reboot). So no splash screen still the best route.

[pett]

If you reboot, you have to use the Activity Monitor app to ensure that a bunch of login-related processes (check for software updates, etc.) have finished.  I got noticably slower times before I figured out that I needed to check that.

--Eric

[goddard@…]

My second 10 second ChimeraX cold-start timing on the iMac was after starting Safari, Mac Mail, and Emacs and the machine had been up 3 minutes, so it didn't seem likely that system startup tasks were skewing the figure -- especially since it exactly matched my first try.  Could be macOS Big Sur is even worse that macOS Catalina in cold start times.  I wonder if the 8 second delay in the splash screen appearing is macOS doing some security check on each app as it starts after a restart.  But I am not curious enough to pursue it further.  I learned my lesson!  Don't restart a Mac.