8278348: [macos12] javax/swing/JTree/4908142/bug4908142.java fails in macos12

[prsadhuk]

Test seem to be failing in macos12.0.1 (although it does not seem to affect 12.1) due to keypresses of "a", "a", "d" is not selecting "aad" but "ade" which seems to point to the fact that 2 exclusive "a" keypress are considered as 1 "a" keypress.
Although I am not able to reroduce this issue if test is ran standalone or in JTree group, but it fails when ran as toplevel "jdk_desktop" testgroup or even whole swing test group.

Looking at text navigational algorithm probably done in JDK-4908142 (although I am not sure if this is done for that bug or subsequently revised)
https://github.com/openjdk/jdk/blob/master/src/java.desktop/share/classes/javax/swing/plaf/basic/BasicTreeUI.java#L3804

it seems if a subsequent key press comes after a predefined timefactor after the previous keypress, it is considered as a fresh/new keypress and not part of ongoing string search ie, if 2nd "a" comes after the predefined timefactor from 1st "a', then seacrh algorithm will search for "ad" and not "aad" as can be seen here
https://github.com/openjdk/jdk/blob/master/src/java.desktop/share/classes/javax/swing/plaf/basic/BasicTreeUI.java#L3815

I am not sure why macos12 will take so long for 2nd "a" keypress but the logs corraborates that it does take more than "timefactor" time what is set now, which is 1000.
1st "a" keypress, we have time 1639400688049 lastTime 0 typedString a
2nd "a" keypress, we have time 1639400691150 lastTime 1639400688049 typedString a [which is diff of 3101]

So, proposed fix is to configure "Tree.timeFactor" to 5000 to workaround this macos12 issue. It pass when full desktop tests is run in macos12 and also test passes in all platforms.

---

Progress

• Change must not contain extraneous whitespace
• Commit message must refer to an issue
• Change must be properly reviewed

Issue

• JDK-8278348: [macos12] javax/swing/JTree/4908142/bug4908142.java fails in macos12

Reviewing

Using git

Checkout this PR locally:
$ git fetch https://git.openjdk.java.net/jdk pull/6826/head:pull/6826
$ git checkout pull/6826

Update a local copy of the PR:
$ git checkout pull/6826
$ git pull https://git.openjdk.java.net/jdk pull/6826/head

Using Skara CLI tools

Checkout this PR locally:
$ git pr checkout 6826

View PR using the GUI difftool:
$ git pr show -t 6826

Using diff file

Download this PR as a diff file:
https://git.openjdk.java.net/jdk/pull/6826.diff

[bridgekeeper]

👋 Welcome back psadhukhan! A progress list of the required criteria for merging this PR into master will be added to the body of your pull request. There are additional pull request commands available for use with this pull request.

[openjdk]

@prsadhuk The following label will be automatically applied to this pull request:

• client

When this pull request is ready to be reviewed, an "RFR" email will be sent to the corresponding mailing list. If you would like to change these labels, use the /label pull request command.

[mlbridge]

Webrevs

• 00: Full (cf6b6f04)

[mrserb]

Can you please check that the slowness was caused by the receiving events from the cocoa, and not by the posting delayed(for some reason) events by the robot.

[prsadhuk]

As per the logs I have put in CRobot.m#Java_sun_lwawt_macosx_CRobot_keyEvent
we get
1st "a" keypress,
2021-12-15 17:27:30.721 java[3040:167835] java keyCode 41
2021-12-15 17:27:30.721 java[3040:167835] Before autoDelay CFAbsoluteTimeGetCurrent 661282050.721198

2nd "a" keypress
2021-12-15 17:27:33.865 java[3040:167835] java keyCode 41
2021-12-15 17:27:33.865 java[3040:167835] Before autoDelay CFAbsoluteTimeGetCurrent 661282053.865368 ==> difference of 3.144

"d" keypress
2021-12-15 17:27:33.994 java[3040:167835] java keyCode 44
2021-12-15 17:27:33.994 java[3040:167835] Before autoDelay CFAbsoluteTimeGetCurrent 661282053.994263 ==> difference of 0.128

[mrserb]

Does it mean that 3.144 after the first press is a delay caused by some code in the robot?

[prsadhuk]

Does it mean that 3.144 after the first press is a delay caused by some code in the robot?

It seems to be osx12.0.1 system quirk..osx12.1 does not same issue...
Logs in Robot.java#keyPress() shows
1st "a" keypress, keyCode 65 System.timemillis1641224225838
2nd "a" keypress, keyCode 65 System.timemillis 1641224229077 diff of 3239....
not sure if any robot code gets executed between these 2 keypress (done in testcase)

[prrace]

This just doesn't feel right. 3 seconds to register a key press ?
I looked at the system on which this was originally reported and the key delay until repeat looks normal.
We've got at least one other bug open where there's some weirdness on macOS 12 where Robot slows down after "m" is pressed. Could this be something similar ?

[prsadhuk]

Not sure if it is similar slowness issue after "m" keypress. For this at least, it is manifested only for repeated keys
as If we type "aad", the time taken for "d" key is (log in Robot#keyPress)
keyCode 68 time 1641224229200 (diff of 123 from last keypress time 1641224229077 )

[mrserb]

If it is not a problem now can we close this PR?

[prsadhuk]

it is a problem in 12.0.1

[bridgekeeper]

@prsadhuk This pull request has been inactive for more than 4 weeks and will be automatically closed if another 4 weeks passes without any activity. To avoid this, simply add a new comment to the pull request. Feel free to ask for assistance if you need help with progressing this pull request towards integration!

[bridgekeeper]

@prsadhuk This pull request has been inactive for more than 8 weeks and will now be automatically closed. If you would like to continue working on this pull request in the future, feel free to reopen it! This can be done using the /open pull request command.