Bug 1011056

Created attachment 855877 [details]
Replay error reproduced with trace

Reproduced this locally on 6.2.x using a single test run script that collects the logs if the error occurs. So far there seem to be 3 different variations that produce the same error message. Attached files contain the normal surefire logs, the workdir test.log, and the server logs with trace enabled at the 'org' level. Couldn't think of any other useful information to gather.

This replay error is the only one that's happened multiple times. It can occur on any or all tests and doesn't cause a cascading failure in later tests. The other two seem to have problems somewhere during the authentication process, but this one doesn't even start authenticating. The message is, I believe, simply ignored as a duplicate. The lines in the test.log are: 

15:58:07,467 WARN  [org.apache.directory.server.kerberos.protocol.KerberosProtocolHandler] (NioDatagramAcceptor-1) Request is a replay (34)
15:58:07,476 WARN  [org.apache.http.client.protocol.RequestTargetAuthentication] (main) NEGOTIATE authentication error: No valid credentials provided (Mechanism level: No valid credentials provided (Mechanism level: Request is a replay (34) - Request is a replay))

Created attachment 855882 [details]
Authentication Failure error reproduced with trace

This is a failure in the authentication process. No idea as to why it happens.

In the test.log the discrepancy shows up as:

14:44:34,129 DEBUG [org.jboss.as.test.integration.security.common.negotiation.JBossNegotiateScheme] (main) Received challenge 'oXAwbqJsBGpgaAYJKoZIhvcSAQICAgBvWTBXoAMCAQWhAwIBD6JLMEmgAwIBA6JCBEB2+4/B++Bk oskpuCKf1l8c0hf3I1xb6cHgUtp9mKiu4at1ZXODGkzpYXHHAyLu+s+/IP48cehpvCh8x+/KKZCM' from the auth server

So far all the 'Received challenge' messages in normal test runs are blank. There's never anything actually sent, which leads me to believe that this message in the test.log is a sign of the authentication failure on the server side. 

The server.log contains this message:

14:44:34,120 INFO  [stdout] (http-/127.0.0.1:8080-2) [Krb5LoginModule] authentication failed

This reproduction is on the 4th test, so I'm not sure if it would cause a cascade failure like the next variation. This one seems to close itself cleanly, no actual error messages, so I suspect it would not cascade.

Created attachment 855886 [details]
ERR_166 error reproduced with trace

This one seems like a badly handled version of the 2nd case. The authentication goes wrong for some reason, but the effect isn't handled well and causes errors that result in the 3rd and 4th tests in the class to fail as well. 

On the test.log side of things there's this message: 

16:12:01,669 ERROR [org.apache.directory.server.ldap.handlers.SearchAbandonListener] (pool-5-thread-1) ERR_166 Failed to close the search cursor for message 3 on abandon request.: java.lang.IllegalStateException: NumActions zero when read action is ended : Version: (vesion: 406, numActions: -1)

And on the server.log side there's a message handled at the debug level (Stacktrace contained in attached files):

16:12:01,714 DEBUG [org.jboss.security] (http-localhost.localdomain/127.0.0.1:8080-1) PBOX000206: Login failure: javax.security.auth.login.LoginException: Error finding roles

This appears to kick off a removal of part of the information needed for the next tests, 3 and 4, which results in them failing as well.

Hopefully this can help.

https://github.com/jbossas/jboss-eap/pull/897

I'm not seeing this issue now on IPV4 jobs for EAP 6.3.0 DR6 but it still occures on IPV6 jobs. 
See eg.:
https://jenkins.mw.lab.eng.bos.redhat.com/hudson/view/EAP6/view/EAP6-AS-Testsuite/job/eap-60-as-testsuite-RHEL-OracleJDK6-dualstackIPV6/92/testReport/

https://jenkins.mw.lab.eng.bos.redhat.com/hudson/view/EAP6/view/EAP6-AS-Testsuite/job/eap-60-as-testsuite-RHEL-OracleJDK6-dualstackIPV6/lastCompletedBuild/jdk=java16_default,label_exp=RHEL5%26%26x86%26%26ipv6%26%26!pure-ipv6/testReport/org.jboss.as.test.integration.security.loginmodules.negotiation/AdvancedLdapLoginModuleTestCase/

Seems that we are hitting another issue. The Request is a replay (34) issues are gone, but it looks there is another IPV6 related issue.

Pavel Janousek <pjanouse> updated the status of jira JBPAPP-10974 to Closed

Correct link after job renaming is 
https://jenkins.mw.lab.eng.bos.redhat.com/hudson/view/EAP6/view/EAP6-AS-Testsuite/job/eap-6x-as-testsuite-RHEL-matrix-OracleJDK6-dualstackIPV6/92/jdk=java16_default,label_exp=RHEL5%26%26x86%26%26ipv6%26%26!pure-ipv6/testReport/org.jboss.as.test.integration.security.loginmodules.negotiation/AdvancedLdapLoginModuleTestCase/

This looks like another issue that has had the 6.4 flag added without resetting the remaining flags meaning it looks like it has 3 ACKs when in fact 3 ACKS were never granted for EAP 6.4.

PR sent: https://github.com/jbossas/jboss-eap/pull/2065

An update in NetworkUtils.formatPossibleIpv6Address(address) method canonizes IPv6 addresses now. The AdvancedLdapLoginModuleTestCase has to be updated to use correct format for LDAP server SPN in KDC.

Verified on EAP 6.4.0.DR12

AdvancedLdapLoginModuleTestCase now use correct address format, however there seems to be another issue. This is now under investigation and will be covered by a new bugzilla.

https://jenkins.mw.lab.eng.bos.redhat.com/hudson/job/eap-6x-as-testsuite-IPv6-rhel/27/RELEASE=6.4.0,jdk=openjdk1.6_local,label_exp=eap-sustaining%20&&%20RHEL5%20&&%20x86%20&&%20ipv6/testReport/org.jboss.as.test.integration.security.loginmodules.negotiation/AdvancedLdapLoginModuleTestCase/