Issue39029
This issue tracker has been migrated to GitHub,
and is currently read-only.
For more information,
see the GitHub FAQs in the Python's Developer Guide.
Created on 2019-12-12 08:59 by xtreak, last changed 2022-04-11 14:59 by admin.
Messages (10) | |||
---|---|---|---|
msg358295 - (view) | Author: Karthikeyan Singaravelan (xtreak) * ![]() |
Date: 2019-12-12 08:59 | |
I can reproduce frequently the failure of test_clean on my Mac machine. It checks for removal of foo_path. It's removed by Maildir.clean that removes files based on the access time as below. The test also does similar thing with os.utime(foo_path, (time.time() - 129600 - 2, foo_stat.st_mtime)) but I guess the file is not really deleted in some cases. https://github.com/python/cpython/blob/7772b1af5ebc9d72d0cfc8332aea6b2143eafa27/Lib/mailbox.py#L482 def clean(self): """Delete old files in "tmp".""" now = time.time() for entry in os.listdir(os.path.join(self._path, 'tmp')): path = os.path.join(self._path, 'tmp', entry) if now - os.path.getatime(path) > 129600: # 60 * 60 * 36 os.remove(path) $ ./python.exe -Wall -m test -R 3:3 -j 4 test_mailbox -m test_clean 0:00:00 load avg: 2.12 Run tests in parallel using 4 child processes 0:00:00 load avg: 2.12 [1/1/1] test_mailbox failed beginning 6 repetitions 123456 .....test test_mailbox failed -- Traceback (most recent call last): File "/Users/kasingar/stuff/python/cpython/Lib/test/test_mailbox.py", line 737, in test_clean self.assertFalse(os.path.exists(foo_path)) AssertionError: True is not false == Tests result: FAILURE == 1 test failed: test_mailbox Total duration: 951 ms Tests result: FAILURE |
|||
msg358299 - (view) | Author: Serhiy Storchaka (serhiy.storchaka) * ![]() |
Date: 2019-12-12 10:30 | |
Should not parallel tests be ran in different directories? |
|||
msg359031 - (view) | Author: Karthikeyan Singaravelan (xtreak) * ![]() |
Date: 2019-12-30 10:37 | |
> Should not parallel tests be ran in different directories? yes, the test uses support.TESTFN which has the value of "{}_{}_tmp".format(TESTFN, os.getpid()) in the setUp [0] to create tempdir. Under parallel tests the pid value of TESTFN is initialised with a pid once and used always in the setup calls. So setup acts under parallel tests with same test folder. The tempdir can be dynamically generated but I guess this pattern to use support.TESTFN is common and there could be other flaky tests. # create tempdir at setup each time and clean it up. diff --git Lib/test/test_mailbox.py Lib/test/test_mailbox.py index 36a265390e..aa8ae9ae20 100644 --- Lib/test/test_mailbox.py +++ Lib/test/test_mailbox.py @@ -51,13 +51,15 @@ class TestMailbox(TestBase): _template = 'From: foo\n\n%s\n' def setUp(self): - self._path = support.TESTFN + self._tempdir = tempfile.TemporaryDirectory() + self._path = self._tempdir.name self._delete_recursively(self._path) self._box = self._factory(self._path) def tearDown(self): self._box.close() self._delete_recursively(self._path) + self._tempdir.cleanup() def test_add(self): # Add copies of a sample message [0] https://github.com/python/cpython/blob/88dce26da6bc4838092128d9a6f1c98bf48b7c90/Lib/test/test_mailbox.py#L54 |
|||
msg359661 - (view) | Author: STINNER Victor (vstinner) * ![]() |
Date: 2020-01-09 10:25 | |
> yes, the test uses support.TESTFN which has the value of "{}_{}_tmp".format(TESTFN, os.getpid()) in the setUp [0] to create tempdir. Under parallel tests the pid value of TESTFN is initialised with a pid once and used always in the setup calls. So setup acts under parallel tests with same test folder. The tempdir can be dynamically generated but I guess this pattern to use support.TESTFN is common and there could be other flaky tests. I don't understand. Let's say that test_mailbox and test_os are run in parallel, process 1 runs test_mailbox and process 2 runs test_os. TESTFN should be different in each process but globally unique. So I don't understand the difference between: - self._path = support.TESTFN and: + self._tempdir = tempfile.TemporaryDirectory() + self._path = self._tempdir.name Is it because the test currently doesn't remove self._path directory in some cases? You wrote "I guess the file is not really deleted in some cases." I think that this should be investigated first. |
|||
msg359662 - (view) | Author: Serhiy Storchaka (serhiy.storchaka) * ![]() |
Date: 2020-01-09 10:30 | |
If TESTFN is the same in different processes, there is something wrong in the code for running parallel tests. |
|||
msg359665 - (view) | Author: Karthikeyan Singaravelan (xtreak) * ![]() |
Date: 2020-01-09 10:49 | |
> You wrote "I guess the file is not really deleted in some cases." I think that this should be investigated first. Sorry, I wanted to mean that as the test deletes the file and goes on to assert it's not present the other test that runs in parallel creates the same file in setup code. Thus I wanted to imply that during assertion and parallel test's setup code the directory is again created. I tried printing os.getpid() and support.TESTFN values in the setup and they are the same for all the tests. ./python.exe -Wall -m test -R 4:4 -j 4 test_mailbox -m test_clean 0:00:00 load avg: 2.91 Run tests in parallel using 4 child processes 0:00:00 load avg: 2.91 [1/1/1] test_mailbox failed os.getpid() = 27901 support.TESTFN = '@test_27901_tmp' os.getpid() = 27901 support.TESTFN = '@test_27901_tmp' beginning 8 repetitions 12345678 .test test_mailbox failed -- Traceback (most recent call last): File "/Users/kasingar/stuff/python/cpython/Lib/test/test_mailbox.py", line 740, in test_clean self.assertFalse(os.path.exists(foo_path)) AssertionError: True is not false == Tests result: FAILURE == 1 test failed: test_mailbox Total duration: 789 ms Tests result: FAILURE |
|||
msg359666 - (view) | Author: STINNER Victor (vstinner) * ![]() |
Date: 2020-01-09 11:04 | |
./python.exe -Wall -m test -R 4:4 -j 4 test_mailbox -m test_clean With this command: test_mailbox is run exactly once. It's not run in parallel. But the same test is run 8 times. os.getpid() = 27901 support.TESTFN = '@test_27901_tmp' os.getpid() = 27901 support.TESTFN = '@test_27901_tmp' That sounds consistent: same pid means same TESTFN. |
|||
msg359667 - (view) | Author: STINNER Victor (vstinner) * ![]() |
Date: 2020-01-09 11:10 | |
I failed to reproduce the issue on my Fedora 31 laptop using 20 processes running on parallel (my CPU has 4 cores: 8 threads). vstinner@apu$ ./python -Wall -m test -R 3:3 -j 20 test_mailbox -m test_clean -F 0:00:00 load avg: 14.86 Run tests in parallel using 20 child processes (...) 0:01:12 load avg: 18.81 [321] test_mailbox passed beginning 6 repetitions 123456 ...... ^C Kill <TestWorkerProcess #1 running test=test_mailbox pid=82501 time=2.2 sec> process group Kill <TestWorkerProcess #2 running test=test_mailbox pid=82485 time=4.1 sec> process group Kill <TestWorkerProcess #3 running test=test_mailbox pid=82499 time=2.5 sec> process group Kill <TestWorkerProcess #4 running test=test_mailbox pid=82525 time=131 ms> process group Kill <TestWorkerProcess #5 running test=test_mailbox pid=82504 time=1.8 sec> process group Kill <TestWorkerProcess #6 running test=test_mailbox pid=82514 time=761 ms> process group Kill <TestWorkerProcess #7 running test=test_mailbox pid=82522 time=239 ms> process group Kill <TestWorkerProcess #8 running test=test_mailbox pid=82509 time=1.3 sec> process group Kill <TestWorkerProcess #9 running test=test_mailbox pid=82523 time=194 ms> process group Kill <TestWorkerProcess #10 running test=test_mailbox pid=82513 time=787 ms> process group Kill <TestWorkerProcess #11 running test=test_mailbox pid=82495 time=3.0 sec> process group Kill <TestWorkerProcess #12 running test=test_mailbox pid=82515 time=674 ms> process group Kill <TestWorkerProcess #13 running test=test_mailbox pid=82483 time=4.2 sec> process group Kill <TestWorkerProcess #14 running test=test_mailbox pid=82482 time=4.3 sec> process group Kill <TestWorkerProcess #15 running test=test_mailbox pid=82487 time=3.7 sec> process group Kill <TestWorkerProcess #16 running test=test_mailbox pid=82492 time=3.3 sec> process group Kill <TestWorkerProcess #17 running test=test_mailbox pid=82491 time=3.4 sec> process group Kill <TestWorkerProcess #18 running test=test_mailbox pid=82500 time=2.4 sec> process group Kill <TestWorkerProcess #19 running test=test_mailbox pid=82494 time=3.1 sec> process group Kill <TestWorkerProcess #20 running test=test_mailbox pid=82506 time=1.5 sec> process group == Tests result: INTERRUPTED == Test suite interrupted by signal SIGINT. 321 tests OK. Total duration: 1 min 12 sec Tests result: INTERRUPTED |
|||
msg359668 - (view) | Author: Karthikeyan Singaravelan (xtreak) * ![]() |
Date: 2020-01-09 11:18 | |
I am able to reproduce it on my Mac and as below the values of os.getpid() are the same with the command. I will try to get to a Linux box to see if I can reproduce this. I was always under the assumption that -j 4 runs tests in parallel as it even says in the message "run tests in parallel using n child processes" . Maybe I am stumbling upon a mac os specific issue or understanding something wrong about the regrtest framework. I am using Macbook pro with Mojave. ./python.exe -Wall -m test -R 3:3 -j 20 test_mailbox -m test_clean -F 0:00:00 load avg: 2.31 Run tests in parallel using 20 child processes 0:00:03 load avg: 2.85 [ 1/1] test_mailbox failed os.getpid() = 37760 support.TESTFN = '@test_37760_tmp' os.getpid() = 37760 support.TESTFN = '@test_37760_tmp' beginning 6 repetitions 123456 .test test_mailbox failed -- Traceback (most recent call last): File "/Users/kasingar/stuff/python/cpython/Lib/test/test_mailbox.py", line 743, in test_clean self.assertFalse(os.path.exists(foo_path)) AssertionError: True is not false Kill <TestWorkerProcess #2 running test=test_mailbox pid=37761 time=3.4 sec> process group Kill <TestWorkerProcess #3 running test=test_mailbox pid=37763 time=3.4 sec> process group Kill <TestWorkerProcess #4 running test=test_mailbox pid=37762 time=3.4 sec> process group Kill <TestWorkerProcess #5 running test=test_mailbox pid=37764 time=3.4 sec> process group Kill <TestWorkerProcess #6 running test=test_mailbox pid=37765 time=3.4 sec> process group Kill <TestWorkerProcess #7 running test=test_mailbox pid=37766 time=3.4 sec> process group Kill <TestWorkerProcess #8 running test=test_mailbox pid=37767 time=3.4 sec> process group Kill <TestWorkerProcess #9 running test=test_mailbox pid=37768 time=3.3 sec> process group Kill <TestWorkerProcess #10 running test=test_mailbox pid=37769 time=3.3 sec> process group Kill <TestWorkerProcess #11 running test=test_mailbox pid=37770 time=3.3 sec> process group Kill <TestWorkerProcess #12 running test=test_mailbox pid=37771 time=3.3 sec> process group Kill <TestWorkerProcess #13 running test=test_mailbox pid=37772 time=3.2 sec> process group Kill <TestWorkerProcess #14 running test=test_mailbox pid=37773 time=3.2 sec> process group Kill <TestWorkerProcess #15 running test=test_mailbox pid=37774 time=3.2 sec> process group Kill <TestWorkerProcess #16 running test=test_mailbox pid=37775 time=3.2 sec> process group Kill <TestWorkerProcess #17 running test=test_mailbox pid=37776 time=3.2 sec> process group Kill <TestWorkerProcess #18 running test=test_mailbox pid=37777 time=3.2 sec> process group Kill <TestWorkerProcess #19 running test=test_mailbox pid=37778 time=3.2 sec> process group Kill <TestWorkerProcess #20 running test=test_mailbox pid=37779 time=3.2 sec> process group == Tests result: FAILURE == 1 test failed: test_mailbox Total duration: 3.4 sec Tests result: FAILURE |
|||
msg359669 - (view) | Author: STINNER Victor (vstinner) * ![]() |
Date: 2020-01-09 11:21 | |
> I was always under the assumption that -j 4 runs tests in parallel If you run one test file, even with -j1000, only one test file will be run in parallel :-) To run the same file in parallel, you have to ask to run it more than once: "-j2 test_mailbox test_mailbox" or "-j2 test_mailbox -F" for example. -F runs the same tests in a loop until it fails. It's a convenient way to run the same test in parallel to detect race conditions ;-) |
History | |||
---|---|---|---|
Date | User | Action | Args |
2022-04-11 14:59:24 | admin | set | github: 83210 |
2020-01-09 11:21:28 | vstinner | set | messages: + msg359669 |
2020-01-09 11:18:14 | xtreak | set | messages: + msg359668 |
2020-01-09 11:10:56 | vstinner | set | messages: + msg359667 |
2020-01-09 11:04:07 | vstinner | set | messages: + msg359666 |
2020-01-09 10:49:37 | xtreak | set | messages: + msg359665 |
2020-01-09 10:30:03 | serhiy.storchaka | set | messages: + msg359662 |
2020-01-09 10:25:09 | vstinner | set | messages: + msg359661 |
2019-12-30 10:37:46 | xtreak | set | nosy:
+ vstinner messages: + msg359031 |
2019-12-12 10:30:30 | serhiy.storchaka | set | nosy:
+ serhiy.storchaka messages: + msg358299 |
2019-12-12 08:59:34 | xtreak | create |