fastcache
fastcache copied to clipboard
pbrady
Signals sometimes get lost
The timeout signal raised during the long running test_wester tests in sympy seem to get lost.
- Pure python cache - signal handled appropriately every time
$ bin/test sympy/core/tests/test_wester.py --slow --timeout 30 --rerun 10 -k test_W25
============================= test process starts ==============================
executable: /home/ptb/miniconda3/envs/py27/bin/python (2.7.8-final-0) [CPython]
architecture: 64-bit
cache: yes
ground types: python
random seed: 19896835
hash randomization: on (PYTHONHASHSEED=1541313885)
sympy/core/tests/test_wester.py[1] T [OK]
============ tests finished: 0 passed, 1 skipped, in 30.19 seconds =============
============================= test process starts ==============================
executable: /home/ptb/miniconda3/envs/py27/bin/python (2.7.8-final-0) [CPython]
architecture: 64-bit
cache: yes
ground types: python
random seed: 73556722
hash randomization: on (PYTHONHASHSEED=2050004862)
sympy/core/tests/test_wester.py[1] T [OK]
============ tests finished: 0 passed, 1 skipped, in 30.16 seconds =============
============================= test process starts ==============================
executable: /home/ptb/miniconda3/envs/py27/bin/python (2.7.8-final-0) [CPython]
architecture: 64-bit
cache: yes
ground types: python
random seed: 26462863
hash randomization: on (PYTHONHASHSEED=3857145256)
sympy/core/tests/test_wester.py[1] T [OK]
============ tests finished: 0 passed, 1 skipped, in 30.16 seconds =============
============================= test process starts ==============================
executable: /home/ptb/miniconda3/envs/py27/bin/python (2.7.8-final-0) [CPython]
architecture: 64-bit
cache: yes
ground types: python
random seed: 34275668
hash randomization: on (PYTHONHASHSEED=881433688)
sympy/core/tests/test_wester.py[1] T [OK]
============ tests finished: 0 passed, 1 skipped, in 30.18 seconds =============
============================= test process starts ==============================
executable: /home/ptb/miniconda3/envs/py27/bin/python (2.7.8-final-0) [CPython]
architecture: 64-bit
cache: yes
ground types: python
random seed: 96870713
hash randomization: on (PYTHONHASHSEED=2112371590)
sympy/core/tests/test_wester.py[1] T [OK]
============ tests finished: 0 passed, 1 skipped, in 30.16 seconds =============
============================= test process starts ==============================
executable: /home/ptb/miniconda3/envs/py27/bin/python (2.7.8-final-0) [CPython]
architecture: 64-bit
cache: yes
ground types: python
random seed: 79399543
hash randomization: on (PYTHONHASHSEED=3148928932)
sympy/core/tests/test_wester.py[1] T [OK]
============ tests finished: 0 passed, 1 skipped, in 30.16 seconds =============
============================= test process starts ==============================
executable: /home/ptb/miniconda3/envs/py27/bin/python (2.7.8-final-0) [CPython]
architecture: 64-bit
cache: yes
ground types: python
random seed: 79708067
hash randomization: on (PYTHONHASHSEED=1148676525)
sympy/core/tests/test_wester.py[1] T [OK]
============ tests finished: 0 passed, 1 skipped, in 30.16 seconds =============
============================= test process starts ==============================
executable: /home/ptb/miniconda3/envs/py27/bin/python (2.7.8-final-0) [CPython]
architecture: 64-bit
cache: yes
ground types: python
random seed: 82605636
hash randomization: on (PYTHONHASHSEED=87545409)
sympy/core/tests/test_wester.py[1] T [OK]
============ tests finished: 0 passed, 1 skipped, in 30.16 seconds =============
============================= test process starts ==============================
executable: /home/ptb/miniconda3/envs/py27/bin/python (2.7.8-final-0) [CPython]
architecture: 64-bit
cache: yes
ground types: python
random seed: 63111394
hash randomization: on (PYTHONHASHSEED=1889469761)
sympy/core/tests/test_wester.py[1] T [OK]
============ tests finished: 0 passed, 1 skipped, in 30.16 seconds =============
============================= test process starts ==============================
executable: /home/ptb/miniconda3/envs/py27/bin/python (2.7.8-final-0) [CPython]
architecture: 64-bit
cache: yes
ground types: python
random seed: 82749091
hash randomization: on (PYTHONHASHSEED=351423868)
sympy/core/tests/test_wester.py[1] T [OK]
============ tests finished: 0 passed, 1 skipped, in 30.16 seconds =============
============================= test process starts ==============================
executable: /home/ptb/miniconda3/envs/py27/bin/python (2.7.8-final-0) [CPython]
architecture: 64-bit
cache: yes
ground types: python
random seed: 63640978
hash randomization: on (PYTHONHASHSEED=531375902)
sympy/core/tests/test_wester.py[1] T [OK]
============ tests finished: 0 passed, 1 skipped, in 30.16 seconds =============
- fastcache with
timeout=180
test('sympy/core/tests/test_wester.py', verbose=True, slow=True, timeout=180, kw='test_W25', rerun=10)
============================= test process starts ==============================
executable: /home/ptb/miniconda3/bin/python3 (3.4.1-final-0) [CPython]
architecture: 64-bit
cache: yes
ground types: python
random seed: 26510469
hash randomization: on (PYTHONHASHSEED=2396247365)
sympy/core/tests/test_wester.py[1]
test_W25 T - Timeout [OK]
============ tests finished: 0 passed, 1 skipped, in 180.28 seconds ============
============================= test process starts ==============================
executable: /home/ptb/miniconda3/bin/python3 (3.4.1-final-0) [CPython]
architecture: 64-bit
cache: yes
ground types: python
random seed: 61102789
hash randomization: on (PYTHONHASHSEED=417119396)
sympy/core/tests/test_wester.py[1]
test_W25 T - Timeout [OK]
============ tests finished: 0 passed, 1 skipped, in 180.24 seconds ============
============================= test process starts ==============================
executable: /home/ptb/miniconda3/bin/python3 (3.4.1-final-0) [CPython]
architecture: 64-bit
cache: yes
ground types: python
random seed: 35622910
hash randomization: on (PYTHONHASHSEED=2146397325)
sympy/core/tests/test_wester.py[1]
test_W25 T - Timeout [OK]
============ tests finished: 0 passed, 1 skipped, in 180.24 seconds ============
============================= test process starts ==============================
executable: /home/ptb/miniconda3/bin/python3 (3.4.1-final-0) [CPython]
architecture: 64-bit
cache: yes
ground types: python
random seed: 43697130
hash randomization: on (PYTHONHASHSEED=1859372131)
sympy/core/tests/test_wester.py[1]
test_W25 T - Timeout [OK]
============ tests finished: 0 passed, 1 skipped, in 180.25 seconds ============
============================= test process starts ==============================
executable: /home/ptb/miniconda3/bin/python3 (3.4.1-final-0) [CPython]
architecture: 64-bit
cache: yes
ground types: python
random seed: 92941575
hash randomization: on (PYTHONHASHSEED=3865564759)
sympy/core/tests/test_wester.py[1]
test_W25 f [OK]
======= tests finished: 0 passed, 1 expected to fail, in 1044.78 seconds =======
- fastcache with
timeout = 30
bin/test sympy/core/tests/test_wester.py --slow --timeout 30 --rerun 10 -k test_W25
============================= test process starts ==============================
executable: /home/ptb/miniconda3/bin/python (3.4.1-final-0) [CPython]
architecture: 64-bit
cache: yes
ground types: python
random seed: 44345956
hash randomization: on (PYTHONHASHSEED=203139206)
sympy/core/tests/test_wester.py[1] T [OK]
============ tests finished: 0 passed, 1 skipped, in 30.24 seconds =============
============================= test process starts ==============================
executable: /home/ptb/miniconda3/bin/python (3.4.1-final-0) [CPython]
architecture: 64-bit
cache: yes
ground types: python
random seed: 90160511
hash randomization: on (PYTHONHASHSEED=3532862812)
sympy/core/tests/test_wester.py[1] T [OK]
============ tests finished: 0 passed, 1 skipped, in 30.24 seconds =============
============================= test process starts ==============================
executable: /home/ptb/miniconda3/bin/python (3.4.1-final-0) [CPython]
architecture: 64-bit
cache: yes
ground types: python
random seed: 59158191
hash randomization: on (PYTHONHASHSEED=3762354216)
sympy/core/tests/test_wester.py[1] T [OK]
============ tests finished: 0 passed, 1 skipped, in 30.25 seconds =============
============================= test process starts ==============================
executable: /home/ptb/miniconda3/bin/python (3.4.1-final-0) [CPython]
architecture: 64-bit
cache: yes
ground types: python
random seed: 71192828
hash randomization: on (PYTHONHASHSEED=561917225)
sympy/core/tests/test_wester.py[1] T [OK]
============ tests finished: 0 passed, 1 skipped, in 30.24 seconds =============
============================= test process starts ==============================
executable: /home/ptb/miniconda3/bin/python (3.4.1-final-0) [CPython]
architecture: 64-bit
cache: yes
ground types: python
random seed: 22436026
hash randomization: on (PYTHONHASHSEED=2964106396)
sympy/core/tests/test_wester.py[1] T [OK]
============ tests finished: 0 passed, 1 skipped, in 30.24 seconds =============
============================= test process starts ==============================
executable: /home/ptb/miniconda3/bin/python (3.4.1-final-0) [CPython]
architecture: 64-bit
cache: yes
ground types: python
random seed: 81004478
hash randomization: on (PYTHONHASHSEED=3399921698)
sympy/core/tests/test_wester.py[1] f [OK]
======= tests finished: 0 passed, 1 expected to fail, in 1423.16 seconds =======
No Idea. http://stackoverflow.com/questions/25874823/pyerr-checksignals-not-picking-up-signal.
Hopefully someone knows. The alternative will be to increase the splits and not use fastcache for the slow tests.
Signals mess with C library functions. See for instance https://github.com/joerick/pyinstrument/issues/16#issuecomment-47174190 (I don't know of a better resource for this now).
@certik and I talked it through and I think the problem was that I wasn't checking the return value for every call into the Python-C-API (i.e. I knew my argument was hashable so I didn't check the return value of PyDict_SetItem). However, these calls passed control back to the interpreter which would have caught the signal and turned it into an exception via the callback. Thus no call into the Python-C-api is safe! Tricky. I'm testing out patches at the moment.
Looks like there are still timeout errors even without fastcache https://travis-ci.org/sympy/sympy/jobs/36210280. Maybe this is actually fixed and travis doesn't do timeouts well
Exactly I think that the gmpy module might be swallowing signals just like yours did.
I'm tempted to just blame travis. I wonder if others have this issue with signals and travis?
I don't know about signals, but Travis does seem to have issues with timeouts sometimes, because the virtual machines can be slow.
But this particular timeout is the No output for 10 minutes kind when the slow tests have a default timeout of 180s. It could just be a fluke but it's something to watch. It looks like one can avoid using signals but it's tricky to get right http://eli.thegreenplace.net/2011/08/22/how-not-to-set-a-timeout-on-a-computation-in-python
Oh that has definitely been happening long before we used fastcache. I at some point disabled the slow tests because of it.
Ah. I'll probably try to do some more involve testing on my local machine then and just ignore whatever happens on travis.