<p dir="auto">I was investigating a weird crash that I had in a software that uses SciPy and links to libsndfile.</p>
<p dir="auto">The backtrace looks like this:</p>
<div class="snippet-clipboard-content notranslate position-relative overflow-auto" data-snippet-clipboard-copy-content="#0  0x00007fffe281936f in sf_error () from /usr/lib/libsndfile.so.1
#1  0x00007fffda890db6 in sf_error_check_fpe (func_name=0x7fffda99a2e5 &quot;expit&quot;) at scipy/special/sf_error.c:152"><pre class="notranslate"><code class="notranslate">#0  0x00007fffe281936f in sf_error () from /usr/lib/libsndfile.so.1
#1  0x00007fffda890db6 in sf_error_check_fpe (func_name=0x7fffda99a2e5 "expit") at scipy/special/sf_error.c:152
</code></pre></div>
<p dir="auto">I couldn't see what was wrong for a good hour but the problem is evident: there are two <code class="notranslate">sf_error</code> functions being loaded at the same time:</p>
<div class="snippet-clipboard-content notranslate position-relative overflow-auto" data-snippet-clipboard-copy-content="https://github.com/scipy/scipy/blob/master/scipy/special/sf_error.c#L52"><pre class="notranslate"><code class="notranslate">https://github.com/scipy/scipy/blob/master/scipy/special/sf_error.c#L52
</code></pre></div>
<p dir="auto">and</p>
<div class="snippet-clipboard-content notranslate position-relative overflow-auto" data-snippet-clipboard-copy-content="https://github.com/erikd/libsndfile/blob/fa1d42fdddcee203c7b0348324f9e657a9eb9c5a/src/sndfile.c#L494"><pre class="notranslate"><code class="notranslate">https://github.com/erikd/libsndfile/blob/fa1d42fdddcee203c7b0348324f9e657a9eb9c5a/src/sndfile.c#L494
</code></pre></div>
<p dir="auto">obviously, <code class="notranslate">sf_error_check_fpe</code> calls an unexpected <code class="notranslate">sf_error</code> with a wildly different ABI which leads to such crashes. What would be easy ways to prevent this ?</p>
<p dir="auto">This is primarily intended as a concise report of some Azure CI behavior to <a class="user-mention notranslate" data-hovercard-type="user" data-hovercard-url="/users/chrispat/hovercard" data-octo-click="hovercard-link-click" data-octo-dimensions="link_type:self" href="https://github.com/chrispat">@chrispat</a> and <a class="user-mention notranslate" data-hovercard-type="user" data-hovercard-url="/users/vtbassmatt/hovercard" data-octo-click="hovercard-link-click" data-octo-dimensions="link_type:self" href="https://github.com/vtbassmatt">@vtbassmatt</a>.</p>
<p dir="auto">In short, it seems that when I run effectively identical branches in the main SciPy repo vs. in my fork of the repo (with effectively identical target master branches), the timings for running our test suite are vastly different. Could it be that there's a priority algorithm directing the jobs in the heavily-used repo to different hardware than the repo that is almost never used?</p>
<p dir="auto">Here's some summary data comparing the two scenarios:</p>
<ul dir="auto">
<li>PR on my fork where 32-bit Windows job finishes in 41 minutes, 46 seconds: <a class="issue-link js-issue-link" data-error-text="Failed to load title" data-id="585152130" data-permission-text="Title is private" data-url="https://github.com/tylerjereddy/scipy/issues/29" data-hovercard-type="pull_request" data-hovercard-url="/tylerjereddy/scipy/pull/29/hovercard" href="https://github.com/tylerjereddy/scipy/pull/29">tylerjereddy#29</a></li>
<li>effectively identical PR to main repo where 32-bit Windows job finishes in 52 minutes, 19 seconds: <a class="issue-link js-issue-link" data-error-text="Failed to load title" data-id="584841895" data-permission-text="Title is private" data-url="https://github.com/scipy/scipy/issues/11694" data-hovercard-type="pull_request" data-hovercard-url="/scipy/scipy/pull/11694/hovercard" href="https://github.com/scipy/scipy/pull/11694">#11694</a></li>
</ul>
<p dir="auto">Since the Azure logs get purged every ~10 days or so, here is the raw text output for:</p>
<ul dir="auto">
<li>
<p dir="auto">my fork PR Windows 32-bit log:<br>
<a href="https://github.com/scipy/scipy/files/4363997/tyler_fork_log.txt">tyler_fork_log.txt</a></p>
</li>
<li>
<p dir="auto">main repo PR Windows 32-bit log:<br>
<a href="https://github.com/scipy/scipy/files/4363998/main_repo_log.txt">main_repo_log.txt</a></p>
</li>
</ul>
<p dir="auto">The big difference seems to be in the amount of time required to run the full test suite; the slowest 10 test durations suggest that there may be some heterogeneity in assigned hardware:</p>
<p dir="auto">Fork Windows 32-bit Win slowest 10 tests:</p>
<div class="snippet-clipboard-content notranslate position-relative overflow-auto" data-snippet-clipboard-copy-content="2020-03-21T15:30:10.7264434Z ========================== slowest 10 test durations ==========================
2020-03-21T15:30:10.7286762Z 138.80s call     stats/tests/test_distributions.py::TestGenInvGauss::test_rvs_p_zero
2020-03-21T15:30:10.7291924Z 88.02s call     optimize/tests/test__differential_evolution.py::TestDifferentialEvolutionSolver::test_L8
2020-03-21T15:30:10.7292840Z 72.08s call     sparse/linalg/eigen/lobpcg/tests/test_lobpcg.py::test_diagonal_data_types
2020-03-21T15:30:10.7294146Z 63.72s call     stats/tests/test_distributions.py::TestGenInvGauss::test_rvs_new_method
2020-03-21T15:30:10.7321531Z 49.00s call     stats/tests/test_distributions.py::TestGenInvGauss::test_rvs_without_mode_shift
2020-03-21T15:30:10.7322497Z 38.24s call     stats/tests/test_continuous_basic.py::test_cont_basic[kstwo-arg59]
2020-03-21T15:30:10.7323293Z 36.45s call     special/tests/test_mpmath.py::TestSystematic::test_legenp_complex_3
2020-03-21T15:30:10.7324067Z 35.74s call     special/tests/test_mpmath.py::TestSystematic::test_legenp_complex_2
2020-03-21T15:30:10.7324855Z 34.31s call     stats/tests/test_distributions.py::TestGenInvGauss::test_rvs_with_mode_shift
2020-03-21T15:30:10.7325610Z 33.23s call     stats/tests/test_stats.py::TestMGCStat::test_twosamp"><pre class="notranslate"><code class="notranslate">2020-03-21T15:30:10.7264434Z ========================== slowest 10 test durations ==========================
2020-03-21T15:30:10.7286762Z 138.80s call     stats/tests/test_distributions.py::TestGenInvGauss::test_rvs_p_zero
2020-03-21T15:30:10.7291924Z 88.02s call     optimize/tests/test__differential_evolution.py::TestDifferentialEvolutionSolver::test_L8
2020-03-21T15:30:10.7292840Z 72.08s call     sparse/linalg/eigen/lobpcg/tests/test_lobpcg.py::test_diagonal_data_types
2020-03-21T15:30:10.7294146Z 63.72s call     stats/tests/test_distributions.py::TestGenInvGauss::test_rvs_new_method
2020-03-21T15:30:10.7321531Z 49.00s call     stats/tests/test_distributions.py::TestGenInvGauss::test_rvs_without_mode_shift
2020-03-21T15:30:10.7322497Z 38.24s call     stats/tests/test_continuous_basic.py::test_cont_basic[kstwo-arg59]
2020-03-21T15:30:10.7323293Z 36.45s call     special/tests/test_mpmath.py::TestSystematic::test_legenp_complex_3
2020-03-21T15:30:10.7324067Z 35.74s call     special/tests/test_mpmath.py::TestSystematic::test_legenp_complex_2
2020-03-21T15:30:10.7324855Z 34.31s call     stats/tests/test_distributions.py::TestGenInvGauss::test_rvs_with_mode_shift
2020-03-21T15:30:10.7325610Z 33.23s call     stats/tests/test_stats.py::TestMGCStat::test_twosamp
</code></pre></div>
<p dir="auto">Main Repo 32-bit Win slowest 10 tests:</p>
<div class="snippet-clipboard-content notranslate position-relative overflow-auto" data-snippet-clipboard-copy-content="2020-03-21T15:35:21.7974905Z ========================== slowest 10 test durations ==========================
2020-03-21T15:35:21.7995869Z 176.72s call     stats/tests/test_distributions.py::TestGenInvGauss::test_rvs_p_zero
2020-03-21T15:35:21.7997603Z 125.06s call     sparse/linalg/tests/test_expm_multiply.py::TestExpmActionInterval::test_expm_multiply_interval_matrix
2020-03-21T15:35:21.7999866Z 112.96s call     sparse/linalg/eigen/lobpcg/tests/test_lobpcg.py::test_diagonal_data_types
2020-03-21T15:35:21.8001497Z 104.41s call     sparse/linalg/tests/test_matfuncs.py::TestExpM::test_pascal
2020-03-21T15:35:21.8002826Z 103.77s call     optimize/tests/test__differential_evolution.py::TestDifferentialEvolutionSolver::test_L8
2020-03-21T15:35:21.8004589Z 78.71s call     stats/tests/test_distributions.py::TestGenInvGauss::test_rvs_new_method
2020-03-21T15:35:21.8006064Z 69.11s call     sparse/linalg/tests/test_expm_multiply.py::TestExpmActionSimple::test_expm_multiply
2020-03-21T15:35:21.8008332Z 55.78s call     stats/tests/test_distributions.py::TestGenInvGauss::test_rvs_without_mode_shift
2020-03-21T15:35:21.8009880Z 47.74s call     stats/tests/test_continuous_basic.py::test_cont_basic[kstwo-arg59]
2020-03-21T15:35:21.8011662Z 45.46s call     stats/tests/test_stats.py::TestMGCStat::test_twosamp"><pre class="notranslate"><code class="notranslate">2020-03-21T15:35:21.7974905Z ========================== slowest 10 test durations ==========================
2020-03-21T15:35:21.7995869Z 176.72s call     stats/tests/test_distributions.py::TestGenInvGauss::test_rvs_p_zero
2020-03-21T15:35:21.7997603Z 125.06s call     sparse/linalg/tests/test_expm_multiply.py::TestExpmActionInterval::test_expm_multiply_interval_matrix
2020-03-21T15:35:21.7999866Z 112.96s call     sparse/linalg/eigen/lobpcg/tests/test_lobpcg.py::test_diagonal_data_types
2020-03-21T15:35:21.8001497Z 104.41s call     sparse/linalg/tests/test_matfuncs.py::TestExpM::test_pascal
2020-03-21T15:35:21.8002826Z 103.77s call     optimize/tests/test__differential_evolution.py::TestDifferentialEvolutionSolver::test_L8
2020-03-21T15:35:21.8004589Z 78.71s call     stats/tests/test_distributions.py::TestGenInvGauss::test_rvs_new_method
2020-03-21T15:35:21.8006064Z 69.11s call     sparse/linalg/tests/test_expm_multiply.py::TestExpmActionSimple::test_expm_multiply
2020-03-21T15:35:21.8008332Z 55.78s call     stats/tests/test_distributions.py::TestGenInvGauss::test_rvs_without_mode_shift
2020-03-21T15:35:21.8009880Z 47.74s call     stats/tests/test_continuous_basic.py::test_cont_basic[kstwo-arg59]
2020-03-21T15:35:21.8011662Z 45.46s call     stats/tests/test_stats.py::TestMGCStat::test_twosamp
</code></pre></div>