JDK-8000439 : NPG: REGRESSION : sun/security/krb5/auto/MaxRetries.java fails with timeout
  • Type: Bug
  • Component: security-libs
  • Sub-Component: java.security
  • Affected Version: hs25
  • Priority: P2
  • Status: Closed
  • Resolution: Not an Issue
  • OS: solaris_11
  • CPU: sparc
  • Submitted: 2012-10-04
  • Updated: 2016-03-31
  • Resolved: 2013-09-30
The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.
Other
hs25Resolved
Related Reports
Relates :  
Sub Tasks
JDK-8000624 :  
Description
sun/security/krb5/auto/MaxRetries.java

The test fails with

----------------- TEST (1000,4) -----------------
>>> KDCCommunication: kdc=localhost UDP:33333, timeout=1000,Attempt =1, #bytes=144
>>> KDCCommunication: kdc=kdc.rabbit.hole UDP:16984, timeout=1000,Attempt =1, #bytes=144
>>> KDCCommunication: kdc=localhost UDP:33333, timeout=1000,Attempt =1, #bytes=226
>>> KDCCommunication: kdc=kdc.rabbit.hole UDP:16984, timeout=1000,Attempt =1, #bytes=226
----------System.err:(43/2757)----------
javax.security.auth.login.LoginException: Receive timed out
	at com.sun.security.auth.module.Krb5LoginModule.attemptAuthentication(Krb5LoginModule.java:771)
	at com.sun.security.auth.module.Krb5LoginModule.login(Krb5LoginModule.java:588)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:474)
	at javax.security.auth.login.LoginContext.invoke(LoginContext.java:785)
	at javax.security.auth.login.LoginContext.access$000(LoginContext.java:203)
	at javax.security.auth.login.LoginContext$4.run(LoginContext.java:698)
	at javax.security.auth.login.LoginContext$4.run(LoginContext.java:696)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.login.LoginContext.invokePriv(LoginContext.java:696)
	at javax.security.auth.login.LoginContext.login(LoginContext.java:594)
	at Context.fromJAAS(Context.java:114)
	at MaxRetries.test1(MaxRetries.java:101)
	at MaxRetries.main(MaxRetries.java:70)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:474)
	at com.sun.javatest.regtest.MainWrapper$MainThread.run(MainWrapper.java:94)
	at java.lang.Thread.run(Thread.java:722)
Caused by: java.net.SocketTimeoutException: Receive timed out
	at java.net.PlainDatagramSocketImpl.receive0(Native Method)
	at java.net.AbstractPlainDatagramSocketImpl.receive(AbstractPlainDatagramSocketImpl.java:143)
	at java.net.DatagramSocket.receive(DatagramSocket.java:781)
	at sun.security.krb5.internal.UDPClient.receive(NetClient.java:206)
	at sun.security.krb5.KdcComm$KdcCommunication.run(KdcComm.java:386)
	at sun.security.krb5.KdcComm$KdcCommunication.run(KdcComm.java:339)
	at java.security.AccessController.doPrivileged(Native Method)
	at sun.security.krb5.KdcComm.send(KdcComm.java:323)
	at sun.security.krb5.KdcComm.send(KdcComm.java:219)
	at sun.security.krb5.KdcComm.send(KdcComm.java:191)
	at sun.security.krb5.KrbAsReqBuilder.send(KrbAsReqBuilder.java:316)
	at sun.security.krb5.KrbAsReqBuilder.action(KrbAsReqBuilder.java:361)
	at com.sun.security.auth.module.Krb5LoginModule.attemptAuthentication(Krb5LoginModule.java:729)
	... 21 more

JavaTest Message: Test threw exception: javax.security.auth.login.LoginException: Receive timed out
JavaTest Message: shutting down test

STATUS:Failed.`main' threw exception: javax.security.auth.login.LoginException: Receive timed out
result: Failed. Execution failed: `main' threw exception: javax.security.auth.login.LoginException: Receive timed out


test result: Failed. Execution failed: `main' threw exception: javax.security.auth.login.LoginException: Receive timed out
Comments
The test still only fails on solaris-sparcv9. Close as there is no convincing proof of it being a hotspot bug. Meanwhile, the test in placed inside ProblemList.txt for solaris-sparc.
02-05-2013

I moved this bug to java.security. It has been shown that this test was unstable even before the PermGen removal. To see this, try JDK-b57 with -XX:-UseCompressedOops and see that it fails the same way as with the NPG build, JDK8-b58. Between b58 and b61 we didn't have CompressedKlassPointers so HotSpot was slightly slower and provoked this timeout. If you still see failures from this test, please open another bug.
26-04-2013

There is no recent changes to the test and source codes related. Yes, the test is timing sensitive, but it runs fine on other platforms and also before b57 and between b61 and b66. I tried to copy b76's libjvm.so to a b83 build but jtreg does not run with this "hybrid" jdk. Therefore I am currently unable to prove the issue is not a jdk one.
03-04-2013

It's not clear to me that this is a NoPermGen related issue anymore, and it's not even clear that it's a HotSpot and not a JDK issue. Do you have anything that supports that this test just isn't unstable? As I said before, running a JDK from before the PermGen removal but with -XX:-CompressedOops also triggers this timout. So, it seems to be very timing sensitive.
03-04-2013

The test is failing again now with the same problem on the same machine. I've done 3 rounds of testing and the result is: b50-b57: always OK b58-b80: always fail b61-b66: always OK b67-b76: failed 6 times randomly (6/30 = 20%) b77-b83: always fail According to the SQE nightly reports, the test only fails on solaris-sparcv9.
31-03-2013

This bug talks about a regression between b57 and b58. The reproducer given in the test consistently reproduced the bug with b58, but not with b57. The reproducer can't reproduce the bug with b61, when we introduced compressed klass pointers: changeset: 3724:8e47bac5643a user: roland date: Tue Oct 09 10:11:38 2012 +0200 summary: 7054512: Compress class pointers after perm gen removal So, I closed this a bing resolved by this fix. Maybe it's better to close it as a dup? Note that this test seem to be very unstable. If I run -XX:-UseCompressedOops I can cosistently reproduce this bug with b57. I would prefer if we opened a new bug for the current timeouts you are seeing, and leave this No PermGen bug as it is (or change it to a dup).
14-02-2013

Why is this bug marked as Resolved, I can't find a change-set. Should it have been marked a dup of something else? Another thing is that hs25-b05 was a long time ago and we're still seeing this periodically in TL nightly testing with hs25-b18.
14-02-2013

I was able to reproduce this on sc14160169 with the excellent reproducer. The timeout is, for some reasone, caused by the lack of compressed klass pointers after the NPG changes. So, this happens with builds JDK8-b58-JDK8-b60 and was fixed in hs25-b05/JDK8-b61. Note that the timeout can be reproduced on build JDK8-b57 and JDK8-b61 if compressed oops is turned off with the flag -XX:-UseCompressedOops.
31-01-2013

I have no idea what "unloaded" means. Context.java [1] uses anonymous classes for PrivilegedExceptionAction and Action [2] (something similar to a Runnable). KDC.java [3] uses them to create new Thread and NameService objects. [1] http://hg.openjdk.java.net/jdk8/tl/jdk/file/a1bbb8805e22/test/sun/security/krb5/auto/Context.java [2] http://hg.openjdk.java.net/jdk8/tl/jdk/file/a1bbb8805e22/test/sun/security/krb5/auto/Action.java [3] http://hg.openjdk.java.net/jdk8/tl/jdk/file/a1bbb8805e22/test/sun/security/krb5/auto/KDC.java
15-01-2013

Does the test require that the anonymous classes be unloaded (the uses in Context.java and KDC.java mentioned above)?
14-01-2013

I don't think it uses any jsr 292 things, neither does it uses any special classloaders. It does use some anonymous classes (through Context.java and KDC.java in the same directory). Yes, it is a performance problem. In fact, even 2000 might fail sometimes. It's just strange that on the same machine, the test almost always passes with b57 but almost always fails with b58. So we think there must be some change in b58 that slows it down.
11-01-2013

Does this test use any of the jsr 292 invokedynamic features. In particular does it use anonymous classes / classloaders? Since the test passes with the change to 2000 (in previous comment), does this mean this is a performance problem?
10-01-2013

You need to change 3 lines: rewriteMaxRetries(1, 10000); test1(10000, 4); // 1 2 1 2 test1(10000, 4); // 1 2 1 2 I don't think it's a hang, because in MaxRetries2.java I change it to 2000 and the test runs fine. It looks like that 1000 milliseconds is enough for b57 but not b58.
10-01-2013

What I would like to do is make the timeout very large so that I can determine if the problem is a hang of some sort. Can I do that wiht MaxRetries2.java.
08-01-2013

I made this change in MaxRetries2.java < rewriteMaxRetries(1, 10000); --- > rewriteMaxRetries(1, 2000); and I see this error below. How are the parameters for rewriteMaxRetries() and test1() connected? JavaTest Message: Test threw exception: java.lang.Exception: Wrong timeout valuetimeout=2000 JavaTest Message: shutting down test STATUS:Failed.`main' threw exception: java.lang.Exception: Wrong timeout valuetimeout=2000 TEST RESULT: Failed. Execution failed: `main' threw exception: java.lang.Exception: Wrong timeout valuetimeout=2000
08-01-2013

Timeout and max_retries use the same argument so it's not easy to only change the timeout. I've created a new test MaxRetries2.java (attached) and separate them. In lines 68-70, you can see that timeout is changed to 2000 and max_retries remains 1.
08-01-2013

Alternative test that can specify max_retries and timeout separately.
08-01-2013

Is there a way to run MaxRetries with a very large time? I looked at the MaxRetries.java and it appears to expect certain values for the time. When I tried to change the timeouts in the calls to test1() I got java.lang.Exception: Wrong timeout value
07-01-2013

Yes, the test can run directly, but in this case, it only fails when run after the ToByteArray test. I have completely no idea why. Originally SQE found out the jdk_security3 job (in the jdk/test/Makefile) fails and after some rounds of divide-and-conquer I simplified it into two tests only. Of course, I cannot guarantee it will succeed when run with other tests.
05-01-2013

Jon - the jdk tests are intended to be run directly (ie: interactively) or via jtreg. We don't use UTE although I believe it can run jtreg tests. Anyway for MaxRetries then you can just run it directly: javac MaxRetries java MaxRetries
05-01-2013

First, some files this test references changed since then so it does not compile now. You might need to call "hg update -r jdk8-b57". Second, you do need the test/closed repo. This bug is about a test failure when these 2 tests are run together.
05-01-2013

When I tried to run the test with you instructions, it failed with ACTION: compile -- Failed. Compilation failed: Compilation failed REASON: User specified action: run compile -XDignore.symbol.file MaxRetries.java I cd to a jdk/test but I had not pulled the test/closed so removed the ToByteArray test. I don't know if there was anything else missing from the jdk/test
05-01-2013

Weijun, Can you provide instructions on how to run this with UTE?
05-01-2013

Setting component and subcomponent; please adjust as appropriate.
17-10-2012