Issue31068
Created on 2017-07-28 14:59 by vstinner, last changed 2017-08-08 23:50 by vstinner. This issue is now closed.
Messages (17) | |||
---|---|---|---|
msg299391 - (view) | Author: STINNER Victor (vstinner) * ![]() |
Date: 2017-07-28 14:59 | |
Builds: * 52: build interrupted after 132 hours * 53: test_ttk_guionly passed * 54: test_ttk_guionly passed * 55: build interrupted after 14 hours Example: http://buildbot.python.org/all/builders/AMD64%20Windows8.1%20Refleaks%202.7/builds/52/steps/test/logs/stdio ... running: test_ttk_guionly (472605 sec) running: test_ttk_guionly (472635 sec) running: test_ttk_g command interrupted, attempting to kill program finished with exit code 1 elapsedTime=475847.190000 |
|||
msg299841 - (view) | Author: STINNER Victor (vstinner) * ![]() |
Date: 2017-08-07 10:24 | |
I interrupted the build 61 (it was running since 58 hours). ... running: test_ttk_guionly (191065 sec) running: test_ttk_guionly (191095 s command interrupted, attempting to kill |
|||
msg299842 - (view) | Author: STINNER Victor (vstinner) * ![]() |
Date: 2017-08-07 10:32 | |
The build 56 was also interrupted, it was running for 85 hours. |
|||
msg299843 - (view) | Author: STINNER Victor (vstinner) * ![]() |
Date: 2017-08-07 10:35 | |
The build 43 was also interrupted (it was running for 10 hours). Summary on builds 42-61, builds interrupted because of test_ttk_guionly: 43, 52, 55, 56, 61. Note: build 53 also failed, but for a different unknown reason. |
|||
msg299844 - (view) | Author: STINNER Victor (vstinner) * ![]() |
Date: 2017-08-07 10:36 | |
> Summary on builds 42-61, builds interrupted because of test_ttk_guionly: 43, 52, 55, 56, 61. 5 fails/20 builds: a failure rate of 25% (1/4) :-( |
|||
msg299875 - (view) | Author: STINNER Victor (vstinner) * ![]() |
Date: 2017-08-07 23:20 | |
I'm trying to reproduce the bug using the following command run in a Command Prompt: PCbuild\amd64\python_d.exe -m test -r -u all -R 3:3 -F -v --timeout=30 test_ttk_guionly Note: I'm using https://github.com/python/cpython/pull/3019 to get --timeout feature. Once (when I wasn't using --timeout=30), I saw test_ttk.test_widgets.TreeviewTest.test_tag_bind() stuck! But it only saw this bug twice in 1 hour of intensive tests, and so I'm not sure that it exists. Since I unable to easily reproduce the bug, it's hard to collect more information about the program state when the bug occurs. |
|||
msg299877 - (view) | Author: STINNER Victor (vstinner) * ![]() |
Date: 2017-08-07 23:39 | |
Ah! I captured the traceback of a first bug using the command: PCbuild\amd64\python_d.exe -m test -R 3:3 -u all -v --timeout=30 -r -F test_ttk_guionly Output: (...) test_resize (test_ttk.test_extensions.LabeledScaleTest) ... *** STACKTRACE - START *** # ThreadID: 1216 File: "C:\haypo\2.7\lib\threading.py", line 774, in __bootstrap self.__bootstrap_inner() File: "C:\haypo\2.7\lib\threading.py", line 801, in __bootstrap_inner self.run() File: "C:\haypo\2.7\lib\test\regrtest.py", line 2024, in run self.dump_threads() File: "C:\haypo\2.7\lib\test\regrtest.py", line 2050, in dump_threads self.dump_thread(stack) # ThreadID: 2172 File: "C:\haypo\2.7\lib\runpy.py", line 174, in _run_module_as_main "__main__", fname, loader, pkg_name) File: "C:\haypo\2.7\lib\runpy.py", line 72, in _run_code exec code in run_globals File: "C:\haypo\2.7\lib\test\__main__.py", line 3, in <module> regrtest.main_in_temp_cwd() File: "C:\haypo\2.7\lib\test\regrtest.py", line 2083, in main_in_temp_cwd main() File: "C:\haypo\2.7\lib\test\regrtest.py", line 841, in main result = local_runtest() File: "C:\haypo\2.7\lib\test\regrtest.py", line 827, in local_runtest testdir=testdir) File: "C:\haypo\2.7\lib\test\regrtest.py", line 1042, in runtest return runtest_inner(test, verbose, quiet, huntrleaks, pgo, testdir) File: "C:\haypo\2.7\lib\test\regrtest.py", line 1234, in runtest_inner huntrleaks) File: "C:\haypo\2.7\lib\test\regrtest.py", line 1369, in dash_R run_the_test() File: "C:\haypo\2.7\lib\test\regrtest.py", line 1355, in run_the_test indirect_test() File: "C:\haypo\2.7\lib\test\test_ttk_guionly.py", line 37, in test_main *runtktests.get_tests(text=False, packages=['test_ttk'])) File: "C:\haypo\2.7\lib\test\support\__init__.py", line 1577, in run_unittest _run_suite(suite) File: "C:\haypo\2.7\lib\test\support\__init__.py", line 1532, in _run_suite result = runner.run(suite) File: "C:\haypo\2.7\lib\unittest\runner.py", line 151, in run test(result) File: "C:\haypo\2.7\lib\unittest\suite.py", line 70, in __call__ return self.run(*args, **kwds) File: "C:\haypo\2.7\lib\unittest\suite.py", line 108, in run test(result) File: "C:\haypo\2.7\lib\unittest\suite.py", line 70, in __call__ return self.run(*args, **kwds) File: "C:\haypo\2.7\lib\unittest\suite.py", line 108, in run test(result) File: "C:\haypo\2.7\lib\unittest\case.py", line 393, in __call__ return self.run(*args, **kwds) File: "C:\haypo\2.7\lib\unittest\case.py", line 329, in run testMethod() File: "C:\haypo\2.7\lib\lib-tk\test\test_ttk\test_extensions.py", line 184, in t est_resize x.update() File: "C:\haypo\2.7\lib\lib-tk\Tkinter.py", line 1023, in update self.tk.call('update') *** STACKTRACE - END *** |
|||
msg299879 - (view) | Author: STINNER Victor (vstinner) * ![]() |
Date: 2017-08-08 00:31 | |
Another bug, truncated traceback since the top was the same: (...) File: "C:\haypo\2.7\lib\lib-tk\test\test_ttk\test_widgets.py", line 1367, in test_heading_callback self.tv.update() File: "C:\haypo\2.7\lib\lib-tk\Tkinter.py", line 1023, in update self.tk.call('update') |
|||
msg299882 - (view) | Author: STINNER Victor (vstinner) * ![]() |
Date: 2017-08-08 00:48 | |
I created bpo-31135: "[2.7] test_ttk_guionly doesn't destroy all widgets on Python 2.7". |
|||
msg299919 - (view) | Author: STINNER Victor (vstinner) * ![]() |
Date: 2017-08-08 13:31 | |
Calling "self.tk.call('update')" runs the Tcl event loop: * http://wiki.tcl.tk/1252 * https://www.tcl.tk/man/tcl/TclCmd/update.htm Interesting but very old (2001) article: "Update considered harmful" http://wiki.tcl.tk/1255 |
|||
msg299923 - (view) | Author: STINNER Victor (vstinner) * ![]() |
Date: 2017-08-08 14:16 | |
The Tcl event loop is recursive: http://wiki.tcl.tk/1527 |
|||
msg299928 - (view) | Author: STINNER Victor (vstinner) * ![]() |
Date: 2017-08-08 14:47 | |
Yesterday, I ran test_ttk_guionly during 3 hours on Windows with Python 2.7 compiled in debug mode. I saw between 4 and 7 hangs. I'm not sure about the exact number since sometimes the test unblocked when I just moved my mouse or clicked on my Command Prompt window.... At this point, I'm only sure that the following tests blocked: * test_ttk\test_extensions.py:184: LabeledScaleTest.test_resize() -- test ttk.LabeledScale * test_ttk\test_widgets.py:1367: TreeviewTest.test_heading_callback() -- test ttk.Treeview * test_ttk.test_widgets.TreeviewTest.test_tag_bind() -- test ttk.Treeview bpo-31135 fixes LabeledScale.destroy(), so it may be related. |
|||
msg299930 - (view) | Author: STINNER Victor (vstinner) * ![]() |
Date: 2017-08-08 15:14 | |
Another hang: test_ttk\test_extensions.py:335: LabeledScaleTest.test2_variable_change(). Traceback: (...) File: "C:\haypo\2.7\lib\lib-tk\test\test_ttk\test_extensions.py", line 335, in test2_variable_change x.update() File: "C:\haypo\2.7\lib\lib-tk\Tkinter.py", line 1023, in update self.tk.call('update') I'm now using this batch script: --- :repeat PCbuild\amd64\python_d.exe -m test -u all --timeout=30 -R 3:3 -r test_ttk_guionly if not %errorlevel% equ 0 goto :fail echo OKKKKK goto :repeat :fail echo ERRRRRR --- |
|||
msg299941 - (view) | Author: STINNER Victor (vstinner) * ![]() |
Date: 2017-08-08 17:42 | |
I pushed my fix for bpo-31135, no idea at this point if it fix this issue. New changeset 56e162ad5c5d3effe9b4f05d0179e1b6a2a2d9b8 by Victor Stinner in branch '2.7': ttk: fix LabeledScale and OptionMenu destroy() method (#3026) https://github.com/python/cpython/commit/56e162ad5c5d3effe9b4f05d0179e1b6a2a2d9b8 |
|||
msg299943 - (view) | Author: STINNER Victor (vstinner) * ![]() |
Date: 2017-08-08 17:50 | |
I interrupted http://buildbot.python.org/all/builders/AMD64%20Windows8.1%20Refleaks%202.7/builds/63/ which was running since 17 hours... ("running: test_ttk_guionly (32770 sec)") |
|||
msg299944 - (view) | Author: STINNER Victor (vstinner) * ![]() |
Date: 2017-08-08 17:52 | |
> I pushed my fix for bpo-31135, no idea at this point if it fix this issue. Too bad, test_resize() failed again while testing commit 56e162ad5c5d3effe9b4f05d0179e1b6a2a2d9b8 :-( So this fix was not enough. |
|||
msg299954 - (view) | Author: STINNER Victor (vstinner) * ![]() |
Date: 2017-08-08 23:50 | |
> Too bad, test_resize() failed again while testing commit 56e162ad5c5d3effe9b4f05d0179e1b6a2a2d9b8 :-( So this fix was not enough. I am not sure anymore about this statement. I had a bug in my watchdog code, that I fixed after this failure. I ran again the test during 3 hours and it didn't fail. I reverted all my local changes, I rebuild Python 2.7 in debug mode to get a fresh python_d.exe, I removed all __pycache__, and then I ran again the test during 1 hour: no fail. I ran 4 instances of the test in parallel during 1 hour: no fail. Hum, it *seems* like the bug was fixed. Since it's a race condition, it's not possible to say that it's really fixed. But my test results show that the bug is very likely to be fixed, so I close the bug. I will watch AMD64 Windows8.1 Refleaks 2.7 buildbot slave next days to check if the bug occurs again. |
History | |||
---|---|---|---|
Date | User | Action | Args |
2017-08-08 23:50:44 | vstinner | set | status: open -> closed resolution: fixed messages: + msg299954 stage: resolved |
2017-08-08 17:52:10 | vstinner | set | messages: + msg299944 |
2017-08-08 17:50:15 | vstinner | set | messages: + msg299943 |
2017-08-08 17:42:12 | vstinner | set | messages: + msg299941 |
2017-08-08 15:14:07 | vstinner | set | messages: + msg299930 |
2017-08-08 14:47:32 | vstinner | set | messages: + msg299928 |
2017-08-08 14:16:46 | vstinner | set | messages: + msg299923 |
2017-08-08 13:31:53 | vstinner | set | messages:
+ msg299919 title: test_ttk_guionly hangs at self.tk.call('update') on AMD64 Windows8.1 Refleaks 2.7 -> [2.7] test_ttk_guionly hangs at self.tk.call('update') on AMD64 Windows8.1 Refleaks 2.7 |
2017-08-08 01:28:44 | vstinner | set | nosy:
+ gpolo |
2017-08-08 00:50:31 | vstinner | set | title: test_ttk_guionly hangs on AMD64 Windows8.1 Refleaks 2.7 -> test_ttk_guionly hangs at self.tk.call('update') on AMD64 Windows8.1 Refleaks 2.7 |
2017-08-08 00:48:29 | vstinner | set | nosy:
+ serhiy.storchaka |
2017-08-08 00:48:19 | vstinner | set | messages: + msg299882 |
2017-08-08 00:31:09 | vstinner | set | messages: + msg299879 |
2017-08-07 23:39:46 | vstinner | set | messages: + msg299877 |
2017-08-07 23:20:12 | vstinner | set | messages: + msg299875 |
2017-08-07 10:36:20 | vstinner | set | messages: + msg299844 |
2017-08-07 10:35:24 | vstinner | set | messages: + msg299843 |
2017-08-07 10:32:04 | vstinner | set | messages: + msg299842 |
2017-08-07 10:24:39 | vstinner | set | messages: + msg299841 |
2017-07-28 14:59:47 | vstinner | create |