[HDFS-14461] RBF: Fix intermittently failing kerberos related unit test

• Type: Sub-task
• Status: Resolved
• Priority: Major
• Resolution: Fixed
• Fix Version/s: 3.3.0
• Hadoop Flags: Reviewed
• Assignee: Xiaoqiao He
• Reporter: CR Hota
• Created: 30/Apr/19 00:08
• Updated: 26/Sep/19 22:40
• Resolved: 26/Sep/19 22:27

Description

TestRouterHttpDelegationToken#testGetDelegationToken fails intermittently. It may be due to some race condition before using the keytab that's created for testing.

 

 Failed

org.apache.hadoop.hdfs.server.federation.security.TestRouterHttpDelegationToken.testGetDelegationToken
 Failing for the past 1 build (Since [!https://builds.apache.org/static/1e9ab9cc/images/16x16/red.png! #26721|https://builds.apache.org/job/PreCommit-HDFS-Build/26721/] )
 [Took 89 ms.|https://builds.apache.org/job/PreCommit-HDFS-Build/26721/testReport/org.apache.hadoop.hdfs.server.federation.security/TestRouterHttpDelegationToken/testGetDelegationToken/history]
  
 Error Message

org.apache.hadoop.security.KerberosAuthException: failure to login: for principal: router/[e-mail] from keytab /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs-rbf/target/test/data/SecurityConfUtil/test.keytab javax.security.auth.login.LoginException: Integrity check on decrypted field failed (31) - PREAUTH_FAILED
h3. Stacktrace

org.apache.hadoop.service.ServiceStateException: org.apache.hadoop.security.KerberosAuthException: failure to login: for principal: router/[e-mail] from keytab /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs-rbf/target/test/data/SecurityConfUtil/test.keytab javax.security.auth.login.LoginException: Integrity check on decrypted field failed (31) - PREAUTH_FAILED at org.apache.hadoop.service.ServiceStateException.convert(ServiceStateException.java:105) at org.apache.hadoop.service.AbstractService.init(AbstractService.java:173) at org.apache.hadoop.hdfs.server.federation.security.TestRouterHttpDelegationToken.setup(TestRouterHttpDelegationToken.java:99) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47) at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:24) at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27) at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) at org.junit.runners.ParentRunner.run(ParentRunner.java:363) at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:365) at org.apache.maven.surefire.junit4.JUnit4Provider.executeWithRerun(JUnit4Provider.java:273) at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:238) at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:159) at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:384) at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:345) at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:126) at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:418) Caused by: org.apache.hadoop.security.KerberosAuthException: failure to login: for principal: router/[e-mail] from keytab /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs-rbf/target/test/data/SecurityConfUtil/test.keytab javax.security.auth.login.LoginException: Integrity check on decrypted field failed (31) - PREAUTH_FAILED at org.apache.hadoop.security.UserGroupInformation.doSubjectLogin(UserGroupInformation.java:2008) at org.apache.hadoop.security.UserGroupInformation.loginUserFromKeytabAndReturnUGI(UserGroupInformation.java:1376) at org.apache.hadoop.security.UserGroupInformation.loginUserFromKeytab(UserGroupInformation.java:1156) at org.apache.hadoop.security.SecurityUtil.login(SecurityUtil.java:315) at org.apache.hadoop.hdfs.server.federation.router.Router.serviceInit(Router.java:159) at org.apache.hadoop.service.AbstractService.init(AbstractService.java:164) ... 27 more Caused by: javax.security.auth.login.LoginException: Integrity check on decrypted field failed (31) - PREAUTH_FAILED at com.sun.security.auth.module.Krb5LoginModule.attemptAuthentication(Krb5LoginModule.java:804) at com.sun.security.auth.module.Krb5LoginModule.login(Krb5LoginModule.java:617) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at javax.security.auth.login.LoginContext.invoke(LoginContext.java:755) at javax.security.auth.login.LoginContext.access$000(LoginContext.java:195) at javax.security.auth.login.LoginContext$4.run(LoginContext.java:682) at javax.security.auth.login.LoginContext$4.run(LoginContext.java:680) at java.security.AccessController.doPrivileged(Native Method) at javax.security.auth.login.LoginContext.invokePriv(LoginContext.java:680) at javax.security.auth.login.LoginContext.login(LoginContext.java:587) at org.apache.hadoop.security.UserGroupInformation$HadoopLoginContext.login(UserGroupInformation.java:2087) at org.apache.hadoop.security.UserGroupInformation.doSubjectLogin(UserGroupInformation.java:1998) ... 32 more Caused by: KrbException: Integrity check on decrypted field failed (31) - PREAUTH_FAILED at sun.security.krb5.KrbAsRep.<init>(KrbAsRep.java:82) 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:776) ... 46 more Caused by: KrbException: Identifier doesn't match expected value (906) at sun.security.krb5.internal.KDCRep.init(KDCRep.java:140) at sun.security.krb5.internal.ASRep.init(ASRep.java:64) at sun.security.krb5.internal.ASRep.<init>(ASRep.java:59) at sun.security.krb5.KrbAsRep.<init>(KrbAsRep.java:60) ... 49 more
h3. Standard Output

2019-04-28 05:53:23,957 [Listener at localhost/39018] INFO minikdc.MiniKdc (MiniKdc.java:<init>(225)) - Configuration: 2019-04-28 05:53:23,957 [Listener at localhost/39018] INFO minikdc.MiniKdc (MiniKdc.java:<init>(226)) - --------------------------------------------------------------- 2019-04-28 05:53:23,957 [Listener at localhost/39018] INFO minikdc.MiniKdc (MiniKdc.java:<init>(228)) - debug: false 2019-04-28 05:53:23,957 [Listener at localhost/39018] INFO minikdc.MiniKdc (MiniKdc.java:<init>(228)) - transport: TCP 2019-04-28 05:53:23,957 [Listener at localhost/39018] INFO minikdc.MiniKdc (MiniKdc.java:<init>(228)) - max.ticket.lifetime: 86400000 2019-04-28 05:53:23,958 [Listener at localhost/39018] INFO minikdc.MiniKdc (MiniKdc.java:<init>(228)) - org.name: EXAMPLE 2019-04-28 05:53:23,958 [Listener at localhost/39018] INFO minikdc.MiniKdc (MiniKdc.java:<init>(228)) - kdc.port: 0 2019-04-28 05:53:23,958 [Listener at localhost/39018] INFO minikdc.MiniKdc (MiniKdc.java:<init>(228)) - org.domain: COM 2019-04-28 05:53:23,958 [Listener at localhost/39018] INFO minikdc.MiniKdc (MiniKdc.java:<init>(228)) - max.renewable.lifetime: 604800000 2019-04-28 05:53:23,958 [Listener at localhost/39018] INFO minikdc.MiniKdc (MiniKdc.java:<init>(228)) - instance: DefaultKrbServer 2019-04-28 05:53:23,958 [Listener at localhost/39018] INFO minikdc.MiniKdc (MiniKdc.java:<init>(228)) - kdc.bind.address: localhost 2019-04-28 05:53:23,959 [Listener at localhost/39018] INFO minikdc.MiniKdc (MiniKdc.java:<init>(230)) - --------------------------------------------------------------- 2019-04-28 05:53:23,961 [Listener at localhost/39018] INFO minikdc.MiniKdc (MiniKdc.java:start(285)) - MiniKdc started. 2019-04-28 05:53:24,014 [pool-10-thread-1] INFO request.KdcRequest (KdcRequest.java:preauth(651)) - The preauth data is empty. 2019-04-28 05:53:24,015 [pool-10-thread-1] INFO server.KdcHandler (KdcHandler.java:handleRecoverableException(177)) - KRB error occurred while processing request:Additional pre-authentication required 2019-04-28 05:53:24,025 [Listener at localhost/39018] INFO service.AbstractService (AbstractService.java:noteFailure(267)) - Service org.apache.hadoop.hdfs.server.federation.router.Router failed in state INITED org.apache.hadoop.security.KerberosAuthException: failure to login: for principal: router/[e-mail] from keytab /testptch/hadoop/hadoop-hdfs-project/hadoop-hdfs-rbf/target/test/data/SecurityConfUtil/test.keytab javax.security.auth.login.LoginException: Integrity check on decrypted field failed (31) - PREAUTH_FAILED at org.apache.hadoop.security.UserGroupInformation.doSubjectLogin(UserGroupInformation.java:2008) at org.apache.hadoop.security.UserGroupInformation.loginUserFromKeytabAndReturnUGI(UserGroupInformation.java:1376) at org.apache.hadoop.security.UserGroupInformation.loginUserFromKeytab(UserGroupInformation.java:1156) at org.apache.hadoop.security.SecurityUtil.login(SecurityUtil.java:315) at org.apache.hadoop.hdfs.server.federation.router.Router.serviceInit(Router.java:159) at org.apache.hadoop.service.AbstractService.init(AbstractService.java:164) at org.apache.hadoop.hdfs.server.federation.security.TestRouterHttpDelegationToken.setup(TestRouterHttpDelegationToken.java:99) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47) at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:24) at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27) at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) at org.junit.runners.ParentRunner.run(ParentRunner.java:363) at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:365) at org.apache.maven.surefire.junit4.JUnit4Provider.executeWithRerun(JUnit4Provider.java:273) at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:238) at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:159) at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:384) at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:345) at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:126) at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:418) Caused by: javax.security.auth.login.LoginException: Integrity check on decrypted field failed (31) - PREAUTH_FAILED at com.sun.security.auth.module.Krb5LoginModule.attemptAuthentication(Krb5LoginModule.java:804) at com.sun.security.auth.module.Krb5LoginModule.login(Krb5LoginModule.java:617) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at javax.security.auth.login.LoginContext.invoke(LoginContext.java:755) at javax.security.auth.login.LoginContext.access$000(LoginContext.java:195) at javax.security.auth.login.LoginContext$4.run(LoginContext.java:682) at javax.security.auth.login.LoginContext$4.run(LoginContext.java:680) at java.security.AccessController.doPrivileged(Native Method) at javax.security.auth.login.LoginContext.invokePriv(LoginContext.java:680) at javax.security.auth.login.LoginContext.login(LoginContext.java:587) at org.apache.hadoop.security.UserGroupInformation$HadoopLoginContext.login(UserGroupInformation.java:2087) at org.apache.hadoop.security.UserGroupInformation.doSubjectLogin(UserGroupInformation.java:1998) ... 32 more Caused by: KrbException: Integrity check on decrypted field failed (31) - PREAUTH_FAILED at sun.security.krb5.KrbAsRep.<init>(KrbAsRep.java:82) 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:776) ... 46 more Caused by: KrbException: Identifier doesn't match expected value (906) at sun.security.krb5.internal.KDCRep.init(KDCRep.java:140) at sun.security.krb5.internal.ASRep.init(ASRep.java:64) at sun.security.krb5.internal.ASRep.<init>(ASRep.java:59) at sun.security.krb5.KrbAsRep.<init>(KrbAsRep.java:60) ... 49 more

 

Issue Links

• is related to: HDFS-14609 RBF: Security should use common AuthenticationFilter