ImageImage

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.

classification
Title: IDLE: ColorDelegatorTest test_incremental_editing failures
Type: behavior Stage: resolved
Components: IDLE, Tests Versions: Python 3.11
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: terry.reedy Nosy List: miss-islington, taleinat, terry.reedy, vstinner
Priority: normal Keywords: patch

Created on 2021-06-01 20:38 by terry.reedy, last changed 2022-04-11 14:59 by admin. This issue is now closed.

Files
File name Uploaded Description Edit
tkinter_testing_utils.py terry.reedy, 2021-06-02 19:02 Adaptive
Pull Requests
URL Status Linked Edit
PR 26404 taleinat, 2021-06-01 20:41
PR 26491 merged taleinat, 2021-06-02 19:45
PR 26499 merged miss-islington, 2021-06-02 23:53
Messages (14)
msg394870 - (view) Author: Terry J. Reedy (terry.reedy) * (Python committer) Date: 2021-06-01 20:38
idlelib.idle_test.test_colordelagator.ColorDelegatorTest.test_incremental_editing has failed on at least on the following machines.  

Pip32  CI Pipelines Win32
Gen3x  https://buildbot.python.org/all/#/builders/464  x86 Gentoo Installed with X 3.x
GenPR  https://buildbot.python.org/all/#/builders/465  x86 Gentoo Installed with X PR

Failures seen.  Since tests are sequential without subtesting, failure means successors are not tested.

line  keyword start       want            got  
569   ('BUILTIN', '1.0'), ('1.0', '1.3')  ()              Gen3x, x3; GenPR
573   ('BUILTIN', '1.0'), ('1.0', '1.3')  ()              Gen3x, x5
586   ('BUILTIN', '1.0'), ('1.0', '1.3')  ()              GenPR
597   ('KEYWORD', '1.0'), ()              ('1.0', '1.1')  Pip32, x2

As far as I can tell, looking at Windows buildbots, the 1 failure on Win32 has not been repeated.  If there have been any on CI machines, I have not been informed.

A few years ago, I believe Gentoo was the only *nix buildbot running tkinter and IDLE tests. It has a problem with a builtin at the beginning of the line about 10-20% of test runs.  This are the majority of its failures in the last week.  Perhaps there is a timing issue we can fix.
msg394914 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2021-06-02 14:30
Buildbots are very unstable these days. I propose to revert the change to give more time to IDLE developers to investigate the issue, and to be able to identify other regressions on buildbots.
https://pythondev.readthedocs.io/ci.html#revert-on-fail

I created https://github.com/python/cpython/pull/26487 to revert
msg394918 - (view) Author: Tal Einat (taleinat) * (Python committer) Date: 2021-06-02 15:00
Please note that the referenced PR is not the correct one.

I'll add a link to the right one shortly.
msg394919 - (view) Author: Tal Einat (taleinat) * (Python committer) Date: 2021-06-02 15:03
The latest PR where changes were made to IDLE's colorizer and its tests, including specifically adding the problematic test, is GH-25851.
msg394921 - (view) Author: Tal Einat (taleinat) * (Python committer) Date: 2021-06-02 15:05
I'm investigating this now. If nothing obvious comes up, I'll revert that PR.
msg394925 - (view) Author: Tal Einat (taleinat) * (Python committer) Date: 2021-06-02 16:07
On Ubuntu 20.04, I've managed to occasionally get this issue to reproduce locally by running the test many times in parallel, repeatedly:

parallel -n8 -N0 './python -m test -ugui test_idle -m test_colorizer' ::: $(seq 20)

This appears to be an issue with our new method of running tests with a Tk mainloop in the background, using the @run_in_tk_mainloop decorator.

Investigating further.
msg394936 - (view) Author: Terry J. Reedy (terry.reedy) * (Python committer) Date: 2021-06-02 19:02
The confusion is my fault: PR-26404 is where I first saw this failure, for the previously added tests, not where the test was added.  I unlinked the erroneous message.

Running 12 duplicate tests in parallel on Windows on a 6 core (12 CPU) machine with

f:\dev\3x>python -m test -j12  -ugui -m test_incremental_editing test_idle test_idle test_idle test_idle test_idle test_idle test_idle test_idle test_idle test_idle test_idle test_idle

resulted in nearly all failing.  Half or less failed with -j6, usually one with -j3, none without -j.  Are the processess failing because of interaction with each other?  Or from be switched with other processes?

Back with -j12: increasing the after delay in run_in_tk_mainloop from 1 to 5 cut the failures down to 0-4 in 12.  Increasing further to 8 resulting in no failures.  Note that human keystrokes are at least, say, 50 milliseconds (1/20 second) apart.

I am reluctant to add a delay that is mostly not needed, so i tried the uploaded 'adaptive' code to only add a long delay if needed.  Uploaded.  But when a tested failed once, it failed again even with the delay, and contrary to the results above.
msg394937 - (view) Author: Terry J. Reedy (terry.reedy) * (Python committer) Date: 2021-06-02 19:09
The other thing I thought is parameterizing the decorator to pass in a delay only for this test, but that require another layer of wrapping, which I cannot do right now.

So I think we should just add skiptest for now.  In fact, we only need to run it when editing colordelagator.
msg394939 - (view) Author: Tal Einat (taleinat) * (Python committer) Date: 2021-06-02 19:31
> Running 12 duplicate tests in parallel on Windows on a 6 core (12 CPU) machine with [...] resulted in nearly all failing.

Yes, running test_idle in parallel with itself usually causes some failures due to UI focus being stolen from one instance by another.  That's why I just ran this test rather than the whole test suite.

> I am reluctant to add a delay that is mostly not needed, so i tried the uploaded 'adaptive' code to only add a long delay if needed.  Uploaded.  But when a tested failed once, it failed again even with the delay, and contrary to the results above.

The delay needs to be placed carefully.  Changing root.after(1, ...) to use 50 rather than 1 (these are milliseconds) seems to resolve the issue entirely on my machine, at the cost of this single test taking 0.4 seconds to run rather than about 0.045 seconds.

> The other thing I thought is parameterizing the decorator to pass in a delay only for this test, but that require another layer of wrapping, which I cannot do right now.

I can do that.  Though I fear this may happen for other such tests as well...  Worth a shot I guess.
msg394941 - (view) Author: Tal Einat (taleinat) * (Python committer) Date: 2021-06-02 19:42
On my machine it running the test many times with parallelization no longer causes any failures with this change.  Also, running other tests which us the @run_in_tk_mainloop decorator, with the same 1ms delay as before, doesn't cause any such failures.  PR forthcoming.
msg394942 - (view) Author: Tal Einat (taleinat) * (Python committer) Date: 2021-06-02 19:45
See PR GH-26491.
msg394959 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2021-06-02 23:53
New changeset adef445dc34685648bd0ea1c125df2ef143912ed by Tal Einat in branch 'main':
bpo-44282: Fix occasional test_incremental_editing failures on buildbots (GH-26491)
https://github.com/python/cpython/commit/adef445dc34685648bd0ea1c125df2ef143912ed
msg394962 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2021-06-03 00:14
New changeset 9c89d62073fa0bcfe68e59add5b55fbcbf7672ab by Miss Islington (bot) in branch '3.10':
bpo-44282: Fix occasional test_incremental_editing failures on buildbots (GH-26491) (GH-26499)
https://github.com/python/cpython/commit/9c89d62073fa0bcfe68e59add5b55fbcbf7672ab
msg394973 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2021-06-03 02:17
The 12 latest build on https://buildbot.python.org/all/#/builders/464 are green (success). Can this issue be closed now? We can reopen it later if the issue strikes back.
History
Date User Action Args
2022-04-11 14:59:46adminsetgithub: 88448
2021-06-03 03:17:41terry.reedysetstatus: open -> closed
resolution: fixed
stage: patch review -> resolved
2021-06-03 02:17:24vstinnersetmessages: + msg394973
2021-06-03 00:14:49vstinnersetmessages: + msg394962
2021-06-02 23:53:49miss-islingtonsetnosy: + miss-islington
pull_requests: + pull_request25095
2021-06-02 23:53:48vstinnersetmessages: + msg394959
2021-06-02 19:45:41taleinatsetmessages: + msg394942
2021-06-02 19:45:26taleinatsetpull_requests: + pull_request25087
2021-06-02 19:42:22taleinatsetmessages: + msg394941
2021-06-02 19:31:55taleinatsetmessages: + msg394939
2021-06-02 19:09:19terry.reedysetmessages: + msg394937
2021-06-02 19:02:09terry.reedysetfiles: + tkinter_testing_utils.py

messages: + msg394936
2021-06-02 17:56:20terry.reedysetmessages: - msg394871
2021-06-02 16:07:56taleinatsetmessages: + msg394925
2021-06-02 15:05:24taleinatsetmessages: + msg394921
2021-06-02 15:03:18taleinatsetmessages: + msg394919
2021-06-02 15:00:05taleinatsetmessages: + msg394918
2021-06-02 14:30:22vstinnersetnosy: + vstinner
messages: + msg394914
2021-06-01 20:41:34taleinatsetkeywords: + patch
stage: needs patch -> patch review
pull_requests: + pull_request25076
2021-06-01 20:40:37terry.reedysetmessages: + msg394871
2021-06-01 20:38:25terry.reedycreate