Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Signals sometimes get lost #26

Open
pbrady opened this issue Sep 16, 2014 · 12 comments · Fixed by #27
Open

Signals sometimes get lost #26

pbrady opened this issue Sep 16, 2014 · 12 comments · Fixed by #27

Comments

@pbrady
Copy link
Owner

pbrady commented Sep 16, 2014

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 =======
@certik
Copy link

certik commented Sep 16, 2014

Interesting. How can they get lost?

@pbrady
Copy link
Owner Author

pbrady commented Sep 16, 2014

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.

@asmeurer
Copy link

Signals mess with C library functions. See for instance joerick/pyinstrument#16 (comment) (I don't know of a better resource for this now).

@pbrady
Copy link
Owner Author

pbrady commented Sep 16, 2014

@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.

@pbrady pbrady mentioned this issue Sep 17, 2014
Merged
@pbrady pbrady mentioned this issue Sep 17, 2014
Merged
@pbrady pbrady reopened this Sep 24, 2014
@pbrady
Copy link
Owner Author

pbrady commented Sep 25, 2014

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

@certik
Copy link

certik commented Sep 25, 2014

Exactly I think that the gmpy module might be swallowing signals just like yours did.

@certik
Copy link

certik commented Sep 25, 2014

Actually, that particular failure doesn't use gmpy. Hm.

@pbrady
Copy link
Owner Author

pbrady commented Sep 25, 2014

I'm tempted to just blame travis. I wonder if others have this issue with signals and travis?

@asmeurer
Copy link

I don't know about signals, but Travis does seem to have issues with timeouts sometimes, because the virtual machines can be slow.

@pbrady
Copy link
Owner Author

pbrady commented Sep 25, 2014

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

@asmeurer
Copy link

Oh that has definitely been happening long before we used fastcache. I at some point disabled the slow tests because of it.

@pbrady
Copy link
Owner Author

pbrady commented Sep 25, 2014

Ah. I'll probably try to do some more involve testing on my local machine then and just ignore whatever happens on travis.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Add checks for Errors to propagate signals pbrady/fastcache
3 participants
@certik @asmeurer @pbrady