You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@pulsar.apache.org by GitBox <gi...@apache.org> on 2021/12/01 06:36:57 UTC
[GitHub] [pulsar] aerfalwl opened a new issue #13060: ERROR Failed to evaluate client token: javax.security.sasl.SaslException: Final handshake step failed
aerfalwl opened a new issue #13060:
URL: https://github.com/apache/pulsar/issues/13060
**Describe the bug**
1. The version of puslar cluster is 2.7.0.
2. Cluster uses kerberos for authentication.
3. When use tools pulsar-admin to list topics under public/default, pulsar-admin shows the following exceptions:
```shell
org.apache.pulsar.client.impl.auth.PulsarSaslClient - Using JAAS/SASL/GSSAPI auth to connect to server Principal broker/host12,
null
Reason: java.util.concurrent.TimeoutException
```
and the broker shows the following exceptions:
```shell
20:47:18.326 [pulsar-web-42-1] ERROR org.apache.pulsar.broker.authentication.PulsarSaslServer - response: Failed to evaluate client token:
javax.security.sasl.SaslException: Final handshake step failed
at com.sun.security.sasl.gsskerb.GssKrb5Server.doHandshake2(GssKrb5Server.java:331) ~[?:1.8.0_271]
at com.sun.security.sasl.gsskerb.GssKrb5Server.evaluateResponse(GssKrb5Server.java:161) ~[?:1.8.0_271]
at org.apache.pulsar.broker.authentication.PulsarSaslServer.response(PulsarSaslServer.java:147) ~[org.apache.pulsar-pulsar-broker-auth-sasl-2.7.0.jar:2.7.0]
at org.apache.pulsar.broker.authentication.SaslAuthenticationDataSource.authenticate(SaslAuthenticationDataSource.java:45) ~[org.apache.pulsar-pulsar-broker-auth-sasl-2.7.0.jar:2.7.0]
at org.apache.pulsar.broker.authentication.SaslAuthenticationState.authenticate(SaslAuthenticationState.java:70) ~[org.apache.pulsar-pulsar-broker-auth-sasl-2.7.0.jar:2.7.0]
at org.apache.pulsar.broker.authentication.AuthenticationProviderSasl.authenticateHttpRequest(AuthenticationProviderSasl.java:264) ~[org.apache.pulsar-pulsar-broker-auth-sasl-2.7.0.jar:2.7.0]
at org.apache.pulsar.broker.web.AuthenticationFilter.doFilter(AuthenticationFilter.java:88) ~[org.apache.pulsar-pulsar-broker-common-2.7.0.jar:2.7.0]
at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193) ~[org.eclipse.jetty-jetty-servlet-9.4.33.v20201020.jar:9.4.33.v20201020]
at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1609) ~[org.eclipse.jetty-jetty-servlet-9.4.33.v20201020.jar:9.4.33.v20201020]
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:561) ~[org.eclipse.jetty-jetty-servlet-9.4.33.v20201020.jar:9.4.33.v20201020]
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) ~[org.eclipse.jetty-jetty-server-9.4.33.v20201020.jar:9.4.33.v20201020]
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1612) ~[org.eclipse.jetty-jetty-server-9.4.33.v20201020.jar:9.4.33.v20201020]
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) ~[org.eclipse.jetty-jetty-server-9.4.33.v20201020.jar:9.4.33.v20201020]
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1434) ~[org.eclipse.jetty-jetty-server-9.4.33.v20201020.jar:9.4.33.v20201020]
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188) ~[org.eclipse.jetty-jetty-server-9.4.33.v20201020.jar:9.4.33.v20201020]
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:501) ~[org.eclipse.jetty-jetty-servlet-9.4.33.v20201020.jar:9.4.33.v20201020]
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1582) ~[org.eclipse.jetty-jetty-server-9.4.33.v20201020.jar:9.4.33.v20201020]
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186) ~[org.eclipse.jetty-jetty-server-9.4.33.v20201020.jar:9.4.33.v20201020]
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1349) ~[org.eclipse.jetty-jetty-server-9.4.33.v20201020.jar:9.4.33.v20201020]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) ~[org.eclipse.jetty-jetty-server-9.4.33.v20201020.jar:9.4.33.v20201020]
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:234) ~[org.eclipse.jetty-jetty-server-9.4.33.v20201020.jar:9.4.33.v20201020]
at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:146) ~[org.eclipse.jetty-jetty-server-9.4.33.v20201020.jar:9.4.33.v20201020]
at org.eclipse.jetty.server.handler.StatisticsHandler.handle(StatisticsHandler.java:179) ~[org.eclipse.jetty-jetty-server-9.4.33.v20201020.jar:9.4.33.v20201020]
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) ~[org.eclipse.jetty-jetty-server-9.4.33.v20201020.jar:9.4.33.v20201020]
at org.eclipse.jetty.server.Server.handle(Server.java:516) ~[org.eclipse.jetty-jetty-server-9.4.33.v20201020.jar:9.4.33.v20201020]
at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:383) ~[org.eclipse.jetty-jetty-server-9.4.33.v20201020.jar:9.4.33.v20201020]
at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:556) [org.eclipse.jetty-jetty-server-9.4.33.v20201020.jar:9.4.33.v20201020]
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:375) [org.eclipse.jetty-jetty-server-9.4.33.v20201020.jar:9.4.33.v20201020]
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:273) [org.eclipse.jetty-jetty-server-9.4.33.v20201020.jar:9.4.33.v20201020]
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) [org.eclipse.jetty-jetty-io-9.4.33.v20201020.jar:9.4.33.v20201020]
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) [org.eclipse.jetty-jetty-io-9.4.33.v20201020.jar:9.4.33.v20201020]
at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104) [org.eclipse.jetty-jetty-io-9.4.33.v20201020.jar:9.4.33.v20201020]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336) [org.eclipse.jetty-jetty-util-9.4.33.v20201020.jar:9.4.33.v20201020]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313) [org.eclipse.jetty-jetty-util-9.4.33.v20201020.jar:9.4.33.v20201020]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171) [org.eclipse.jetty-jetty-util-9.4.33.v20201020.jar:9.4.33.v20201020]
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129) [org.eclipse.jetty-jetty-util-9.4.33.v20201020.jar:9.4.33.v20201020]
at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:375) [org.eclipse.jetty-jetty-util-9.4.33.v20201020.jar:9.4.33.v20201020]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_271]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_271]
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [io.netty-netty-common-4.1.51.Final.jar:4.1.51.Final]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_271]
Caused by: org.ietf.jgss.GSSException: Defective token detected (Mechanism level: Kerberos GSS-API Mechanism Token:Defective Token ID!)
at sun.security.jgss.krb5.MessageToken_v2$MessageTokenHeader.<init>(MessageToken_v2.java:561) ~[?:1.8.0_271]
at sun.security.jgss.krb5.MessageToken_v2.<init>(MessageToken_v2.java:194) ~[?:1.8.0_271]
at sun.security.jgss.krb5.MessageToken_v2.<init>(MessageToken_v2.java:165) ~[?:1.8.0_271]
at sun.security.jgss.krb5.WrapToken_v2.<init>(WrapToken_v2.java:71) ~[?:1.8.0_271]
at sun.security.jgss.krb5.Krb5Context.unwrap(Krb5Context.java:1058) ~[?:1.8.0_271]
at sun.security.jgss.GSSContextImpl.unwrap(GSSContextImpl.java:403) ~[?:1.8.0_271]
at com.sun.security.sasl.gsskerb.GssKrb5Server.doHandshake2(GssKrb5Server.java:254) ~[?:1.8.0_271]
... 40 more
20:47:18.333 [pulsar-web-42-1] WARN org.apache.pulsar.broker.web.AuthenticationFilter - [22.21.8.34] Failed to authenticate HTTP request: Final handshake step failed
20:47:18.334 [pulsar-web-42-1] INFO org.eclipse.jetty.server.RequestLog - 22.21.8.34 - - [29/Nov/2021:20:47:18 +0800] "GET /admin/v2/non-persistent/public/default/0x00000000_0x10000000 HTTP/1.1" 401 194 "-" "Jersey/2.31 (HttpUrlConnection 1.8.0_271)" 9
20:47:18.336 [jersey-client-async-executor-6] WARN org.apache.pulsar.client.impl.auth.AuthenticationSasl - Failed to perform http request
javax.ws.rs.ProcessingException: java.lang.NullPointerException
at org.glassfish.jersey.client.ClientRuntime.processFailure(ClientRuntime.java:247) ~[org.glassfish.jersey.core-jersey-client-2.31.jar:?]
at org.glassfish.jersey.client.ClientRuntime.processFailure(ClientRuntime.java:242) ~[org.glassfish.jersey.core-jersey-client-2.31.jar:?]
at org.glassfish.jersey.client.ClientRuntime.access$100(ClientRuntime.java:62) ~[org.glassfish.jersey.core-jersey-client-2.31.jar:?]
at org.glassfish.jersey.client.ClientRuntime$2.lambda$failure$1(ClientRuntime.java:178) ~[org.glassfish.jersey.core-jersey-client-2.31.jar:?]
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:248) ~[org.glassfish.jersey.core-jersey-common-2.31.jar:?]
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:244) ~[org.glassfish.jersey.core-jersey-common-2.31.jar:?]
at org.glassfish.jersey.internal.Errors.process(Errors.java:292) ~[org.glassfish.jersey.core-jersey-common-2.31.jar:?]
at org.glassfish.jersey.internal.Errors.process(Errors.java:274) ~[org.glassfish.jersey.core-jersey-common-2.31.jar:?]
at org.glassfish.jersey.internal.Errors.process(Errors.java:244) ~[org.glassfish.jersey.core-jersey-common-2.31.jar:?]
at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:288) ~[org.glassfish.jersey.core-jersey-common-2.31.jar:?]
at org.glassfish.jersey.client.ClientRuntime$2.failure(ClientRuntime.java:178) ~[org.glassfish.jersey.core-jersey-client-2.31.jar:?]
at org.glassfish.jersey.client.internal.HttpUrlConnector.apply(HttpUrlConnector.java:273) ~[org.glassfish.jersey.core-jersey-client-2.31.jar:?]
at org.glassfish.jersey.client.ClientRuntime.lambda$null$6(ClientRuntime.java:182) ~[org.glassfish.jersey.core-jersey-client-2.31.jar:?]
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:248) ~[org.glassfish.jersey.core-jersey-common-2.31.jar:?]
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:244) ~[org.glassfish.jersey.core-jersey-common-2.31.jar:?]
at org.glassfish.jersey.internal.Errors.process(Errors.java:292) ~[org.glassfish.jersey.core-jersey-common-2.31.jar:?]
at org.glassfish.jersey.internal.Errors.process(Errors.java:274) ~[org.glassfish.jersey.core-jersey-common-2.31.jar:?]
at org.glassfish.jersey.internal.Errors.process(Errors.java:244) ~[org.glassfish.jersey.core-jersey-common-2.31.jar:?]
at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:288) ~[org.glassfish.jersey.core-jersey-common-2.31.jar:?]
at org.glassfish.jersey.client.ClientRuntime.lambda$createRunnableForAsyncProcessing$7(ClientRuntime.java:156) ~[org.glassfish.jersey.core-jersey-client-2.31.jar:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_271]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_271]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_271]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_271]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_271]
Caused by: java.lang.NullPointerException
at java.util.Base64$Decoder.decode(Base64.java:549) ~[?:1.8.0_271]
at org.apache.pulsar.client.impl.auth.AuthenticationSasl.newRequestHeader(AuthenticationSasl.java:269) ~[org.apache.pulsar-pulsar-client-auth-sasl-2.7.0.jar:2.7.0]
at org.apache.pulsar.client.impl.auth.AuthenticationSasl.newRequestBuilder(AuthenticationSasl.java:198) ~[org.apache.pulsar-pulsar-client-auth-sasl-2.7.0.jar:2.7.0]
at org.apache.pulsar.client.impl.auth.AuthenticationSasl.authenticationStage(AuthenticationSasl.java:307) ~[org.apache.pulsar-pulsar-client-auth-sasl-2.7.0.jar:2.7.0]
at org.apache.pulsar.client.impl.auth.AuthenticationSasl$1.completed(AuthenticationSasl.java:313) ~[org.apache.pulsar-pulsar-client-auth-sasl-2.7.0.jar:2.7.0]
at org.apache.pulsar.client.impl.auth.AuthenticationSasl$1.completed(AuthenticationSasl.java:308) ~[org.apache.pulsar-pulsar-client-auth-sasl-2.7.0.jar:2.7.0]
at org.glassfish.jersey.client.JerseyInvocation$1.completed(JerseyInvocation.java:814) ~[org.glassfish.jersey.core-jersey-client-2.31.jar:?]
at org.glassfish.jersey.client.ClientRuntime.processResponse(ClientRuntime.java:229) ~[org.glassfish.jersey.core-jersey-client-2.31.jar:?]
at org.glassfish.jersey.client.ClientRuntime.access$200(ClientRuntime.java:62) ~[org.glassfish.jersey.core-jersey-client-2.31.jar:?]
at org.glassfish.jersey.client.ClientRuntime$2.lambda$response$0(ClientRuntime.java:173) ~[org.glassfish.jersey.core-jersey-client-2.31.jar:?]
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:248) ~[org.glassfish.jersey.core-jersey-common-2.31.jar:?]
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:244) ~[org.glassfish.jersey.core-jersey-common-2.31.jar:?]
at org.glassfish.jersey.internal.Errors.process(Errors.java:292) ~[org.glassfish.jersey.core-jersey-common-2.31.jar:?]
at org.glassfish.jersey.internal.Errors.process(Errors.java:274) ~[org.glassfish.jersey.core-jersey-common-2.31.jar:?]
at org.glassfish.jersey.internal.Errors.process(Errors.java:244) ~[org.glassfish.jersey.core-jersey-common-2.31.jar:?]
at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:288) ~[org.glassfish.jersey.core-jersey-common-2.31.jar:?]
at org.glassfish.jersey.client.ClientRuntime$2.response(ClientRuntime.java:173) ~[org.glassfish.jersey.core-jersey-client-2.31.jar:?]
at org.glassfish.jersey.client.internal.HttpUrlConnector.apply(HttpUrlConnector.java:269) ~[org.glassfish.jersey.core-jersey-client-2.31.jar:?]
... 13 more
```
**To Reproduce**
Steps to reproduce the behavior:
1. execute the following command:
```shell
./bin/pulsar-admin topics list public/default
```
2. Wait for one hour (which is the token expired time hardcode in the broker), and execute the command in step 1 again.
**Expected behavior**
The command list all the topics without error.
**Possiable Reason**
1. When the client make a request to the server, there is a two-stage-handshake authentication, after which the server will generate a token to client, and then the client could commenicate with the server with given token.
2. When the token expired, the client need to do the two-stage-authentication again.
**Debug**
1. when use linux tools tcpdump to capture http message at port 8080. I find there is something unnornal at the second handshake stage of the authentication.
2. The following picture is captured from file "pulsar-client-auth-sasl\src\main\java\org\apache\pulsar\client\impl\auth\AuthenticationSasl.java"
3. From the picture, we can know that, when the token expired, it will redo the two-stage-handshake authentication, and re-assignment the authData. But the authData is not changed out of the functon(in the caller of the function). In the other word, the authData is correct in the first-stage-handshake, but incorrect in the second-stage-handshake.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] github-actions[bot] commented on issue #13060: ERROR Failed to evaluate client token: javax.security.sasl.SaslException: Final handshake step failed
Posted by GitBox <gi...@apache.org>.
github-actions[bot] commented on issue #13060:
URL: https://github.com/apache/pulsar/issues/13060#issuecomment-1051440563
The issue had no activity for 30 days, mark with Stale label.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org