[jira] [Updated] (ZOOKEEPER-2230) Connections fo ZooKeeper server becomes slow over time with native GSSAPI
[
https://issues.apache.org/jira/browse/ZOOKEEPER-2230?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Deepesh Reja updated ZOOKEEPER-2230:
Release Note: (was: Add credential to private credential set only once)
> Connections fo ZooKeeper server becomes slow over time with native GSSAPI
> -
>
> Key: ZOOKEEPER-2230
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-2230
> Project: ZooKeeper
> Issue Type: Bug
> Components: server
>Affects Versions: 3.4.6, 3.4.7, 3.4.8
> Environment: OS: RHEL6
> Java: 1.8.0_40
> Configuration:
> java.env:
> {noformat}
> SERVER_JVMFLAGS="$SERVER_JVMFLAGS -Xmx5120m"
> SERVER_JVMFLAGS="$SERVER_JVMFLAGS
> -Djava.security.auth.login.config=/local/apps/zookeeper-test1/conf/jaas-server.conf"
> SERVER_JVMFLAGS="$SERVER_JVMFLAGS -Dsun.security.jgss.native=true"
> {noformat}
> jaas-server.conf:
> {noformat}
> Server {
> com.sun.security.auth.module.Krb5LoginModule required
> useKeyTab=true
> isInitiator=false
> principal="zookeeper/@";
> };
> {noformat}
> Process environment:
> {noformat}
> KRB5_KTNAME=/local/apps/zookeeper-test1/conf/keytab
> ZOO_LOG_DIR=/local/apps/zookeeper-test1/log
> ZOOCFGDIR=/local/apps/zookeeper-test1/conf
> {noformat}
>Reporter: Deepesh Reja
>Assignee: Enis Soztutar
> Labels: patch
> Fix For: 3.4.6, 3.4.7, 3.4.8
>
>
> ZooKeeper server becomes slow over time when native GSSAPI is used. The
> connection to the server starts taking upto 10 seconds.
> This is happening with ZooKeeper-3.4.6 and is fairly reproducible.
> Debug logs:
> {noformat}
> 2015-07-02 00:58:49,318 [myid:] - INFO
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:NIOServerCnxnFactory@197] -
> Accepted socket connection from /:47942
> 2015-07-02 00:58:49,318 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@78] -
> serviceHostname is ''
> 2015-07-02 00:58:49,318 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@79] -
> servicePrincipalName is 'zookeeper'
> 2015-07-02 00:58:49,318 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@80] - SASL
> mechanism(mech) is 'GSSAPI'
> 2015-07-02 00:58:49,324 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@106] - Added
> private credential to subject: [GSSCredential:
> zookeeper@ 1.2.840.113554.1.2.2 Accept [class
> sun.security.jgss.wrapper.GSSCredElement]]
> 2015-07-02 00:58:59,441 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@810] - Session
> establishment request from client /:47942 client's lastZxid is 0x0
> 2015-07-02 00:58:59,441 [myid:] - INFO
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@868] - Client
> attempting to establish new session at /:47942
> 2015-07-02 00:58:59,448 [myid:] - DEBUG
> [SyncThread:0:FinalRequestProcessor@88] - Processing request::
> sessionid:0x14e486028785c81 type:createSession cxid:0x0 zxid:0x110e79
> txntype:-10 reqpath:n/a
> 2015-07-02 00:58:59,448 [myid:] - DEBUG
> [SyncThread:0:FinalRequestProcessor@160] - sessionid:0x14e486028785c81
> type:createSession cxid:0x0 zxid:0x110e79 txntype:-10 reqpath:n/a
> 2015-07-02 00:58:59,448 [myid:] - INFO [SyncThread:0:ZooKeeperServer@617] -
> Established session 0x14e486028785c81 with negotiated timeout 1 for
> client /:47942
> 2015-07-02 00:58:59,452 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@949] - Responding
> to client SASL token.
> 2015-07-02 00:58:59,452 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@953] - Size of
> client SASL token: 706
> 2015-07-02 00:58:59,460 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@984] - Size of
> server SASL response: 161
> 2015-07-02 00:58:59,462 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@949] - Responding
> to client SASL token.
> 2015-07-02 00:58:59,462 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@953] - Size of
> client SASL token: 0
> 2015-07-02 00:58:59,462 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@984] - Size of
> server SASL response: 32
> 2015-07-02 00:58:59,463 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@949] - Responding
> to client SASL token.
> 2015-07-02 00:58:59,463 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@953] - Size of
> client SASL token: 32
> 2015-07-02 00:58:59,464 [myid:] - INFO
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:SaslServerCallbackHandler@118] -
> Successfully authenticated client: authenticationID=;
> authorizationID=.
> 2015-07-02 00:58:59,464
[jira] [Issue Comment Deleted] (ZOOKEEPER-2230) Connections fo ZooKeeper server becomes slow over time with native GSSAPI
[
https://issues.apache.org/jira/browse/ZOOKEEPER-2230?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Deepesh Reja updated ZOOKEEPER-2230:
Comment: was deleted
(was: For every connection to the server, a new ZooKeeperSaslServer is
instantiated and when we use native GSSAPI, the credentials are added to the
subject's private credential set. These credentials are nothing but credentials
of server principal and for every connection it remains the same because
servicePrincipalName and serviceHostName doesn't change. The private credential
set allows addition of same object to the set because equals() method of
GSSCredential doesn't adhere to the RFC and returns False unless both objects
are same.
The patch checks if there is no credential in the private credential set, the
credential is added to the set otherwise not.
References:
http://grepcode.com/file/repository.grepcode.com/java/root/jdk/openjdk/8u40-b25/sun/security/jgss/GSSCredentialImpl.java#GSSCredentialImpl.equals%28java.lang.Object%29
http://stackoverflow.com/questions/10285421/java-gssapi-compare-two-gsscredential-instances
)
> Connections fo ZooKeeper server becomes slow over time with native GSSAPI
> -
>
> Key: ZOOKEEPER-2230
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-2230
> Project: ZooKeeper
> Issue Type: Bug
> Components: server
>Affects Versions: 3.4.6, 3.4.7, 3.4.8
> Environment: OS: RHEL6
> Java: 1.8.0_40
> Configuration:
> java.env:
> {noformat}
> SERVER_JVMFLAGS="$SERVER_JVMFLAGS -Xmx5120m"
> SERVER_JVMFLAGS="$SERVER_JVMFLAGS
> -Djava.security.auth.login.config=/local/apps/zookeeper-test1/conf/jaas-server.conf"
> SERVER_JVMFLAGS="$SERVER_JVMFLAGS -Dsun.security.jgss.native=true"
> {noformat}
> jaas-server.conf:
> {noformat}
> Server {
> com.sun.security.auth.module.Krb5LoginModule required
> useKeyTab=true
> isInitiator=false
> principal="zookeeper/@";
> };
> {noformat}
> Process environment:
> {noformat}
> KRB5_KTNAME=/local/apps/zookeeper-test1/conf/keytab
> ZOO_LOG_DIR=/local/apps/zookeeper-test1/log
> ZOOCFGDIR=/local/apps/zookeeper-test1/conf
> {noformat}
>Reporter: Deepesh Reja
>Assignee: Enis Soztutar
> Labels: patch
> Fix For: 3.4.6, 3.4.7, 3.4.8
>
>
> ZooKeeper server becomes slow over time when native GSSAPI is used. The
> connection to the server starts taking upto 10 seconds.
> This is happening with ZooKeeper-3.4.6 and is fairly reproducible.
> Debug logs:
> {noformat}
> 2015-07-02 00:58:49,318 [myid:] - INFO
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:NIOServerCnxnFactory@197] -
> Accepted socket connection from /:47942
> 2015-07-02 00:58:49,318 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@78] -
> serviceHostname is ''
> 2015-07-02 00:58:49,318 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@79] -
> servicePrincipalName is 'zookeeper'
> 2015-07-02 00:58:49,318 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@80] - SASL
> mechanism(mech) is 'GSSAPI'
> 2015-07-02 00:58:49,324 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@106] - Added
> private credential to subject: [GSSCredential:
> zookeeper@ 1.2.840.113554.1.2.2 Accept [class
> sun.security.jgss.wrapper.GSSCredElement]]
> 2015-07-02 00:58:59,441 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@810] - Session
> establishment request from client /:47942 client's lastZxid is 0x0
> 2015-07-02 00:58:59,441 [myid:] - INFO
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@868] - Client
> attempting to establish new session at /:47942
> 2015-07-02 00:58:59,448 [myid:] - DEBUG
> [SyncThread:0:FinalRequestProcessor@88] - Processing request::
> sessionid:0x14e486028785c81 type:createSession cxid:0x0 zxid:0x110e79
> txntype:-10 reqpath:n/a
> 2015-07-02 00:58:59,448 [myid:] - DEBUG
> [SyncThread:0:FinalRequestProcessor@160] - sessionid:0x14e486028785c81
> type:createSession cxid:0x0 zxid:0x110e79 txntype:-10 reqpath:n/a
> 2015-07-02 00:58:59,448 [myid:] - INFO [SyncThread:0:ZooKeeperServer@617] -
> Established session 0x14e486028785c81 with negotiated timeout 1 for
> client /:47942
> 2015-07-02 00:58:59,452 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@949] - Responding
> to client SASL token.
> 2015-07-02 00:58:59,452 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@953] - Size of
> client SASL token: 706
> 2015-07-02 00:58:59,460 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@984] - Size of
> server SASL response: 161
> 2015-07-02 00:58:59,462 [myid:] - DEBUG
> [NIOServerCxn.Fa
[jira] [Updated] (ZOOKEEPER-2230) Connections fo ZooKeeper server becomes slow over time with native GSSAPI
[
https://issues.apache.org/jira/browse/ZOOKEEPER-2230?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Deepesh Reja updated ZOOKEEPER-2230:
Attachment: ZOOKEEPER-2230.patch
> Connections fo ZooKeeper server becomes slow over time with native GSSAPI
> -
>
> Key: ZOOKEEPER-2230
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-2230
> Project: ZooKeeper
> Issue Type: Bug
> Components: server
>Affects Versions: 3.4.6, 3.4.7, 3.4.8, 3.5.0
> Environment: OS: RHEL6
> Java: 1.8.0_40
> Configuration:
> java.env:
> {noformat}
> SERVER_JVMFLAGS="$SERVER_JVMFLAGS -Xmx5120m"
> SERVER_JVMFLAGS="$SERVER_JVMFLAGS
> -Djava.security.auth.login.config=/local/apps/zookeeper-test1/conf/jaas-server.conf"
> SERVER_JVMFLAGS="$SERVER_JVMFLAGS -Dsun.security.jgss.native=true"
> {noformat}
> jaas-server.conf:
> {noformat}
> Server {
> com.sun.security.auth.module.Krb5LoginModule required
> useKeyTab=true
> isInitiator=false
> principal="zookeeper/@";
> };
> {noformat}
> Process environment:
> {noformat}
> KRB5_KTNAME=/local/apps/zookeeper-test1/conf/keytab
> ZOO_LOG_DIR=/local/apps/zookeeper-test1/log
> ZOOCFGDIR=/local/apps/zookeeper-test1/conf
> {noformat}
>Reporter: Deepesh Reja
>Assignee: Enis Soztutar
> Labels: patch
> Fix For: 3.4.6, 3.4.7, 3.4.8, 3.5.2
>
> Attachments: ZOOKEEPER-2230.patch
>
>
> ZooKeeper server becomes slow over time when native GSSAPI is used. The
> connection to the server starts taking upto 10 seconds.
> This is happening with ZooKeeper-3.4.6 and is fairly reproducible.
> Debug logs:
> {noformat}
> 2015-07-02 00:58:49,318 [myid:] - INFO
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:NIOServerCnxnFactory@197] -
> Accepted socket connection from /:47942
> 2015-07-02 00:58:49,318 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@78] -
> serviceHostname is ''
> 2015-07-02 00:58:49,318 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@79] -
> servicePrincipalName is 'zookeeper'
> 2015-07-02 00:58:49,318 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@80] - SASL
> mechanism(mech) is 'GSSAPI'
> 2015-07-02 00:58:49,324 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@106] - Added
> private credential to subject: [GSSCredential:
> zookeeper@ 1.2.840.113554.1.2.2 Accept [class
> sun.security.jgss.wrapper.GSSCredElement]]
> 2015-07-02 00:58:59,441 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@810] - Session
> establishment request from client /:47942 client's lastZxid is 0x0
> 2015-07-02 00:58:59,441 [myid:] - INFO
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@868] - Client
> attempting to establish new session at /:47942
> 2015-07-02 00:58:59,448 [myid:] - DEBUG
> [SyncThread:0:FinalRequestProcessor@88] - Processing request::
> sessionid:0x14e486028785c81 type:createSession cxid:0x0 zxid:0x110e79
> txntype:-10 reqpath:n/a
> 2015-07-02 00:58:59,448 [myid:] - DEBUG
> [SyncThread:0:FinalRequestProcessor@160] - sessionid:0x14e486028785c81
> type:createSession cxid:0x0 zxid:0x110e79 txntype:-10 reqpath:n/a
> 2015-07-02 00:58:59,448 [myid:] - INFO [SyncThread:0:ZooKeeperServer@617] -
> Established session 0x14e486028785c81 with negotiated timeout 1 for
> client /:47942
> 2015-07-02 00:58:59,452 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@949] - Responding
> to client SASL token.
> 2015-07-02 00:58:59,452 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@953] - Size of
> client SASL token: 706
> 2015-07-02 00:58:59,460 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@984] - Size of
> server SASL response: 161
> 2015-07-02 00:58:59,462 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@949] - Responding
> to client SASL token.
> 2015-07-02 00:58:59,462 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@953] - Size of
> client SASL token: 0
> 2015-07-02 00:58:59,462 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@984] - Size of
> server SASL response: 32
> 2015-07-02 00:58:59,463 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@949] - Responding
> to client SASL token.
> 2015-07-02 00:58:59,463 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@953] - Size of
> client SASL token: 32
> 2015-07-02 00:58:59,464 [myid:] - INFO
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:SaslServerCallbackHandler@118] -
> Successfully authenticated client: authenticationID=;
> authorizationID=.
> 2015
[jira] [Commented] (ZOOKEEPER-2230) Connections fo ZooKeeper server becomes slow over time with native GSSAPI
[
https://issues.apache.org/jira/browse/ZOOKEEPER-2230?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15526214#comment-15526214
]
Deepesh Reja commented on ZOOKEEPER-2230:
-
Hi [~rgs],
I've figured out the issue and the came up with the attached patch. Can you
please review it and push it further?
Thanks,
Deepesh
> Connections fo ZooKeeper server becomes slow over time with native GSSAPI
> -
>
> Key: ZOOKEEPER-2230
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-2230
> Project: ZooKeeper
> Issue Type: Bug
> Components: server
>Affects Versions: 3.4.6, 3.4.7, 3.4.8, 3.5.0
> Environment: OS: RHEL6
> Java: 1.8.0_40
> Configuration:
> java.env:
> {noformat}
> SERVER_JVMFLAGS="$SERVER_JVMFLAGS -Xmx5120m"
> SERVER_JVMFLAGS="$SERVER_JVMFLAGS
> -Djava.security.auth.login.config=/local/apps/zookeeper-test1/conf/jaas-server.conf"
> SERVER_JVMFLAGS="$SERVER_JVMFLAGS -Dsun.security.jgss.native=true"
> {noformat}
> jaas-server.conf:
> {noformat}
> Server {
> com.sun.security.auth.module.Krb5LoginModule required
> useKeyTab=true
> isInitiator=false
> principal="zookeeper/@";
> };
> {noformat}
> Process environment:
> {noformat}
> KRB5_KTNAME=/local/apps/zookeeper-test1/conf/keytab
> ZOO_LOG_DIR=/local/apps/zookeeper-test1/log
> ZOOCFGDIR=/local/apps/zookeeper-test1/conf
> {noformat}
>Reporter: Deepesh Reja
>Assignee: Enis Soztutar
> Labels: patch
> Fix For: 3.4.6, 3.4.7, 3.4.8, 3.5.2
>
> Attachments: ZOOKEEPER-2230.patch
>
>
> ZooKeeper server becomes slow over time when native GSSAPI is used. The
> connection to the server starts taking upto 10 seconds.
> This is happening with ZooKeeper-3.4.6 and is fairly reproducible.
> Debug logs:
> {noformat}
> 2015-07-02 00:58:49,318 [myid:] - INFO
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:NIOServerCnxnFactory@197] -
> Accepted socket connection from /:47942
> 2015-07-02 00:58:49,318 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@78] -
> serviceHostname is ''
> 2015-07-02 00:58:49,318 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@79] -
> servicePrincipalName is 'zookeeper'
> 2015-07-02 00:58:49,318 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@80] - SASL
> mechanism(mech) is 'GSSAPI'
> 2015-07-02 00:58:49,324 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@106] - Added
> private credential to subject: [GSSCredential:
> zookeeper@ 1.2.840.113554.1.2.2 Accept [class
> sun.security.jgss.wrapper.GSSCredElement]]
> 2015-07-02 00:58:59,441 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@810] - Session
> establishment request from client /:47942 client's lastZxid is 0x0
> 2015-07-02 00:58:59,441 [myid:] - INFO
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@868] - Client
> attempting to establish new session at /:47942
> 2015-07-02 00:58:59,448 [myid:] - DEBUG
> [SyncThread:0:FinalRequestProcessor@88] - Processing request::
> sessionid:0x14e486028785c81 type:createSession cxid:0x0 zxid:0x110e79
> txntype:-10 reqpath:n/a
> 2015-07-02 00:58:59,448 [myid:] - DEBUG
> [SyncThread:0:FinalRequestProcessor@160] - sessionid:0x14e486028785c81
> type:createSession cxid:0x0 zxid:0x110e79 txntype:-10 reqpath:n/a
> 2015-07-02 00:58:59,448 [myid:] - INFO [SyncThread:0:ZooKeeperServer@617] -
> Established session 0x14e486028785c81 with negotiated timeout 1 for
> client /:47942
> 2015-07-02 00:58:59,452 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@949] - Responding
> to client SASL token.
> 2015-07-02 00:58:59,452 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@953] - Size of
> client SASL token: 706
> 2015-07-02 00:58:59,460 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@984] - Size of
> server SASL response: 161
> 2015-07-02 00:58:59,462 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@949] - Responding
> to client SASL token.
> 2015-07-02 00:58:59,462 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@953] - Size of
> client SASL token: 0
> 2015-07-02 00:58:59,462 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@984] - Size of
> server SASL response: 32
> 2015-07-02 00:58:59,463 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@949] - Responding
> to client SASL token.
> 2015-07-02 00:58:59,463 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@953] - Size of
> client SASL token: 32
> 2015-07-02 00:58:59,464 [myid:] - INFO
[jira] [Commented] (ZOOKEEPER-2230) Connections fo ZooKeeper server becomes slow over time with native GSSAPI
[
https://issues.apache.org/jira/browse/ZOOKEEPER-2230?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15526223#comment-15526223
]
Deepesh Reja commented on ZOOKEEPER-2230:
-
>> -1 tests included. The patch doesn't appear to include any new or modified
>> tests.
I don't think this needs a new tests because it doesn't really include a new
function/class or change a lot in the function.
> Connections fo ZooKeeper server becomes slow over time with native GSSAPI
> -
>
> Key: ZOOKEEPER-2230
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-2230
> Project: ZooKeeper
> Issue Type: Bug
> Components: server
>Affects Versions: 3.4.6, 3.4.7, 3.4.8, 3.5.0
> Environment: OS: RHEL6
> Java: 1.8.0_40
> Configuration:
> java.env:
> {noformat}
> SERVER_JVMFLAGS="$SERVER_JVMFLAGS -Xmx5120m"
> SERVER_JVMFLAGS="$SERVER_JVMFLAGS
> -Djava.security.auth.login.config=/local/apps/zookeeper-test1/conf/jaas-server.conf"
> SERVER_JVMFLAGS="$SERVER_JVMFLAGS -Dsun.security.jgss.native=true"
> {noformat}
> jaas-server.conf:
> {noformat}
> Server {
> com.sun.security.auth.module.Krb5LoginModule required
> useKeyTab=true
> isInitiator=false
> principal="zookeeper/@";
> };
> {noformat}
> Process environment:
> {noformat}
> KRB5_KTNAME=/local/apps/zookeeper-test1/conf/keytab
> ZOO_LOG_DIR=/local/apps/zookeeper-test1/log
> ZOOCFGDIR=/local/apps/zookeeper-test1/conf
> {noformat}
>Reporter: Deepesh Reja
>Assignee: Enis Soztutar
> Labels: patch
> Fix For: 3.4.6, 3.4.7, 3.4.8, 3.5.2
>
> Attachments: ZOOKEEPER-2230.patch
>
>
> ZooKeeper server becomes slow over time when native GSSAPI is used. The
> connection to the server starts taking upto 10 seconds.
> This is happening with ZooKeeper-3.4.6 and is fairly reproducible.
> Debug logs:
> {noformat}
> 2015-07-02 00:58:49,318 [myid:] - INFO
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:NIOServerCnxnFactory@197] -
> Accepted socket connection from /:47942
> 2015-07-02 00:58:49,318 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@78] -
> serviceHostname is ''
> 2015-07-02 00:58:49,318 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@79] -
> servicePrincipalName is 'zookeeper'
> 2015-07-02 00:58:49,318 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@80] - SASL
> mechanism(mech) is 'GSSAPI'
> 2015-07-02 00:58:49,324 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@106] - Added
> private credential to subject: [GSSCredential:
> zookeeper@ 1.2.840.113554.1.2.2 Accept [class
> sun.security.jgss.wrapper.GSSCredElement]]
> 2015-07-02 00:58:59,441 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@810] - Session
> establishment request from client /:47942 client's lastZxid is 0x0
> 2015-07-02 00:58:59,441 [myid:] - INFO
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@868] - Client
> attempting to establish new session at /:47942
> 2015-07-02 00:58:59,448 [myid:] - DEBUG
> [SyncThread:0:FinalRequestProcessor@88] - Processing request::
> sessionid:0x14e486028785c81 type:createSession cxid:0x0 zxid:0x110e79
> txntype:-10 reqpath:n/a
> 2015-07-02 00:58:59,448 [myid:] - DEBUG
> [SyncThread:0:FinalRequestProcessor@160] - sessionid:0x14e486028785c81
> type:createSession cxid:0x0 zxid:0x110e79 txntype:-10 reqpath:n/a
> 2015-07-02 00:58:59,448 [myid:] - INFO [SyncThread:0:ZooKeeperServer@617] -
> Established session 0x14e486028785c81 with negotiated timeout 1 for
> client /:47942
> 2015-07-02 00:58:59,452 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@949] - Responding
> to client SASL token.
> 2015-07-02 00:58:59,452 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@953] - Size of
> client SASL token: 706
> 2015-07-02 00:58:59,460 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@984] - Size of
> server SASL response: 161
> 2015-07-02 00:58:59,462 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@949] - Responding
> to client SASL token.
> 2015-07-02 00:58:59,462 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@953] - Size of
> client SASL token: 0
> 2015-07-02 00:58:59,462 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@984] - Size of
> server SASL response: 32
> 2015-07-02 00:58:59,463 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@949] - Responding
> to client SASL token.
> 2015-07-02 00:58:59,463 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@953] - Size
[jira] [Commented] (ZOOKEEPER-2230) Connections fo ZooKeeper server becomes slow over time with native GSSAPI
[
https://issues.apache.org/jira/browse/ZOOKEEPER-2230?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15562377#comment-15562377
]
Deepesh Reja commented on ZOOKEEPER-2230:
-
Hi [~rgs],
Can you please review the patch and merge it?
> Connections fo ZooKeeper server becomes slow over time with native GSSAPI
> -
>
> Key: ZOOKEEPER-2230
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-2230
> Project: ZooKeeper
> Issue Type: Bug
> Components: server
>Affects Versions: 3.4.6, 3.4.7, 3.4.8, 3.5.0
> Environment: OS: RHEL6
> Java: 1.8.0_40
> Configuration:
> java.env:
> {noformat}
> SERVER_JVMFLAGS="$SERVER_JVMFLAGS -Xmx5120m"
> SERVER_JVMFLAGS="$SERVER_JVMFLAGS
> -Djava.security.auth.login.config=/local/apps/zookeeper-test1/conf/jaas-server.conf"
> SERVER_JVMFLAGS="$SERVER_JVMFLAGS -Dsun.security.jgss.native=true"
> {noformat}
> jaas-server.conf:
> {noformat}
> Server {
> com.sun.security.auth.module.Krb5LoginModule required
> useKeyTab=true
> isInitiator=false
> principal="zookeeper/@";
> };
> {noformat}
> Process environment:
> {noformat}
> KRB5_KTNAME=/local/apps/zookeeper-test1/conf/keytab
> ZOO_LOG_DIR=/local/apps/zookeeper-test1/log
> ZOOCFGDIR=/local/apps/zookeeper-test1/conf
> {noformat}
>Reporter: Deepesh Reja
>Assignee: Enis Soztutar
> Labels: patch
> Fix For: 3.4.6, 3.4.7, 3.4.8, 3.5.2
>
> Attachments: ZOOKEEPER-2230.patch
>
>
> ZooKeeper server becomes slow over time when native GSSAPI is used. The
> connection to the server starts taking upto 10 seconds.
> This is happening with ZooKeeper-3.4.6 and is fairly reproducible.
> Debug logs:
> {noformat}
> 2015-07-02 00:58:49,318 [myid:] - INFO
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:NIOServerCnxnFactory@197] -
> Accepted socket connection from /:47942
> 2015-07-02 00:58:49,318 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@78] -
> serviceHostname is ''
> 2015-07-02 00:58:49,318 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@79] -
> servicePrincipalName is 'zookeeper'
> 2015-07-02 00:58:49,318 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@80] - SASL
> mechanism(mech) is 'GSSAPI'
> 2015-07-02 00:58:49,324 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@106] - Added
> private credential to subject: [GSSCredential:
> zookeeper@ 1.2.840.113554.1.2.2 Accept [class
> sun.security.jgss.wrapper.GSSCredElement]]
> 2015-07-02 00:58:59,441 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@810] - Session
> establishment request from client /:47942 client's lastZxid is 0x0
> 2015-07-02 00:58:59,441 [myid:] - INFO
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@868] - Client
> attempting to establish new session at /:47942
> 2015-07-02 00:58:59,448 [myid:] - DEBUG
> [SyncThread:0:FinalRequestProcessor@88] - Processing request::
> sessionid:0x14e486028785c81 type:createSession cxid:0x0 zxid:0x110e79
> txntype:-10 reqpath:n/a
> 2015-07-02 00:58:59,448 [myid:] - DEBUG
> [SyncThread:0:FinalRequestProcessor@160] - sessionid:0x14e486028785c81
> type:createSession cxid:0x0 zxid:0x110e79 txntype:-10 reqpath:n/a
> 2015-07-02 00:58:59,448 [myid:] - INFO [SyncThread:0:ZooKeeperServer@617] -
> Established session 0x14e486028785c81 with negotiated timeout 1 for
> client /:47942
> 2015-07-02 00:58:59,452 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@949] - Responding
> to client SASL token.
> 2015-07-02 00:58:59,452 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@953] - Size of
> client SASL token: 706
> 2015-07-02 00:58:59,460 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@984] - Size of
> server SASL response: 161
> 2015-07-02 00:58:59,462 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@949] - Responding
> to client SASL token.
> 2015-07-02 00:58:59,462 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@953] - Size of
> client SASL token: 0
> 2015-07-02 00:58:59,462 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@984] - Size of
> server SASL response: 32
> 2015-07-02 00:58:59,463 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@949] - Responding
> to client SASL token.
> 2015-07-02 00:58:59,463 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@953] - Size of
> client SASL token: 32
> 2015-07-02 00:58:59,464 [myid:] - INFO
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:SaslServerCallbackHandler@118] -
> Suc
[jira] [Commented] (ZOOKEEPER-2230) Connections fo ZooKeeper server becomes slow over time with native GSSAPI
[
https://issues.apache.org/jira/browse/ZOOKEEPER-2230?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15608199#comment-15608199
]
Deepesh Reja commented on ZOOKEEPER-2230:
-
Hi [~ekoontz]/[~mahadev],
>From ZOOKEEPER-938, I feel that you might be interested in this patch. Can you
>please review and merge this?
Thanks,
Deepesh
> Connections fo ZooKeeper server becomes slow over time with native GSSAPI
> -
>
> Key: ZOOKEEPER-2230
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-2230
> Project: ZooKeeper
> Issue Type: Bug
> Components: server
>Affects Versions: 3.4.6, 3.4.7, 3.4.8, 3.5.0
> Environment: OS: RHEL6
> Java: 1.8.0_40
> Configuration:
> java.env:
> {noformat}
> SERVER_JVMFLAGS="$SERVER_JVMFLAGS -Xmx5120m"
> SERVER_JVMFLAGS="$SERVER_JVMFLAGS
> -Djava.security.auth.login.config=/local/apps/zookeeper-test1/conf/jaas-server.conf"
> SERVER_JVMFLAGS="$SERVER_JVMFLAGS -Dsun.security.jgss.native=true"
> {noformat}
> jaas-server.conf:
> {noformat}
> Server {
> com.sun.security.auth.module.Krb5LoginModule required
> useKeyTab=true
> isInitiator=false
> principal="zookeeper/@";
> };
> {noformat}
> Process environment:
> {noformat}
> KRB5_KTNAME=/local/apps/zookeeper-test1/conf/keytab
> ZOO_LOG_DIR=/local/apps/zookeeper-test1/log
> ZOOCFGDIR=/local/apps/zookeeper-test1/conf
> {noformat}
>Reporter: Deepesh Reja
>Assignee: Enis Soztutar
> Labels: patch
> Fix For: 3.4.6, 3.4.7, 3.4.8, 3.5.2
>
> Attachments: ZOOKEEPER-2230.patch
>
>
> ZooKeeper server becomes slow over time when native GSSAPI is used. The
> connection to the server starts taking upto 10 seconds.
> This is happening with ZooKeeper-3.4.6 and is fairly reproducible.
> Debug logs:
> {noformat}
> 2015-07-02 00:58:49,318 [myid:] - INFO
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:NIOServerCnxnFactory@197] -
> Accepted socket connection from /:47942
> 2015-07-02 00:58:49,318 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@78] -
> serviceHostname is ''
> 2015-07-02 00:58:49,318 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@79] -
> servicePrincipalName is 'zookeeper'
> 2015-07-02 00:58:49,318 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@80] - SASL
> mechanism(mech) is 'GSSAPI'
> 2015-07-02 00:58:49,324 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@106] - Added
> private credential to subject: [GSSCredential:
> zookeeper@ 1.2.840.113554.1.2.2 Accept [class
> sun.security.jgss.wrapper.GSSCredElement]]
> 2015-07-02 00:58:59,441 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@810] - Session
> establishment request from client /:47942 client's lastZxid is 0x0
> 2015-07-02 00:58:59,441 [myid:] - INFO
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@868] - Client
> attempting to establish new session at /:47942
> 2015-07-02 00:58:59,448 [myid:] - DEBUG
> [SyncThread:0:FinalRequestProcessor@88] - Processing request::
> sessionid:0x14e486028785c81 type:createSession cxid:0x0 zxid:0x110e79
> txntype:-10 reqpath:n/a
> 2015-07-02 00:58:59,448 [myid:] - DEBUG
> [SyncThread:0:FinalRequestProcessor@160] - sessionid:0x14e486028785c81
> type:createSession cxid:0x0 zxid:0x110e79 txntype:-10 reqpath:n/a
> 2015-07-02 00:58:59,448 [myid:] - INFO [SyncThread:0:ZooKeeperServer@617] -
> Established session 0x14e486028785c81 with negotiated timeout 1 for
> client /:47942
> 2015-07-02 00:58:59,452 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@949] - Responding
> to client SASL token.
> 2015-07-02 00:58:59,452 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@953] - Size of
> client SASL token: 706
> 2015-07-02 00:58:59,460 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@984] - Size of
> server SASL response: 161
> 2015-07-02 00:58:59,462 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@949] - Responding
> to client SASL token.
> 2015-07-02 00:58:59,462 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@953] - Size of
> client SASL token: 0
> 2015-07-02 00:58:59,462 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@984] - Size of
> server SASL response: 32
> 2015-07-02 00:58:59,463 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@949] - Responding
> to client SASL token.
> 2015-07-02 00:58:59,463 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@953] - Size of
> client SASL token: 32
> 2015-07-02 00:58:59,464 [m
[jira] [Commented] (ZOOKEEPER-2230) Connections fo ZooKeeper server becomes slow over time with native GSSAPI
[
https://issues.apache.org/jira/browse/ZOOKEEPER-2230?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15692157#comment-15692157
]
Deepesh Reja commented on ZOOKEEPER-2230:
-
I am not sure why the first credential in Private Credentials set is keytab
file name. We are running proposed patch in Production and we are not seeing
any issues.
> Connections fo ZooKeeper server becomes slow over time with native GSSAPI
> -
>
> Key: ZOOKEEPER-2230
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-2230
> Project: ZooKeeper
> Issue Type: Bug
> Components: server
>Affects Versions: 3.4.6, 3.4.7, 3.4.8, 3.5.0
> Environment: OS: RHEL6
> Java: 1.8.0_40
> Configuration:
> java.env:
> {noformat}
> SERVER_JVMFLAGS="$SERVER_JVMFLAGS -Xmx5120m"
> SERVER_JVMFLAGS="$SERVER_JVMFLAGS
> -Djava.security.auth.login.config=/local/apps/zookeeper-test1/conf/jaas-server.conf"
> SERVER_JVMFLAGS="$SERVER_JVMFLAGS -Dsun.security.jgss.native=true"
> {noformat}
> jaas-server.conf:
> {noformat}
> Server {
> com.sun.security.auth.module.Krb5LoginModule required
> useKeyTab=true
> isInitiator=false
> principal="zookeeper/@";
> };
> {noformat}
> Process environment:
> {noformat}
> KRB5_KTNAME=/local/apps/zookeeper-test1/conf/keytab
> ZOO_LOG_DIR=/local/apps/zookeeper-test1/log
> ZOOCFGDIR=/local/apps/zookeeper-test1/conf
> {noformat}
>Reporter: Deepesh Reja
>Assignee: Enis Soztutar
> Labels: patch
> Fix For: 3.4.6, 3.4.7, 3.4.8, 3.5.2
>
> Attachments: ZOOKEEPER-2230.patch
>
>
> ZooKeeper server becomes slow over time when native GSSAPI is used. The
> connection to the server starts taking upto 10 seconds.
> This is happening with ZooKeeper-3.4.6 and is fairly reproducible.
> Debug logs:
> {noformat}
> 2015-07-02 00:58:49,318 [myid:] - INFO
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:NIOServerCnxnFactory@197] -
> Accepted socket connection from /:47942
> 2015-07-02 00:58:49,318 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@78] -
> serviceHostname is ''
> 2015-07-02 00:58:49,318 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@79] -
> servicePrincipalName is 'zookeeper'
> 2015-07-02 00:58:49,318 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@80] - SASL
> mechanism(mech) is 'GSSAPI'
> 2015-07-02 00:58:49,324 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@106] - Added
> private credential to subject: [GSSCredential:
> zookeeper@ 1.2.840.113554.1.2.2 Accept [class
> sun.security.jgss.wrapper.GSSCredElement]]
> 2015-07-02 00:58:59,441 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@810] - Session
> establishment request from client /:47942 client's lastZxid is 0x0
> 2015-07-02 00:58:59,441 [myid:] - INFO
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@868] - Client
> attempting to establish new session at /:47942
> 2015-07-02 00:58:59,448 [myid:] - DEBUG
> [SyncThread:0:FinalRequestProcessor@88] - Processing request::
> sessionid:0x14e486028785c81 type:createSession cxid:0x0 zxid:0x110e79
> txntype:-10 reqpath:n/a
> 2015-07-02 00:58:59,448 [myid:] - DEBUG
> [SyncThread:0:FinalRequestProcessor@160] - sessionid:0x14e486028785c81
> type:createSession cxid:0x0 zxid:0x110e79 txntype:-10 reqpath:n/a
> 2015-07-02 00:58:59,448 [myid:] - INFO [SyncThread:0:ZooKeeperServer@617] -
> Established session 0x14e486028785c81 with negotiated timeout 1 for
> client /:47942
> 2015-07-02 00:58:59,452 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@949] - Responding
> to client SASL token.
> 2015-07-02 00:58:59,452 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@953] - Size of
> client SASL token: 706
> 2015-07-02 00:58:59,460 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@984] - Size of
> server SASL response: 161
> 2015-07-02 00:58:59,462 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@949] - Responding
> to client SASL token.
> 2015-07-02 00:58:59,462 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@953] - Size of
> client SASL token: 0
> 2015-07-02 00:58:59,462 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@984] - Size of
> server SASL response: 32
> 2015-07-02 00:58:59,463 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@949] - Responding
> to client SASL token.
> 2015-07-02 00:58:59,463 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@953] - Size of
> client SASL token: 32
> 2015-07-02 00:58:
[jira] [Commented] (ZOOKEEPER-2230) Connections fo ZooKeeper server becomes slow over time with native GSSAPI
[
https://issues.apache.org/jira/browse/ZOOKEEPER-2230?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15707509#comment-15707509
]
Deepesh Reja commented on ZOOKEEPER-2230:
-
[~fittey] Can you provide us your zookeeper configurations like jaas.conf, Java
properties set while starting ZooKeeper, etc.? I'll try to reproduce it in my
environment and see if I can come to a conclusion.
> Connections fo ZooKeeper server becomes slow over time with native GSSAPI
> -
>
> Key: ZOOKEEPER-2230
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-2230
> Project: ZooKeeper
> Issue Type: Bug
> Components: server
>Affects Versions: 3.4.6, 3.4.7, 3.4.8, 3.5.0
> Environment: OS: RHEL6
> Java: 1.8.0_40
> Configuration:
> java.env:
> {noformat}
> SERVER_JVMFLAGS="$SERVER_JVMFLAGS -Xmx5120m"
> SERVER_JVMFLAGS="$SERVER_JVMFLAGS
> -Djava.security.auth.login.config=/local/apps/zookeeper-test1/conf/jaas-server.conf"
> SERVER_JVMFLAGS="$SERVER_JVMFLAGS -Dsun.security.jgss.native=true"
> {noformat}
> jaas-server.conf:
> {noformat}
> Server {
> com.sun.security.auth.module.Krb5LoginModule required
> useKeyTab=true
> isInitiator=false
> principal="zookeeper/@";
> };
> {noformat}
> Process environment:
> {noformat}
> KRB5_KTNAME=/local/apps/zookeeper-test1/conf/keytab
> ZOO_LOG_DIR=/local/apps/zookeeper-test1/log
> ZOOCFGDIR=/local/apps/zookeeper-test1/conf
> {noformat}
>Reporter: Deepesh Reja
>Assignee: Enis Soztutar
> Labels: patch
> Fix For: 3.4.6, 3.4.7, 3.4.8, 3.5.2
>
> Attachments: ZOOKEEPER-2230.patch
>
>
> ZooKeeper server becomes slow over time when native GSSAPI is used. The
> connection to the server starts taking upto 10 seconds.
> This is happening with ZooKeeper-3.4.6 and is fairly reproducible.
> Debug logs:
> {noformat}
> 2015-07-02 00:58:49,318 [myid:] - INFO
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:NIOServerCnxnFactory@197] -
> Accepted socket connection from /:47942
> 2015-07-02 00:58:49,318 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@78] -
> serviceHostname is ''
> 2015-07-02 00:58:49,318 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@79] -
> servicePrincipalName is 'zookeeper'
> 2015-07-02 00:58:49,318 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@80] - SASL
> mechanism(mech) is 'GSSAPI'
> 2015-07-02 00:58:49,324 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@106] - Added
> private credential to subject: [GSSCredential:
> zookeeper@ 1.2.840.113554.1.2.2 Accept [class
> sun.security.jgss.wrapper.GSSCredElement]]
> 2015-07-02 00:58:59,441 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@810] - Session
> establishment request from client /:47942 client's lastZxid is 0x0
> 2015-07-02 00:58:59,441 [myid:] - INFO
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@868] - Client
> attempting to establish new session at /:47942
> 2015-07-02 00:58:59,448 [myid:] - DEBUG
> [SyncThread:0:FinalRequestProcessor@88] - Processing request::
> sessionid:0x14e486028785c81 type:createSession cxid:0x0 zxid:0x110e79
> txntype:-10 reqpath:n/a
> 2015-07-02 00:58:59,448 [myid:] - DEBUG
> [SyncThread:0:FinalRequestProcessor@160] - sessionid:0x14e486028785c81
> type:createSession cxid:0x0 zxid:0x110e79 txntype:-10 reqpath:n/a
> 2015-07-02 00:58:59,448 [myid:] - INFO [SyncThread:0:ZooKeeperServer@617] -
> Established session 0x14e486028785c81 with negotiated timeout 1 for
> client /:47942
> 2015-07-02 00:58:59,452 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@949] - Responding
> to client SASL token.
> 2015-07-02 00:58:59,452 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@953] - Size of
> client SASL token: 706
> 2015-07-02 00:58:59,460 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@984] - Size of
> server SASL response: 161
> 2015-07-02 00:58:59,462 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@949] - Responding
> to client SASL token.
> 2015-07-02 00:58:59,462 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@953] - Size of
> client SASL token: 0
> 2015-07-02 00:58:59,462 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@984] - Size of
> server SASL response: 32
> 2015-07-02 00:58:59,463 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@949] - Responding
> to client SASL token.
> 2015-07-02 00:58:59,463 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@953] - Size of
[jira] [Commented] (ZOOKEEPER-2230) Connections fo ZooKeeper server becomes slow over time with native GSSAPI
[
https://issues.apache.org/jira/browse/ZOOKEEPER-2230?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15751226#comment-15751226
]
Deepesh Reja commented on ZOOKEEPER-2230:
-
[~fittey] I think you are seeing different behavior because of setting
"storeKey" to true which adds principal's key in the Subject's private
credentials set. Due to this, there is always an entry in the set.
I'll see if I can come up with something so that this also work when "storeKey"
is set to True.
Also, please let me know if you have something or need help on the patch you
are working on.
> Connections fo ZooKeeper server becomes slow over time with native GSSAPI
> -
>
> Key: ZOOKEEPER-2230
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-2230
> Project: ZooKeeper
> Issue Type: Bug
> Components: server
>Affects Versions: 3.4.6, 3.4.7, 3.4.8, 3.5.0
> Environment: OS: RHEL6
> Java: 1.8.0_40
> Configuration:
> java.env:
> {noformat}
> SERVER_JVMFLAGS="$SERVER_JVMFLAGS -Xmx5120m"
> SERVER_JVMFLAGS="$SERVER_JVMFLAGS
> -Djava.security.auth.login.config=/local/apps/zookeeper-test1/conf/jaas-server.conf"
> SERVER_JVMFLAGS="$SERVER_JVMFLAGS -Dsun.security.jgss.native=true"
> {noformat}
> jaas-server.conf:
> {noformat}
> Server {
> com.sun.security.auth.module.Krb5LoginModule required
> useKeyTab=true
> isInitiator=false
> principal="zookeeper/@";
> };
> {noformat}
> Process environment:
> {noformat}
> KRB5_KTNAME=/local/apps/zookeeper-test1/conf/keytab
> ZOO_LOG_DIR=/local/apps/zookeeper-test1/log
> ZOOCFGDIR=/local/apps/zookeeper-test1/conf
> {noformat}
>Reporter: Deepesh Reja
>Assignee: Enis Soztutar
> Labels: patch
> Fix For: 3.4.6, 3.4.7, 3.4.8, 3.5.2
>
> Attachments: ZOOKEEPER-2230.patch
>
>
> ZooKeeper server becomes slow over time when native GSSAPI is used. The
> connection to the server starts taking upto 10 seconds.
> This is happening with ZooKeeper-3.4.6 and is fairly reproducible.
> Debug logs:
> {noformat}
> 2015-07-02 00:58:49,318 [myid:] - INFO
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:NIOServerCnxnFactory@197] -
> Accepted socket connection from /:47942
> 2015-07-02 00:58:49,318 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@78] -
> serviceHostname is ''
> 2015-07-02 00:58:49,318 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@79] -
> servicePrincipalName is 'zookeeper'
> 2015-07-02 00:58:49,318 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@80] - SASL
> mechanism(mech) is 'GSSAPI'
> 2015-07-02 00:58:49,324 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@106] - Added
> private credential to subject: [GSSCredential:
> zookeeper@ 1.2.840.113554.1.2.2 Accept [class
> sun.security.jgss.wrapper.GSSCredElement]]
> 2015-07-02 00:58:59,441 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@810] - Session
> establishment request from client /:47942 client's lastZxid is 0x0
> 2015-07-02 00:58:59,441 [myid:] - INFO
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@868] - Client
> attempting to establish new session at /:47942
> 2015-07-02 00:58:59,448 [myid:] - DEBUG
> [SyncThread:0:FinalRequestProcessor@88] - Processing request::
> sessionid:0x14e486028785c81 type:createSession cxid:0x0 zxid:0x110e79
> txntype:-10 reqpath:n/a
> 2015-07-02 00:58:59,448 [myid:] - DEBUG
> [SyncThread:0:FinalRequestProcessor@160] - sessionid:0x14e486028785c81
> type:createSession cxid:0x0 zxid:0x110e79 txntype:-10 reqpath:n/a
> 2015-07-02 00:58:59,448 [myid:] - INFO [SyncThread:0:ZooKeeperServer@617] -
> Established session 0x14e486028785c81 with negotiated timeout 1 for
> client /:47942
> 2015-07-02 00:58:59,452 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@949] - Responding
> to client SASL token.
> 2015-07-02 00:58:59,452 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@953] - Size of
> client SASL token: 706
> 2015-07-02 00:58:59,460 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@984] - Size of
> server SASL response: 161
> 2015-07-02 00:58:59,462 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@949] - Responding
> to client SASL token.
> 2015-07-02 00:58:59,462 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@953] - Size of
> client SASL token: 0
> 2015-07-02 00:58:59,462 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@984] - Size of
> server SASL response: 32
> 2015-07-02 00:58:59,463 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/
[jira] [Created] (ZOOKEEPER-2230) Connections fo ZooKeeper server becomes slow over time with native GSSAPI
Deepesh Reja created ZOOKEEPER-2230:
---
Summary: Connections fo ZooKeeper server becomes slow over time
with native GSSAPI
Key: ZOOKEEPER-2230
URL: https://issues.apache.org/jira/browse/ZOOKEEPER-2230
Project: ZooKeeper
Issue Type: Bug
Components: server
Affects Versions: 3.4.6
Environment: OS: RHEL6
Java: 1.8.0_40
Configuration:
java.env:
{quote}
SERVER_JVMFLAGS="$SERVER_JVMFLAGS -Xmx5120m"
SERVER_JVMFLAGS="$SERVER_JVMFLAGS
-Djava.security.auth.login.config=/local/apps/zookeeper-test1/conf/jaas-server.conf"
SERVER_JVMFLAGS="$SERVER_JVMFLAGS -Dsun.security.jgss.native=true"
{quote}
jaas-server.conf:
{quote}
Server {
com.sun.security.auth.module.Krb5LoginModule required
useKeyTab=true
isInitiator=false
principal="zookeeper/@UNIX.DESHAW.COM";
};
{quote}
Process environment:
{quote}
KRB5_KTNAME=/local/apps/zookeeper-test1/conf/keytab
ZOO_LOG_DIR=/local/apps/zookeeper-test1/log
ZOOCFGDIR=/local/apps/zookeeper-test1/conf
{quote}
Reporter: Deepesh Reja
ZooKeeper server becomes slow over time when native GSSAPI is used. The
connection to the server starts taking upto 10 seconds.
This is happening with ZooKeeper-3.4.6 and is fairly reproducible.
Debug logs:
{noformat}
2015-07-02 00:58:49,318 [myid:] - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:NIOServerCnxnFactory@197] -
Accepted socket connection from /:47942
2015-07-02 00:58:49,318 [myid:] - DEBUG
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@78] -
serviceHostname is ''
2015-07-02 00:58:49,318 [myid:] - DEBUG
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@79] -
servicePrincipalName is 'zookeeper'
2015-07-02 00:58:49,318 [myid:] - DEBUG
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@80] - SASL
mechanism(mech) is 'GSSAPI'
2015-07-02 00:58:49,324 [myid:] - DEBUG
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@106] - Added
private credential to subject: [GSSCredential:
zookeeper@ 1.2.840.113554.1.2.2 Accept [class
sun.security.jgss.wrapper.GSSCredElement]]
2015-07-02 00:58:59,441 [myid:] - DEBUG
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@810] - Session
establishment request from client /:47942 client's lastZxid is 0x0
2015-07-02 00:58:59,441 [myid:] - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@868] - Client
attempting to establish new session at /:47942
2015-07-02 00:58:59,448 [myid:] - DEBUG [SyncThread:0:FinalRequestProcessor@88]
- Processing request:: sessionid:0x14e486028785c81 type:createSession cxid:0x0
zxid:0x110e79 txntype:-10 reqpath:n/a
2015-07-02 00:58:59,448 [myid:] - DEBUG
[SyncThread:0:FinalRequestProcessor@160] - sessionid:0x14e486028785c81
type:createSession cxid:0x0 zxid:0x110e79 txntype:-10 reqpath:n/a
2015-07-02 00:58:59,448 [myid:] - INFO [SyncThread:0:ZooKeeperServer@617] -
Established session 0x14e486028785c81 with negotiated timeout 1 for client
/:47942
2015-07-02 00:58:59,452 [myid:] - DEBUG
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@949] - Responding
to client SASL token.
2015-07-02 00:58:59,452 [myid:] - DEBUG
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@953] - Size of
client SASL token: 706
2015-07-02 00:58:59,460 [myid:] - DEBUG
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@984] - Size of
server SASL response: 161
2015-07-02 00:58:59,462 [myid:] - DEBUG
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@949] - Responding
to client SASL token.
2015-07-02 00:58:59,462 [myid:] - DEBUG
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@953] - Size of
client SASL token: 0
2015-07-02 00:58:59,462 [myid:] - DEBUG
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@984] - Size of
server SASL response: 32
2015-07-02 00:58:59,463 [myid:] - DEBUG
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@949] - Responding
to client SASL token.
2015-07-02 00:58:59,463 [myid:] - DEBUG
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@953] - Size of
client SASL token: 32
2015-07-02 00:58:59,464 [myid:] - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:SaslServerCallbackHandler@118] -
Successfully authenticated client: authenticationID=;
authorizationID=.
2015-07-02 00:58:59,464 [myid:] - INFO
[NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@964] - adding SASL
authorization for authorizationID:
2015-07-02 00:58:59,465 [myid:] - INFO [ProcessThread(sid:0
cport:-1)::PrepRequestProcessor@494] - Processed session termination for
sessionid: 0x14e486028785c81
2015-07-02 00:58:59,467 [myid:] - DEBUG [SyncThread:0:FinalRequestProcessor@88]
- Processing request:: sessionid:0x14e486028785c81 type:closeSession cxid:0x1
zxid:0x110e7a txntype:-11 reqpath:n/a
2015-07-02 00:58:59,467 [myid:] - DEBUG
[SyncThread:0:FinalRequestProcessor@160]
[jira] [Updated] (ZOOKEEPER-2230) Connections fo ZooKeeper server becomes slow over time with native GSSAPI
[
https://issues.apache.org/jira/browse/ZOOKEEPER-2230?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Deepesh Reja updated ZOOKEEPER-2230:
Environment:
OS: RHEL6
Java: 1.8.0_40
Configuration:
java.env:
{noformat}
SERVER_JVMFLAGS="$SERVER_JVMFLAGS -Xmx5120m"
SERVER_JVMFLAGS="$SERVER_JVMFLAGS
-Djava.security.auth.login.config=/local/apps/zookeeper-test1/conf/jaas-server.conf"
SERVER_JVMFLAGS="$SERVER_JVMFLAGS -Dsun.security.jgss.native=true"
{noformat}
jaas-server.conf:
{noformat}
Server {
com.sun.security.auth.module.Krb5LoginModule required
useKeyTab=true
isInitiator=false
principal="zookeeper/@";
};
{noformat}
Process environment:
{noformat}
KRB5_KTNAME=/local/apps/zookeeper-test1/conf/keytab
ZOO_LOG_DIR=/local/apps/zookeeper-test1/log
ZOOCFGDIR=/local/apps/zookeeper-test1/conf
{noformat}
was:
OS: RHEL6
Java: 1.8.0_40
Configuration:
java.env:
{quote}
SERVER_JVMFLAGS="$SERVER_JVMFLAGS -Xmx5120m"
SERVER_JVMFLAGS="$SERVER_JVMFLAGS
-Djava.security.auth.login.config=/local/apps/zookeeper-test1/conf/jaas-server.conf"
SERVER_JVMFLAGS="$SERVER_JVMFLAGS -Dsun.security.jgss.native=true"
{quote}
jaas-server.conf:
{quote}
Server {
com.sun.security.auth.module.Krb5LoginModule required
useKeyTab=true
isInitiator=false
principal="zookeeper/@UNIX.DESHAW.COM";
};
{quote}
Process environment:
{quote}
KRB5_KTNAME=/local/apps/zookeeper-test1/conf/keytab
ZOO_LOG_DIR=/local/apps/zookeeper-test1/log
ZOOCFGDIR=/local/apps/zookeeper-test1/conf
{quote}
> Connections fo ZooKeeper server becomes slow over time with native GSSAPI
> -
>
> Key: ZOOKEEPER-2230
> URL: https://issues.apache.org/jira/browse/ZOOKEEPER-2230
> Project: ZooKeeper
> Issue Type: Bug
> Components: server
>Affects Versions: 3.4.6
> Environment: OS: RHEL6
> Java: 1.8.0_40
> Configuration:
> java.env:
> {noformat}
> SERVER_JVMFLAGS="$SERVER_JVMFLAGS -Xmx5120m"
> SERVER_JVMFLAGS="$SERVER_JVMFLAGS
> -Djava.security.auth.login.config=/local/apps/zookeeper-test1/conf/jaas-server.conf"
> SERVER_JVMFLAGS="$SERVER_JVMFLAGS -Dsun.security.jgss.native=true"
> {noformat}
> jaas-server.conf:
> {noformat}
> Server {
> com.sun.security.auth.module.Krb5LoginModule required
> useKeyTab=true
> isInitiator=false
> principal="zookeeper/@";
> };
> {noformat}
> Process environment:
> {noformat}
> KRB5_KTNAME=/local/apps/zookeeper-test1/conf/keytab
> ZOO_LOG_DIR=/local/apps/zookeeper-test1/log
> ZOOCFGDIR=/local/apps/zookeeper-test1/conf
> {noformat}
>Reporter: Deepesh Reja
>
> ZooKeeper server becomes slow over time when native GSSAPI is used. The
> connection to the server starts taking upto 10 seconds.
> This is happening with ZooKeeper-3.4.6 and is fairly reproducible.
> Debug logs:
> {noformat}
> 2015-07-02 00:58:49,318 [myid:] - INFO
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:NIOServerCnxnFactory@197] -
> Accepted socket connection from /:47942
> 2015-07-02 00:58:49,318 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@78] -
> serviceHostname is ''
> 2015-07-02 00:58:49,318 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@79] -
> servicePrincipalName is 'zookeeper'
> 2015-07-02 00:58:49,318 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@80] - SASL
> mechanism(mech) is 'GSSAPI'
> 2015-07-02 00:58:49,324 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperSaslServer@106] - Added
> private credential to subject: [GSSCredential:
> zookeeper@ 1.2.840.113554.1.2.2 Accept [class
> sun.security.jgss.wrapper.GSSCredElement]]
> 2015-07-02 00:58:59,441 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@810] - Session
> establishment request from client /:47942 client's lastZxid is 0x0
> 2015-07-02 00:58:59,441 [myid:] - INFO
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@868] - Client
> attempting to establish new session at /:47942
> 2015-07-02 00:58:59,448 [myid:] - DEBUG
> [SyncThread:0:FinalRequestProcessor@88] - Processing request::
> sessionid:0x14e486028785c81 type:createSession cxid:0x0 zxid:0x110e79
> txntype:-10 reqpath:n/a
> 2015-07-02 00:58:59,448 [myid:] - DEBUG
> [SyncThread:0:FinalRequestProcessor@160] - sessionid:0x14e486028785c81
> type:createSession cxid:0x0 zxid:0x110e79 txntype:-10 reqpath:n/a
> 2015-07-02 00:58:59,448 [myid:] - INFO [SyncThread:0:ZooKeeperServer@617] -
> Established session 0x14e486028785c81 with negotiated timeout 1 for
> client /:47942
> 2015-07-02 00:58:59,452 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKeeperServer@949] - Responding
> to client SASL token.
> 2015-07-02 00:58:59,452 [myid:] - DEBUG
> [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:42405:ZooKee
