classification
Title: test_thread should clean threads after each test
Type: Stage: resolved
Components: Tests Versions: Python 3.7, Python 3.6, Python 3.5, Python 2.7
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: Nosy List: grzgrzgrz3, serhiy.storchaka, vstinner
Priority: normal Keywords:

Created on 2017-05-12 22:35 by vstinner, last changed 2017-05-17 21:49 by vstinner. This issue is now closed.

Pull Requests
URL Status Linked Edit
PR 1583 merged grzgrzgrz3, 2017-05-14 23:57
PR 1592 merged vstinner, 2017-05-15 15:30
PR 1622 merged vstinner, 2017-05-16 23:43
PR 1623 merged vstinner, 2017-05-16 23:44
PR 1634 merged vstinner, 2017-05-17 18:41
PR 1636 merged vstinner, 2017-05-17 19:00
PR 1637 merged vstinner, 2017-05-17 19:01
Messages (13)
msg293586 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-05-12 22:35
http://buildbot.python.org/all/builders/AMD64%20Debian%20root%202.7/builds/154/steps/test/logs/stdio

0:04:59 [312/402/1] test_thread failed
Traceback (most recent call last):
  File "/root/buildarea/2.7.angelico-debian-amd64/build/Lib/test/test_thread.py", line 133, in task
    raise SyntaxError
SyntaxError: None
test test_thread failed -- Traceback (most recent call last):
  File "/root/buildarea/2.7.angelico-debian-amd64/build/Lib/test/test_thread.py", line 150, in test_save_exception_state_on_error
    self.assertIn("Traceback", stderr.getvalue())
AssertionError: 'Traceback' not found in 'Unhandled exception in thread started by <function task at 0x7f06c77ab1b0>\n'
msg293643 - (view) Author: Serhiy Storchaka (serhiy.storchaka) * (Python committer) Date: 2017-05-14 09:56
I just encountered with this failure. It is random, I can reproduce it only when run test_thread repeatedly in parallel with running other tests (maybe needed high load factor).

$ ./python -m test -uall -F test_thread test_thread test_thread test_thread 
Run tests sequentially
0:00:00 [  1] test_thread
0:00:00 [  2] test_thread
Traceback (most recent call last):
  File "/home/serhiy/py/cpython2.7/Lib/test/test_thread.py", line 133, in task
    raise SyntaxError
SyntaxError: None
test test_thread failed -- Traceback (most recent call last):
  File "/home/serhiy/py/cpython2.7/Lib/test/test_thread.py", line 150, in test_save_exception_state_on_error
    self.assertIn("Traceback", stderr.getvalue())
AssertionError: 'Traceback' not found in 'Unhandled exception in thread started by <function task at 0xb6a89ee4>\n'

1 test OK.
1 test failed:
    test_thread

Total duration: 432 ms
Tests result: FAILURE
[50664 refs]
msg293661 - (view) Author: Grzegorz Grzywacz (grzgrzgrz3) * Date: 2017-05-14 23:57
Problem is with test test_thread.ThreadRunningTests.test_save_exception_state_on_error when other tests leave threads runnig. 

test_save_exception_state_on_error relay on thread._get_count(), if this value decrease test assume thread is finished with is not always correct (other threads finish - started by different test).

Fix is to make sure each test wait for all threads to finsh.
msg293678 - (view) Author: Serhiy Storchaka (serhiy.storchaka) * (Python committer) Date: 2017-05-15 06:04
The solution in PR 1583 looks unsafe to me. If some threads hang the loop `while self.thread_count != thread._count()` will never finished. If some dangling threads created in other tests or by regrtest itself are finished during running the test_thread test, that loop will never finished too.
msg293713 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-05-15 15:19
Using 5 terminals to run 5 tests in parallel.

I'm unable to reproduce the bug if I only run the test alone:

   ./python -m test -uall -F -m test_save_exception_state_on_error test_thread

But I'm able to reproduce the bug if I run the full test_thread.py:

   ./python -m test -uall -F test_thread

So I'm now more confident that grzgrzgrz3's patch can fix the issue. test_thread uses the low-level thread.start_new_thread() function to spawn threads, but pthread_join() is not used to wait for the thread exit. So multiple test_thread tests can "leak" threads which can have random effect on following tests.
msg293718 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-05-15 15:55
New changeset 79ef7f8e88a4972c4aecf95cfc5cd934f1861e08 by Victor Stinner in branch 'master':
bpo-30357: test_thread now uses threading_cleanup() (#1592)
https://github.com/python/cpython/commit/79ef7f8e88a4972c4aecf95cfc5cd934f1861e08
msg293724 - (view) Author: Grzegorz Grzywacz (grzgrzgrz3) * Date: 2017-05-15 17:01
I think this do not solve this issue yet. There is still posibillity that different tests/testrunners spawn threads and 'fool' testcase. I think we should not relay on `thread._count` value where it's possible. 

For master branch `thread._set_sentinel()` can be used. For 2.7 i don't know simple solution.

I would like to know your opinion it is worth changing?
msg293731 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-05-15 19:00
There is still posibillity that different tests/testrunners spawn threads
and 'fool' testcase.

If you run multiple test files in parallel, each test runner process runs a
single test at the same time: test methods are run sequentially to prevent
side effects.
msg293732 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-05-15 19:01
New changeset 6924ed55c9807d69757e03bbe1caeec1104efacb by Victor Stinner (grzgrzgrz3) in branch '2.7':
bpo-30357 each test in test_thread waits until all spawned threads finish (#1583)
https://github.com/python/cpython/commit/6924ed55c9807d69757e03bbe1caeec1104efacb
msg293825 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-05-17 00:14
Backported to 3.5 (aeb644714d37fb974e3acdf7daef031461e1283f) and 3.6 (6b5b85aecf4db796a05582202a6c875b36eae516).

I now close the issue, I consider that the change should fix the randomly failing test. If the failure comes back, I will reopen the issue.

Thank you very much Grzegorz Grzywacz for your first contribution!
msg293876 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-05-17 18:58
New changeset f8d05b3a24e745ab4a974b891ac1389e2f11ce4d by Victor Stinner in branch 'master':
bpo-30387: Fix warning in test_threading (#1634)
https://github.com/python/cpython/commit/f8d05b3a24e745ab4a974b891ac1389e2f11ce4d
msg293891 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-05-17 21:49
New changeset 44944b602af23712d7119801183cdc6e202e4f76 by Victor Stinner in branch '3.6':
bpo-30387: Fix warning in test_threading (#1634) (#1636)
https://github.com/python/cpython/commit/44944b602af23712d7119801183cdc6e202e4f76
msg293893 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2017-05-17 21:49
New changeset f5633e02433a81a6d0f14fc1c3294e752f4ac1a3 by Victor Stinner in branch '3.5':
bpo-30387: Fix warning in test_threading (#1634) (#1637)
https://github.com/python/cpython/commit/f5633e02433a81a6d0f14fc1c3294e752f4ac1a3
History
Date User Action Args
2017-05-17 21:49:45vstinnersetmessages: + msg293893
2017-05-17 21:49:41vstinnersetmessages: + msg293891
2017-05-17 19:01:18vstinnersetpull_requests: + pull_request1730
2017-05-17 19:00:37vstinnersetpull_requests: + pull_request1728
2017-05-17 18:58:52vstinnersetmessages: + msg293876
2017-05-17 18:41:33vstinnersetpull_requests: + pull_request1725
2017-05-17 00:14:25vstinnersetstatus: open -> closed
versions: + Python 3.5, Python 3.6, Python 3.7
messages: + msg293825

resolution: fixed
stage: resolved
2017-05-17 00:13:03vstinnersetpull_requests: + pull_request1712
2017-05-17 00:12:40vstinnersetpull_requests: - pull_request1712
2017-05-17 00:12:28vstinnersetpull_requests: + pull_request1712
2017-05-17 00:10:03vstinnersetpull_requests: - pull_request1712
2017-05-16 23:45:56vstinnersettitle: test_thread.test_save_exception_state_on_error(): Unhandled exception in thread: AMD64 Debian root 2.7 -> test_thread should clean threads after each test
2017-05-16 23:44:42vstinnersetpull_requests: + pull_request1712
2017-05-16 23:43:30vstinnersetpull_requests: + pull_request1711
2017-05-15 19:01:09vstinnersetmessages: + msg293732
2017-05-15 19:00:02vstinnersetmessages: + msg293731
2017-05-15 17:01:27grzgrzgrz3setmessages: + msg293724
2017-05-15 15:55:34vstinnersetmessages: + msg293718
2017-05-15 15:30:23vstinnersetpull_requests: + pull_request1686
2017-05-15 15:19:17vstinnersetmessages: + msg293713
2017-05-15 06:04:34serhiy.storchakasetmessages: + msg293678
2017-05-14 23:57:36grzgrzgrz3setnosy: + grzgrzgrz3
messages: + msg293661
2017-05-14 23:57:24grzgrzgrz3setpull_requests: + pull_request1676
2017-05-14 09:56:15serhiy.storchakasetnosy: + serhiy.storchaka
messages: + msg293643
2017-05-12 22:35:04vstinnercreate