[
https://issues.apache.org/jira/browse/HDFS-14461?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16887266#comment-16887266
]
Eric Yang commented on HDFS-14461:
----------------------------------
[~hexiaoqiao] This is not related to HADOOP-16354 or HADOOP-16314. The error
message indicate there is a race condition between MiniKdc startup and
router.start(). The master key for MiniKdc has not been written yet in the
setup() method, and the router is already attempting to start up and login to
Kerberos.
If I put a one second sleep after
{code}
Configuration conf = SecurityConfUtil.initSecurity();
{code}
The router server can start properly. However, the test failed with:
{code}
[ERROR]
testGetDelegationToken(org.apache.hadoop.hdfs.server.federation.security.TestRouterHttpDelegationToken)
Time elapsed: 1.551 s <<< ERROR!
java.io.IOException: Security enabled but user not authenticated by filter
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at
sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
at
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at
org.apache.hadoop.ipc.RemoteException.instantiateException(RemoteException.java:121)
at
org.apache.hadoop.ipc.RemoteException.unwrapRemoteException(RemoteException.java:110)
at
org.apache.hadoop.hdfs.web.WebHdfsFileSystem.toIOException(WebHdfsFileSystem.java:551)
at
org.apache.hadoop.hdfs.web.WebHdfsFileSystem.access$800(WebHdfsFileSystem.java:136)
at
org.apache.hadoop.hdfs.web.WebHdfsFileSystem$AbstractRunner.shouldRetry(WebHdfsFileSystem.java:898)
at
org.apache.hadoop.hdfs.web.WebHdfsFileSystem$AbstractRunner.runWithRetry(WebHdfsFileSystem.java:864)
at
org.apache.hadoop.hdfs.web.WebHdfsFileSystem$AbstractRunner.access$100(WebHdfsFileSystem.java:663)
at
org.apache.hadoop.hdfs.web.WebHdfsFileSystem$AbstractRunner$1.run(WebHdfsFileSystem.java:701)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAs(Subject.java:422)
at
org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1891)
at
org.apache.hadoop.hdfs.web.WebHdfsFileSystem$AbstractRunner.run(WebHdfsFileSystem.java:697)
at
org.apache.hadoop.hdfs.web.WebHdfsFileSystem.getDelegationToken(WebHdfsFileSystem.java:1749)
at
org.apache.hadoop.hdfs.server.federation.security.TestRouterHttpDelegationToken.testGetDelegationToken(TestRouterHttpDelegationToken.java:120)
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.InvokeMethod.evaluate(InvokeMethod.java:17)
at
org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
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.ipc.RemoteException(java.io.IOException): Security
enabled but user not authenticated by filter
at
org.apache.hadoop.hdfs.web.WebHdfsFileSystem.validateResponse(WebHdfsFileSystem.java:526)
at
org.apache.hadoop.hdfs.web.WebHdfsFileSystem.access$200(WebHdfsFileSystem.java:136)
at
org.apache.hadoop.hdfs.web.WebHdfsFileSystem$AbstractRunner.connect(WebHdfsFileSystem.java:760)
at
org.apache.hadoop.hdfs.web.WebHdfsFileSystem$AbstractRunner.runWithRetry(WebHdfsFileSystem.java:835)
... 35 more
{code}
If I am reading the code correctly, there is no configuration reference to
SPNEGO principal or keytab. Hadoop code will fall back to default:
hadoop.http.authentication.kerberos.principal=HTTP/_HOST@LOCALHOST
HDFS fallback to dfs.web.authentication.kerberos.keytab for getting SPNEGO
keytab.
dfs.web.authentication.kerberos.keytab needs to be configured in the test case
to refer to test.keytab to address this issue to ensure web interface is
secured by SPNEGO keytab.
Without configuring those, the service is running without a SPNEGO principal to
authenticate the incoming request. Hence, the failure is expected.
> RBF: Fix intermittently failing kerberos related unit test
> ----------------------------------------------------------
>
> Key: HDFS-14461
> URL: https://issues.apache.org/jira/browse/HDFS-14461
> Project: Hadoop HDFS
> Issue Type: Sub-task
> Reporter: CR Hota
> Assignee: Fengnan Li
> Priority: Major
>
> TestRouterHttpDelegationToken#testGetDelegationToken fails intermittently. It
> may be due to some race condition before using the keytab that's created for
> testing.
>
> {code:java}
> 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/[email protected] 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/[email protected] 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/[email protected] 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/[email protected] 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
> {code}
--
This message was sent by Atlassian JIRA
(v7.6.14#76016)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
