tests timing out

[richardjgowers]

Travis has a 50 min timeout and it looks like our tests are getting very close to that and occaisionally timing out. It's very likely a 90/10 situation so rewriting a few tests can probably shave a few minutes off the average time.

[tylerjereddy]

Making the tests faster is probably the best solution as you say. pytest-test-groups could also be used to split up our suite into 2 groups (matrix entries) in CI if really needed. I just saw someone talking about that in another project because some platforms (like ARM64) can be quite slow to run big test suites.

[orbeckst]

There are some tests that seem to run an excessive time; everything that recently ran slower than 10s:

========================== slowest 50 test durations ===========================
91.97s call     MDAnalysisTests/analysis/test_dihedrals.py::TestRamachandran::test_ramachandran
91.51s call     MDAnalysisTests/analysis/test_dihedrals.py::TestRamachandran::test_protein_ends
91.39s call     MDAnalysisTests/analysis/test_dihedrals.py::TestRamachandran::test_ramachandran_single_frame
51.02s call     MDAnalysisTests/analysis/test_density.py::Test_density_from_Universe::test_notwithin
39.76s call     MDAnalysisTests/analysis/test_density.py::TestNotWithin::test_within
39.43s call     MDAnalysisTests/analysis/test_density.py::TestNotWithin::test_not_within
38.16s call     MDAnalysisTests/analysis/test_density.py::TestNotWithin::test_has_DeprecationWarning
37.19s call     MDAnalysisTests/analysis/test_hbonds.py::TestHydrogenBondAnalysisHeuristic::test_true_traj
37.14s call     MDAnalysisTests/analysis/test_hbonds.py::TestHydrogenBondAnalysisHeavyFail::test_true_traj
37.10s call     MDAnalysisTests/analysis/test_hbonds.py::TestHydrogenBondAnalysisHeavy::test_true_traj
37.06s call     MDAnalysisTests/analysis/test_hbonds.py::TestHydrogenBondAnalysisPBC::test_true_traj
36.93s call     MDAnalysisTests/analysis/test_hbonds.py::TestHydrogenBondAnalysis::test_true_traj
33.12s call     MDAnalysisTests/analysis/test_dihedrals.py::TestRamachandran::test_None_removal
19.29s call     MDAnalysisTests/visualization/test_streamlines.py::test_streamplot_2D
15.06s call     MDAnalysisTests/analysis/test_hole2.py::TestHoleAnalysis::test_context_manager
13.83s call     MDAnalysisTests/coordinates/test_pdb.py::test_conect_bonds_all
13.67s call     MDAnalysisTests/analysis/test_density.py::Test_density_from_Universe::test_update_selection
12.39s call     MDAnalysisTests/analysis/test_density.py::TestDensityAnalysis::test_run[dynamic]
10.07s call     MDAnalysisTests/coordinates/test_gro.py::TestGROLargeWriter::test_writer_large

The Ramachandran ones in particular worry me – this should not be slow as it's just dihedrals.

The ones in test_density will be removed eventually but it's also pretty bad that they take so long.

[lilyminium]

The Ramachandran ones in particular worry me – this should not be slow as it's just dihedrals.

For that particular suite of tests, there's quite a lot of them (3k+). phi_selection and psi_selection take up 48% and 52% of the time respectively. The actual code in run() and conclude are pretty negligible.

prun suggests that fnmatch is the expensive thing here; phi_selection and psi_selection find the atoms via select_atoms.

[richardjgowers]

I'm just looking into this now, I wouldn't have guessed that that's the bottleneck : /

[yuxuanzhuang]

It seems that residue.universe.select_atoms(sel_str) in phi_selection / psi_selection is bottlenecking it. I would suggest do something like this to prevent from selecting from the whole universe.

for res1, res2 in zip(u.select_atoms("protein").residues[0:-2], u.select_atoms("protein").residues[1:-1]):
    sel = res1.atoms.select_atoms('segid {} and name C'.format(res2.segment.segid)) + res2.atoms.select_atoms('name N', 'name CA', 'name C')

[lilyminium]

Sorry @richardjgowers, didn't see your comment earlier -- I hope I haven't duplicated your work.

@yuxuanzhuang thanks for the suggestion! That wouldn't quite produce the same behaviour as the current phi/psi_selection functions because it relies on the residues being consecutive, in the same segment, and not missing any gaps in the middle of the protein. Unfortunately, because segid and resid are both values provided by the file format, there's no guarantee that they make any real sense.

[IAlibay]

Going through old issues - closing this as tests now run somewhere between 10 to 16 mins on CI.

There's probably scope for further optimising some of our tests, but at this point cutting off coverage for some of our runners might be more effective in the short term (tests can be as low as 7 mins on gh CI when we don't need coverage).

Please do open a new issue if necessary.