zookeeper-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "ASF GitHub Bot (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (ZOOKEEPER-1534) Zookeeper server do not send Sal authentication failure notification to the client
Date Wed, 14 Feb 2018 20:47:03 GMT

    [ https://issues.apache.org/jira/browse/ZOOKEEPER-1534?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16364755#comment-16364755
] 

ASF GitHub Bot commented on ZOOKEEPER-1534:
-------------------------------------------

Github user eolivelli commented on a diff in the pull request:

    https://github.com/apache/zookeeper/pull/457#discussion_r168304302
  
    --- Diff: src/java/test/org/apache/zookeeper/test/WatcherAuthTest.java ---
    @@ -0,0 +1,84 @@
    +package org.apache.zookeeper.test;
    +
    +import org.apache.zookeeper.WatchedEvent;
    +import org.apache.zookeeper.ZooKeeper;
    +import org.apache.zookeeper.client.ZKClientConfig;
    +import org.junit.Assert;
    +import org.junit.Before;
    +import org.junit.Ignore;
    +import org.junit.Test;
    +import org.slf4j.Logger;
    +import org.slf4j.LoggerFactory;
    +
    +import java.io.File;
    +import java.io.FileWriter;
    +import java.io.IOException;
    +import java.util.concurrent.LinkedBlockingQueue;
    +
    +import static org.apache.zookeeper.test.ClientBase.createTmpDir;
    +
    +public class WatcherAuthTest {
    --- End diff --
    
    I am sorry, I can't find in this test where ate we starting the server


> Zookeeper server do not send Sal authentication failure notification to the client
> ----------------------------------------------------------------------------------
>
>                 Key: ZOOKEEPER-1534
>                 URL: https://issues.apache.org/jira/browse/ZOOKEEPER-1534
>             Project: ZooKeeper
>          Issue Type: Bug
>          Components: server
>    Affects Versions: 3.4.3
>         Environment: Windows 7. Zookeeper 3.4.3 Curator 1.1.15  Java 1.6
>            Reporter: Tally Tsabary
>            Priority: Major
>
> Server side: zookeeper 3.4.3 with patch ZOOKEEPER-1437.patch 22/Jun/12 00:24
> Client side: java, Curator 1.1.15, zookeeper 3.4.3 with patch ZOOKEEPER-1437.patch 22/Jun/12
00:24
> Environment configured to use Sasl authentication.
> While the authenticatiion is successful, everything works fine.
> In case of authentication failue, it seems that the zk server catch the SaslException
and close the socket without sending any additional notification to the client, so despite
the client has an implementation to handle Sasl authentication failure, it is never used…
>  
> Details:
> =========
>  
>  
> zk server log:
> {noformat}
> 2012-08-10 11:00:46,730 [myid:] - INFO  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxnFactory@213]
- Accepted socket connection from /127.0.0.1:50208
> 2012-08-10 11:00:46,731 [myid:] - DEBUG [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:ZooKeeperServer@780]
- Session establishment request from client /127.0.0.1:50208 client's lastZxid is 0x0
> 2012-08-10 11:00:46,731 [myid:] - INFO  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:ZooKeeperServer@838]
- Client attempting to establish new session at /127.0.0.1:50208
> 2012-08-10 11:00:46,733 [myid:] - DEBUG [SyncThread:0:FinalRequestProcessor@88] - Processing
request:: sessionid:0x1390fd2ee630004 type:createSession cxid:0x0 zxid:0x26b txntype:-10 reqpath:n/a
> 2012-08-10 11:00:46,733 [myid:] - DEBUG [SyncThread:0:FinalRequestProcessor@160] - sessionid:0x1390fd2ee630004
type:createSession cxid:0x0 zxid:0x26b txntype:-10 reqpath:n/a
> 2012-08-10 11:00:46,734 [myid:] - INFO  [SyncThread:0:ZooKeeperServer@604] - Established
session 0x1390fd2ee630004 with negotiated timeout 40000 for client /127.0.0.1:50208
> 2012-08-10 11:00:46,736 [myid:] - DEBUG [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:ZooKeeperServer@919]
- Responding to client SASL token.
> 2012-08-10 11:00:46,736 [myid:] - DEBUG [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:ZooKeeperServer@923]
- Size of client SASL token: 0
> 2012-08-10 11:00:46,736 [myid:] - DEBUG [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:ZooKeeperServer@954]
- Size of server SASL response: 101
> 2012-08-10 11:00:46,740 [myid:] - DEBUG [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:ZooKeeperServer@919]
- Responding to client SASL token.
> 2012-08-10 11:00:46,741 [myid:] - DEBUG [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:ZooKeeperServer@923]
- Size of client SASL token: 272
> 2012-08-10 11:00:46,741 [myid:] - DEBUG [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:SaslServerCallbackHandler@106]
- client supplied realm: zk-sasl-md5
> 2012-08-10 11:00:46,741 [myid:] - WARN  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:ZooKeeperServer@939]
- Client failed to SASL authenticate: javax.security.sasl.SaslException: DIGEST-MD5: digest
response format violation. Mismatched response.
> 2012-08-10 11:00:46,742 [myid:] - WARN  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:ZooKeeperServer@945]
- Closing client connection due to SASL authentication failure.
> 2012-08-10 11:00:46,742 [myid:] - INFO  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1000]
- Closed socket connection for client /127.0.0.1:50208 which had sessionid 0x1390fd2ee630004
> 2012-08-10 11:00:46,743 [myid:] - ERROR [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@180]
- Unexpected Exception: 
> java.nio.channels.CancelledKeyException
>                at sun.nio.ch.SelectionKeyImpl.ensureValid(SelectionKeyImpl.java:55)
>                at sun.nio.ch.SelectionKeyImpl.interestOps(SelectionKeyImpl.java:59)
>                at org.apache.zookeeper.server.NIOServerCnxn.sendBuffer(NIOServerCnxn.java:153)
>                at org.apache.zookeeper.server.NIOServerCnxn.sendResponse(NIOServerCnxn.java:1075)
>                at org.apache.zookeeper.server.ZooKeeperServer.processPacket(ZooKeeperServer.java:906)
>                at org.apache.zookeeper.server.NIOServerCnxn.readRequest(NIOServerCnxn.java:365)
>                at org.apache.zookeeper.server.NIOServerCnxn.readPayload(NIOServerCnxn.java:202)
>                at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:236)
>                at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:224)
>                at java.lang.Thread.run(Thread.java:662)
>  {noformat}
>  
> At the corresponding source: org.apache.zookeeper.server.ZooKeeperServer
>  
> {noformat}
> private Record processSasl(ByteBuffer incomingBuffer, ServerCnxn cnxn) throws IOException
{
>         LOG.debug("Responding to client SASL token.");
>         GetSASLRequest clientTokenRecord = new GetSASLRequest();
>         ByteBufferInputStream.byteBuffer2Record(incomingBuffer,clientTokenRecord);
>         byte[] clientToken = clientTokenRecord.getToken();
>         LOG.debug("Size of client SASL token: " + clientToken.length);
>         byte[] responseToken = null;
>         try {
>             ZooKeeperSaslServer saslServer  = cnxn.zooKeeperSaslServer;
>             try {
>                 // note that clientToken might be empty (clientToken.length == 0):
>                 // if using the DIGEST-MD5 mechanism, clientToken will be empty at the
beginning of the
>                 // SASL negotiation process.
>                 responseToken = saslServer.evaluateResponse(clientToken);
>                 if (saslServer.isComplete() == true) {
>                     String authorizationID = saslServer.getAuthorizationID();
>                     LOG.info("adding SASL authorization for authorizationID: " + authorizationID);
>                     cnxn.addAuthInfo(new Id("sasl",authorizationID));
>                 }
>             }
>             catch (SaslException e) {
>                 LOG.warn("Client failed to SASL authenticate: " + e);
>                 if ((System.getProperty("zookeeper.allowSaslFailedClients") != null)
>                   &&
>                   (System.getProperty("zookeeper.allowSaslFailedClients").equals("true")))
{
>                     LOG.warn("Maintaining client connection despite SASL authentication
failure.");
>                 } else {
>                     LOG.warn("Closing client connection due to SASL authentication failure.");
>                     cnxn.close();   Tally: at this stage the socket is closed without
sending any notification to the client
>                 }
>             }
>         }
>         catch (NullPointerException e) {
>             LOG.error("cnxn.saslServer is null: cnxn object did not initialize its saslServer
properly.");
>         }
>         if (responseToken != null) {
>             LOG.debug("Size of server SASL response: " + responseToken.length);
>         }
>         // wrap SASL response token to client inside a Response object.
>         return new SetSASLResponse(responseToken);
>     }
> {noformat}
>  
>  
> The client log shows that the client identified the socket closer and just retry to connect
as if the zk server just went down..
> {noformat}
> [10-Aug-2012 11:00:44.558 IST] INFO <org.apache.zookeeper.ClientCnxn$SendThread>
Opening socket connection to server 127.0.0.1/127.0.0.1:2181
> [10-Aug-2012 11:00:44.559 IST] INFO <org.apache.zookeeper.client.ZooKeeperSaslClient>
Found Login Context section 'Client': will use it to attempt to SASL-authenticate.
> [10-Aug-2012 11:00:44.560 IST] INFO <org.apache.zookeeper.client.ZooKeeperSaslClient>
Client will use DIGEST-MD5 as SASL mechanism.
> [10-Aug-2012 11:00:44.561 IST] INFO <org.apache.zookeeper.ClientCnxn$SendThread>
Socket connection established to 127.0.0.1/127.0.0.1:2181, initiating session
> [10-Aug-2012 11:00:44.563 IST] DEBUG <org.apache.zookeeper.ClientCnxn$SendThread>
Session establishment request sent on 127.0.0.1/127.0.0.1:2181
> [10-Aug-2012 11:00:44.564 IST] DEBUG <org.apache.zookeeper.ClientCnxnSocketNIO>
deferring non-priming packet: clientPath:null serverPath:null finished:false header:: 0,3
 replyHeader:: 0,0,0  request:: '/dev,F  response::  until SASL authentication completes.
> [10-Aug-2012 11:00:44.566 IST] DEBUG <org.apache.zookeeper.ClientCnxnSocketNIO>
deferring non-priming packet: clientPath:/ serverPath:/ finished:false header:: 0,9  replyHeader::
0,0,0  request:: '/  response::  until SASL authentication completes.
> [10-Aug-2012 11:00:44.568 IST] INFO <org.apache.zookeeper.ClientCnxn$SendThread>
Session establishment complete on server 127.0.0.1/127.0.0.1:2181, sessionid = 0x1390fd2ee630003,
negotiated timeout = 40000
> [10-Aug-2012 11:00:44.569 IST] INFO <com.netflix.curator.framework.state.ConnectionStateManager>
State change: RECONNECTED
> [10-Aug-2012 11:00:44.569 IST] DEBUG <org.apache.zookeeper.ClientCnxnSocketNIO>
deferring non-priming packet: clientPath:null serverPath:null finished:false header:: 0,3
 replyHeader:: 0,0,0  request:: '/dev,F  response::  until SASL authentication completes.
> [10-Aug-2012 11:00:44.572 IST] DEBUG <org.apache.zookeeper.ClientCnxnSocketNIO>
deferring non-priming packet: clientPath:/ serverPath:/ finished:false header:: 0,9  replyHeader::
0,0,0  request:: '/  response::  until SASL authentication completes.
> [10-Aug-2012 11:00:44.574 IST] DEBUG <org.apache.zookeeper.ClientCnxnSocketNIO>
deferring non-priming packet: clientPath:null serverPath:null finished:false header:: 0,3
 replyHeader:: 0,0,0  request:: '/dev,F  response::  until SASL authentication completes.
> [10-Aug-2012 11:00:44.576 IST] DEBUG <org.apache.zookeeper.ClientCnxnSocketNIO>
deferring non-priming packet: clientPath:/ serverPath:/ finished:false header:: 0,9  replyHeader::
0,0,0  request:: '/  response::  until SASL authentication completes.
> [10-Aug-2012 11:00:44.578 IST] DEBUG <org.apache.zookeeper.client.ZooKeeperSaslClient>
ClientCnxn:sendSaslPacket:length=0
> [10-Aug-2012 11:00:44.579 IST] DEBUG <org.apache.zookeeper.ClientCnxnSocketNIO>
deferring non-priming packet: clientPath:null serverPath:null finished:false header:: 0,3
 replyHeader:: 0,0,0  request:: '/dev,F  response::  until SASL authentication completes.
> [10-Aug-2012 11:00:44.581 IST] DEBUG <org.apache.zookeeper.ClientCnxnSocketNIO>
deferring non-priming packet: clientPath:/ serverPath:/ finished:false header:: 0,9  replyHeader::
0,0,0  request:: '/  response::  until SASL authentication completes.
> [10-Aug-2012 11:00:44.583 IST] DEBUG <org.apache.zookeeper.ClientCnxnSocketNIO>
deferring non-priming packet: clientPath:/ serverPath:/ finished:false header:: 0,9  replyHeader::
0,0,0  request:: '/  response::  until SASL authentication completes.
> [10-Aug-2012 11:00:44.585 IST] DEBUG <org.apache.zookeeper.ClientCnxnSocketNIO>
deferring non-priming packet: clientPath:null serverPath:null finished:false header:: 0,3
 replyHeader:: 0,0,0  request:: '/dev,F  response::  until SASL authentication completes.
> [10-Aug-2012 11:00:44.587 IST] DEBUG <org.apache.zookeeper.ClientCnxnSocketNIO>
deferring non-priming packet: clientPath:/ serverPath:/ finished:false header:: 0,9  replyHeader::
0,0,0  request:: '/  response::  until SASL authentication completes.
> [10-Aug-2012 11:00:44.589 IST] DEBUG <org.apache.zookeeper.ClientCnxnSocketNIO>
deferring non-priming packet: clientPath:/ serverPath:/ finished:false header:: 0,9  replyHeader::
0,0,0  request:: '/  response::  until SASL authentication completes.
> [10-Aug-2012 11:00:44.591 IST] DEBUG <org.apache.zookeeper.client.ZooKeeperSaslClient$2>
saslClient.evaluateChallenge(len=101)
> [10-Aug-2012 11:00:44.592 IST] DEBUG <org.apache.zookeeper.client.ZooKeeperSaslClient>
ClientCnxn:sendSaslPacket:length=272
> [10-Aug-2012 11:00:44.593 IST] DEBUG <org.apache.zookeeper.ClientCnxnSocketNIO>
deferring non-priming packet: clientPath:null serverPath:null finished:false header:: 0,3
 replyHeader:: 0,0,0  request:: '/dev,F  response::  until SASL authentication completes.
> [10-Aug-2012 11:00:44.596 IST] DEBUG <org.apache.zookeeper.ClientCnxnSocketNIO>
deferring non-priming packet: clientPath:/ serverPath:/ finished:false header:: 0,9  replyHeader::
0,0,0  request:: '/  response::  until SASL authentication completes.
> [10-Aug-2012 11:00:44.598 IST] DEBUG <org.apache.zookeeper.ClientCnxnSocketNIO>
deferring non-priming packet: clientPath:/ serverPath:/ finished:false header:: 0,9  replyHeader::
0,0,0  request:: '/  response::  until SASL authentication completes.
> [10-Aug-2012 11:00:44.600 IST] INFO <org.apache.zookeeper.ClientCnxn$SendThread>
Unable to read additional data from server sessionid 0x1390fd2ee630003, likely server has
closed socket, closing socket connection and attempting reconnect
> [10-Aug-2012 11:00:44.701 IST] ERROR <com.netflix.curator.framework.imps.CuratorFrameworkImpl>
Background operation retry gave up
> org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss
>                at org.apache.zookeeper.KeeperException.create(KeeperException.java:99)
>                at com.netflix.curator.framework.imps.CuratorFrameworkImpl.processBackgroundOperation(CuratorFrameworkImpl.java:438)
>                at com.netflix.curator.framework.imps.BackgroundSyncImpl$1.processResult(BackgroundSyncImpl.java:49)
>                at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:606)
>                at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
> [10-Aug-2012 11:00:44.706 IST] INFO <com.netflix.curator.framework.state.ConnectionStateManager>
State change: LOST
> [10-Aug-2012 11:00:44.708 IST] WARN <com.netflix.curator.framework.state.ConnectionStateManager>
ConnectionStateManager queue full - dropping events to make room
> [10-Aug-2012 11:00:44.710 IST] INFO <com.netflix.curator.framework.state.ConnectionStateManager>
State change: SUSPENDED
> {noformat}



--
This message was sent by Atlassian JIRA
(v7.6.3#76005)

Mime
View raw message