ZooKeeper
  1. ZooKeeper
  2. ZOOKEEPER-1657

Increased CPU usage by unnecessary SASL checks

    Details

      Description

      I did some profiling in one of our Java environments and found an interesting footprint in ZooKeeper. The SASL support seems to trigger a lot times on the client although it's not even in use.

      Is there a switch to disable SASL completely?

      The attached screenshot shows a 10-minute profiling session on one of our production Jetty servers. The Jetty server handles ~1k web requests per minute. The average response time per web request is a few milli seconds. The profiling was performed on a machine running for >24h.

      We noticed a significant CPU increase on our servers when deploying an update from ZooKeeper 3.3.2 to ZooKeeper 3.4.5. Thus, we started investigating. The screenshot shows that only 32% CPU time are spent in Jetty. In contrast, 65% are spend in ZooKeeper.

      A few notes/thoughts:

      • ClientCnxn$SendThread.clientTunneledAuthenticationInProgress seems to be the culprit
      • javax.security.auth.login.Configuration.getConfiguration seems to be called very often?
      • There is quite a bit reflection involved in java.security.AccessController.doPrivileged
      • No security manager is active in the JVM: I tend to place an if-check in the code before calling AccessController.doPrivileged. When no SM is installed, the runnable can be called directly which safes cycles.
      1. zookeeper-hotspot-gone.png
        23 kB
        Gunnar Wagenknecht
      2. zookeeper-hotspot.png
        89 kB
        Gunnar Wagenknecht
      3. ZOOKEEPER-1657.patch
        2 kB
        Eugene Koontz
      4. ZOOKEEPER-1657.patch
        4 kB
        Eugene Koontz
      5. ZOOKEEPER-1657.patch
        4 kB
        Eugene Koontz
      6. ZOOKEEPER-1657.patch
        6 kB
        Philip K. Warren
      7. ZOOKEEPER-1657.patch
        6 kB
        Flavio Junqueira
      8. ZOOKEEPER-1657.patch
        8 kB
        Flavio Junqueira
      9. ZOOKEEPER-1657.patch
        7 kB
        Flavio Junqueira

        Issue Links

          Activity

          Transition Time In Source Status Execution Times Last Executer Last Execution Date
          Patch Available Patch Available Open Open
          185d 1h 37m 4 Flavio Junqueira 18/Sep/13 10:31
          Open Open Patch Available Patch Available
          15d 15h 9m 5 Flavio Junqueira 18/Sep/13 10:32
          Patch Available Patch Available Resolved Resolved
          1h 26m 1 Flavio Junqueira 18/Sep/13 11:58
          Resolved Resolved Closed Closed
          176d 7h 17m 1 Flavio Junqueira 13/Mar/14 18:16
          Flavio Junqueira made changes -
          Status Resolved [ 5 ] Closed [ 6 ]
          Hide
          Flavio Junqueira added a comment -

          Closing issues after releasing 3.4.6.

          Show
          Flavio Junqueira added a comment - Closing issues after releasing 3.4.6.
          Kuba Skopal made changes -
          Link This issue supercedes ZOOKEEPER-1764 [ ZOOKEEPER-1764 ]
          Hide
          Hudson added a comment -

          SUCCESS: Integrated in ZooKeeper-trunk #2060 (See https://builds.apache.org/job/ZooKeeper-trunk/2060/)
          ZOOKEEPER-1657. Increased CPU usage by unnecessary SASL checks (Philip K. Warren via fpj) (fpj: http://svn.apache.org/viewcvs.cgi/?root=Apache-SVN&view=rev&rev=1524364)

          • /zookeeper/trunk/CHANGES.txt
          • /zookeeper/trunk/src/java/main/org/apache/zookeeper/ClientCnxn.java
          • /zookeeper/trunk/src/java/main/org/apache/zookeeper/client/ZooKeeperSaslClient.java
          • /zookeeper/trunk/src/java/test/org/apache/zookeeper/test/SaslClientTest.java
          Show
          Hudson added a comment - SUCCESS: Integrated in ZooKeeper-trunk #2060 (See https://builds.apache.org/job/ZooKeeper-trunk/2060/ ) ZOOKEEPER-1657 . Increased CPU usage by unnecessary SASL checks (Philip K. Warren via fpj) (fpj: http://svn.apache.org/viewcvs.cgi/?root=Apache-SVN&view=rev&rev=1524364 ) /zookeeper/trunk/CHANGES.txt /zookeeper/trunk/src/java/main/org/apache/zookeeper/ClientCnxn.java /zookeeper/trunk/src/java/main/org/apache/zookeeper/client/ZooKeeperSaslClient.java /zookeeper/trunk/src/java/test/org/apache/zookeeper/test/SaslClientTest.java
          Flavio Junqueira made changes -
          Status Patch Available [ 10002 ] Resolved [ 5 ]
          Resolution Fixed [ 1 ]
          Hide
          Flavio Junqueira added a comment -

          Trunk: Committed revision 1524364.

          Show
          Flavio Junqueira added a comment - Trunk: Committed revision 1524364.
          Hide
          Flavio Junqueira added a comment -

          b3.4: Committed revision 1524355.

          Show
          Flavio Junqueira added a comment - b3.4: Committed revision 1524355.
          Hide
          Hadoop QA added a comment -

          +1 overall. Here are the results of testing the latest attachment
          http://issues.apache.org/jira/secure/attachment/12603798/ZOOKEEPER-1657.patch
          against trunk revision 1524275.

          +1 @author. The patch does not contain any @author tags.

          +1 tests included. The patch appears to include 3 new or modified tests.

          +1 javadoc. The javadoc tool did not generate any warning messages.

          +1 javac. The applied patch does not increase the total number of javac compiler warnings.

          +1 findbugs. The patch does not introduce any new Findbugs (version 1.3.9) warnings.

          +1 release audit. The applied patch does not increase the total number of release audit warnings.

          +1 core tests. The patch passed core unit tests.

          +1 contrib tests. The patch passed contrib unit tests.

          Test results: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1587//testReport/
          Findbugs warnings: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1587//artifact/trunk/build/test/findbugs/newPatchFindbugsWarnings.html
          Console output: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1587//console

          This message is automatically generated.

          Show
          Hadoop QA added a comment - +1 overall. Here are the results of testing the latest attachment http://issues.apache.org/jira/secure/attachment/12603798/ZOOKEEPER-1657.patch against trunk revision 1524275. +1 @author. The patch does not contain any @author tags. +1 tests included. The patch appears to include 3 new or modified tests. +1 javadoc. The javadoc tool did not generate any warning messages. +1 javac. The applied patch does not increase the total number of javac compiler warnings. +1 findbugs. The patch does not introduce any new Findbugs (version 1.3.9) warnings. +1 release audit. The applied patch does not increase the total number of release audit warnings. +1 core tests. The patch passed core unit tests. +1 contrib tests. The patch passed contrib unit tests. Test results: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1587//testReport/ Findbugs warnings: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1587//artifact/trunk/build/test/findbugs/newPatchFindbugsWarnings.html Console output: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1587//console This message is automatically generated.
          Flavio Junqueira made changes -
          Status Open [ 1 ] Patch Available [ 10002 ]
          Hide
          Flavio Junqueira added a comment -

          Just run through QA to make sure.

          Show
          Flavio Junqueira added a comment - Just run through QA to make sure.
          Flavio Junqueira made changes -
          Attachment ZOOKEEPER-1657.patch [ 12603798 ]
          Flavio Junqueira made changes -
          Status Patch Available [ 10002 ] Open [ 1 ]
          Hide
          Rakesh R added a comment -

          Thanks Flavio Junqueira +1 from me, please go ahead

          Show
          Rakesh R added a comment - Thanks Flavio Junqueira +1 from me, please go ahead
          Hide
          Flavio Junqueira added a comment -

          Thanks, I'll make sure not to add the .project file and upload the committed patch without it.

          Show
          Flavio Junqueira added a comment - Thanks, I'll make sure not to add the .project file and upload the committed patch without it.
          Hide
          Rakesh R added a comment -

          I was out of station for few days. Sorry for the delay.

          In latest patch I could see the following, is it required?. Otw the patch is ready to go in.

          Index: .project
          ===================================================================
          --- .project	(revision 0)
          +++ .project	(revision 0)
          @@ -0,0 +1,11 @@
          +<?xml version="1.0" encoding="UTF-8"?>
          +<projectDescription>
          +	<name>zookeeper-1657-trunk</name>
          +	<comment></comment>
          +	<projects>
          +	</projects>
          +	<buildSpec>
          +	</buildSpec>
          +	<natures>
          +	</natures>
          +</projectDescription>
          
          Show
          Rakesh R added a comment - I was out of station for few days. Sorry for the delay. In latest patch I could see the following, is it required?. Otw the patch is ready to go in. Index: .project =================================================================== --- .project (revision 0) +++ .project (revision 0) @@ -0,0 +1,11 @@ +<?xml version= "1.0" encoding= "UTF-8" ?> +<projectDescription> + <name>zookeeper-1657-trunk</name> + <comment></comment> + <projects> + </projects> + <buildSpec> + </buildSpec> + <natures> + </natures> +</projectDescription>
          Hide
          Flavio Junqueira added a comment -

          Rakesh R, Could you let me know if you have any other concern here, please? Otherwise, I'm going to get this in, since I have a +1 from Mahadev konar already.

          Show
          Flavio Junqueira added a comment - Rakesh R , Could you let me know if you have any other concern here, please? Otherwise, I'm going to get this in, since I have a +1 from Mahadev konar already.
          Hide
          Flavio Junqueira added a comment -

          Is this one ready to go? Can I get a +1, please?

          Show
          Flavio Junqueira added a comment - Is this one ready to go? Can I get a +1, please?
          Hide
          Hadoop QA added a comment -

          +1 overall. Here are the results of testing the latest attachment
          http://issues.apache.org/jira/secure/attachment/12602860/ZOOKEEPER-1657.patch
          against trunk revision 1522079.

          +1 @author. The patch does not contain any @author tags.

          +1 tests included. The patch appears to include 3 new or modified tests.

          +1 javadoc. The javadoc tool did not generate any warning messages.

          +1 javac. The applied patch does not increase the total number of javac compiler warnings.

          +1 findbugs. The patch does not introduce any new Findbugs (version 1.3.9) warnings.

          +1 release audit. The applied patch does not increase the total number of release audit warnings.

          +1 core tests. The patch passed core unit tests.

          +1 contrib tests. The patch passed contrib unit tests.

          Test results: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1574//testReport/
          Findbugs warnings: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1574//artifact/trunk/build/test/findbugs/newPatchFindbugsWarnings.html
          Console output: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1574//console

          This message is automatically generated.

          Show
          Hadoop QA added a comment - +1 overall. Here are the results of testing the latest attachment http://issues.apache.org/jira/secure/attachment/12602860/ZOOKEEPER-1657.patch against trunk revision 1522079. +1 @author. The patch does not contain any @author tags. +1 tests included. The patch appears to include 3 new or modified tests. +1 javadoc. The javadoc tool did not generate any warning messages. +1 javac. The applied patch does not increase the total number of javac compiler warnings. +1 findbugs. The patch does not introduce any new Findbugs (version 1.3.9) warnings. +1 release audit. The applied patch does not increase the total number of release audit warnings. +1 core tests. The patch passed core unit tests. +1 contrib tests. The patch passed contrib unit tests. Test results: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1574//testReport/ Findbugs warnings: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1574//artifact/trunk/build/test/findbugs/newPatchFindbugsWarnings.html Console output: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1574//console This message is automatically generated.
          Flavio Junqueira made changes -
          Status Open [ 1 ] Patch Available [ 10002 ]
          Flavio Junqueira made changes -
          Attachment ZOOKEEPER-1657.patch [ 12602860 ]
          Hide
          Flavio Junqueira added a comment -

          Added missing license header and messages to assert statements.

          Show
          Flavio Junqueira added a comment - Added missing license header and messages to assert statements.
          Flavio Junqueira made changes -
          Status Patch Available [ 10002 ] Open [ 1 ]
          Hide
          Rakesh R added a comment -

          Sorry to pitch in late. Patch looks nice.

          Adding few observations about the patch:

          1. missing apache license headers in SaslClientTest.java
          2. its good practise to give 'error message while asserting' and would help in analysing failure logs.
            For example:
            Assert.assertTrue("Didn't enabled ZooKeeperSaslClient!", ZooKeeperSaslClient.isEnabled());
            
          Show
          Rakesh R added a comment - Sorry to pitch in late. Patch looks nice. Adding few observations about the patch: missing apache license headers in SaslClientTest.java its good practise to give 'error message while asserting' and would help in analysing failure logs. For example: Assert.assertTrue( "Didn't enabled ZooKeeperSaslClient!" , ZooKeeperSaslClient.isEnabled());
          Hide
          Mahadev konar added a comment -

          +1 for the patch. Looks good. Thanks Eugene/Flavio.

          Show
          Mahadev konar added a comment - +1 for the patch. Looks good. Thanks Eugene/Flavio.
          Hide
          Flavio Junqueira added a comment -

          Can I get a +1 here please?

          Show
          Flavio Junqueira added a comment - Can I get a +1 here please?
          Hide
          Hadoop QA added a comment -

          +1 overall. Here are the results of testing the latest attachment
          http://issues.apache.org/jira/secure/attachment/12601126/ZOOKEEPER-1657.patch
          against trunk revision 1519515.

          +1 @author. The patch does not contain any @author tags.

          +1 tests included. The patch appears to include 3 new or modified tests.

          +1 javadoc. The javadoc tool did not generate any warning messages.

          +1 javac. The applied patch does not increase the total number of javac compiler warnings.

          +1 findbugs. The patch does not introduce any new Findbugs (version 1.3.9) warnings.

          +1 release audit. The applied patch does not increase the total number of release audit warnings.

          +1 core tests. The patch passed core unit tests.

          +1 contrib tests. The patch passed contrib unit tests.

          Test results: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1554//testReport/
          Findbugs warnings: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1554//artifact/trunk/build/test/findbugs/newPatchFindbugsWarnings.html
          Console output: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1554//console

          This message is automatically generated.

          Show
          Hadoop QA added a comment - +1 overall. Here are the results of testing the latest attachment http://issues.apache.org/jira/secure/attachment/12601126/ZOOKEEPER-1657.patch against trunk revision 1519515. +1 @author. The patch does not contain any @author tags. +1 tests included. The patch appears to include 3 new or modified tests. +1 javadoc. The javadoc tool did not generate any warning messages. +1 javac. The applied patch does not increase the total number of javac compiler warnings. +1 findbugs. The patch does not introduce any new Findbugs (version 1.3.9) warnings. +1 release audit. The applied patch does not increase the total number of release audit warnings. +1 core tests. The patch passed core unit tests. +1 contrib tests. The patch passed contrib unit tests. Test results: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1554//testReport/ Findbugs warnings: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1554//artifact/trunk/build/test/findbugs/newPatchFindbugsWarnings.html Console output: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1554//console This message is automatically generated.
          Flavio Junqueira made changes -
          Status Open [ 1 ] Patch Available [ 10002 ]
          Flavio Junqueira made changes -
          Attachment ZOOKEEPER-1657.patch [ 12601126 ]
          Flavio Junqueira made changes -
          Status Patch Available [ 10002 ] Open [ 1 ]
          Hide
          Flavio Junqueira added a comment -

          I'd like to propose a small change to the name of the test class. I think it looks nicer to get it clustered with the other SASL test classes. Feel free to disagree, though. I'm uploading a patch with this change.

          Show
          Flavio Junqueira added a comment - I'd like to propose a small change to the name of the test class. I think it looks nicer to get it clustered with the other SASL test classes. Feel free to disagree, though. I'm uploading a patch with this change.
          Flavio Junqueira made changes -
          Assignee Philip K. Warren [ pkwarren ]
          Flavio Junqueira made changes -
          Assignee Eugene Koontz [ ekoontz ]
          Hide
          Hadoop QA added a comment -

          +1 overall. Here are the results of testing the latest attachment
          http://issues.apache.org/jira/secure/attachment/12598620/ZOOKEEPER-1657.patch
          against trunk revision 1516126.

          +1 @author. The patch does not contain any @author tags.

          +1 tests included. The patch appears to include 3 new or modified tests.

          +1 javadoc. The javadoc tool did not generate any warning messages.

          +1 javac. The applied patch does not increase the total number of javac compiler warnings.

          +1 findbugs. The patch does not introduce any new Findbugs (version 1.3.9) warnings.

          +1 release audit. The applied patch does not increase the total number of release audit warnings.

          +1 core tests. The patch passed core unit tests.

          +1 contrib tests. The patch passed contrib unit tests.

          Test results: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1547//testReport/
          Findbugs warnings: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1547//artifact/trunk/build/test/findbugs/newPatchFindbugsWarnings.html
          Console output: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1547//console

          This message is automatically generated.

          Show
          Hadoop QA added a comment - +1 overall. Here are the results of testing the latest attachment http://issues.apache.org/jira/secure/attachment/12598620/ZOOKEEPER-1657.patch against trunk revision 1516126. +1 @author. The patch does not contain any @author tags. +1 tests included. The patch appears to include 3 new or modified tests. +1 javadoc. The javadoc tool did not generate any warning messages. +1 javac. The applied patch does not increase the total number of javac compiler warnings. +1 findbugs. The patch does not introduce any new Findbugs (version 1.3.9) warnings. +1 release audit. The applied patch does not increase the total number of release audit warnings. +1 core tests. The patch passed core unit tests. +1 contrib tests. The patch passed contrib unit tests. Test results: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1547//testReport/ Findbugs warnings: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1547//artifact/trunk/build/test/findbugs/newPatchFindbugsWarnings.html Console output: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1547//console This message is automatically generated.
          Flavio Junqueira made changes -
          Status Open [ 1 ] Patch Available [ 10002 ]
          Hide
          Flavio Junqueira added a comment -

          Submitting patch to let it run through jenkins.

          Show
          Flavio Junqueira added a comment - Submitting patch to let it run through jenkins.
          Philip K. Warren made changes -
          Attachment ZOOKEEPER-1657.patch [ 12598620 ]
          Hide
          Philip K. Warren added a comment -

          I have taken Eugene's patch and applied it to ZooKeeper trunk (hope this is ok). I moved the logic to check if the SASL client was enabled to a static method, and added a test to verify the behavior (that the SASL client is enabled by default).

          Show
          Philip K. Warren added a comment - I have taken Eugene's patch and applied it to ZooKeeper trunk (hope this is ok). I moved the logic to check if the SASL client was enabled to a static method, and added a test to verify the behavior (that the SASL client is enabled by default).
          Flavio Junqueira made changes -
          Status Patch Available [ 10002 ] Open [ 1 ]
          Hide
          Flavio Junqueira added a comment -

          The patch didn't apply cleanly to trunk, could you upload a new patch, please?

          Show
          Flavio Junqueira added a comment - The patch didn't apply cleanly to trunk, could you upload a new patch, please?
          Hide
          Hadoop QA added a comment -

          -1 overall. Here are the results of testing the latest attachment
          http://issues.apache.org/jira/secure/attachment/12571944/zookeeper-hotspot-gone.png
          against trunk revision 1463329.

          +1 @author. The patch does not contain any @author tags.

          -1 tests included. The patch doesn't appear to include any new or modified tests.
          Please justify why no new tests are needed for this patch.
          Also please list what manual steps were performed to verify this patch.

          -1 patch. The patch command could not apply the patch.

          Console output: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1477//console

          This message is automatically generated.

          Show
          Hadoop QA added a comment - -1 overall. Here are the results of testing the latest attachment http://issues.apache.org/jira/secure/attachment/12571944/zookeeper-hotspot-gone.png against trunk revision 1463329. +1 @author. The patch does not contain any @author tags. -1 tests included. The patch doesn't appear to include any new or modified tests. Please justify why no new tests are needed for this patch. Also please list what manual steps were performed to verify this patch. -1 patch. The patch command could not apply the patch. Console output: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1477//console This message is automatically generated.
          Patrick Hunt made changes -
          Assignee Eugene Koontz [ ekoontz ]
          Hide
          Germán Blanco added a comment -

          If I am not wrong, this patch also solves the problem of the continuous SecurityException loggging.

          Show
          Germán Blanco added a comment - If I am not wrong, this patch also solves the problem of the continuous SecurityException loggging.
          Germán Blanco made changes -
          Link This issue contains ZOOKEEPER-1623 [ ZOOKEEPER-1623 ]
          Germán Blanco made changes -
          Link This issue contains ZOOKEEPER-1512 [ ZOOKEEPER-1512 ]
          Hide
          Eugene Koontz added a comment -

          Regarding: "Please justify why no new tests are needed for this patch."

          This is an optimization that avoids some unnecessary code execution. No bugs are fixed and no new behavior is introduced that would require additional testing.

          Show
          Eugene Koontz added a comment - Regarding: "Please justify why no new tests are needed for this patch." This is an optimization that avoids some unnecessary code execution. No bugs are fixed and no new behavior is introduced that would require additional testing.
          Hide
          Eugene Koontz added a comment -

          Thanks for reporting back Gunnar! Good to hear that this patch fixes the hotspot.

          Show
          Eugene Koontz added a comment - Thanks for reporting back Gunnar! Good to hear that this patch fixes the hotspot.
          Hide
          Hadoop QA added a comment -

          -1 overall. Here are the results of testing the latest attachment
          http://issues.apache.org/jira/secure/attachment/12571944/zookeeper-hotspot-gone.png
          against trunk revision 1448007.

          +1 @author. The patch does not contain any @author tags.

          -1 tests included. The patch doesn't appear to include any new or modified tests.
          Please justify why no new tests are needed for this patch.
          Also please list what manual steps were performed to verify this patch.

          -1 patch. The patch command could not apply the patch.

          Console output: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1421//console

          This message is automatically generated.

          Show
          Hadoop QA added a comment - -1 overall. Here are the results of testing the latest attachment http://issues.apache.org/jira/secure/attachment/12571944/zookeeper-hotspot-gone.png against trunk revision 1448007. +1 @author. The patch does not contain any @author tags. -1 tests included. The patch doesn't appear to include any new or modified tests. Please justify why no new tests are needed for this patch. Also please list what manual steps were performed to verify this patch. -1 patch. The patch command could not apply the patch. Console output: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1421//console This message is automatically generated.
          Gunnar Wagenknecht made changes -
          Attachment zookeeper-hotspot-gone.png [ 12571944 ]
          Hide
          Gunnar Wagenknecht added a comment -

          After deploying the fix on a separate node and profiling again (similar workload, similar conditions) I can confirm that ZooKeeper is no longer a hot-spot.

          Show
          Gunnar Wagenknecht added a comment - After deploying the fix on a separate node and profiling again (similar workload, similar conditions) I can confirm that ZooKeeper is no longer a hot-spot.
          Mahadev konar made changes -
          Fix Version/s 3.5.0 [ 12316644 ]
          Fix Version/s 3.4.6 [ 12323310 ]
          Hide
          Hadoop QA added a comment -

          -1 overall. Here are the results of testing the latest attachment
          http://issues.apache.org/jira/secure/attachment/12571652/ZOOKEEPER-1657.patch
          against trunk revision 1448007.

          +1 @author. The patch does not contain any @author tags.

          -1 tests included. The patch doesn't appear to include any new or modified tests.
          Please justify why no new tests are needed for this patch.
          Also please list what manual steps were performed to verify this patch.

          +1 javadoc. The javadoc tool did not generate any warning messages.

          +1 javac. The applied patch does not increase the total number of javac compiler warnings.

          +1 findbugs. The patch does not introduce any new Findbugs (version 1.3.9) warnings.

          +1 release audit. The applied patch does not increase the total number of release audit warnings.

          +1 core tests. The patch passed core unit tests.

          +1 contrib tests. The patch passed contrib unit tests.

          Test results: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1413//testReport/
          Findbugs warnings: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1413//artifact/trunk/build/test/findbugs/newPatchFindbugsWarnings.html
          Console output: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1413//console

          This message is automatically generated.

          Show
          Hadoop QA added a comment - -1 overall. Here are the results of testing the latest attachment http://issues.apache.org/jira/secure/attachment/12571652/ZOOKEEPER-1657.patch against trunk revision 1448007. +1 @author. The patch does not contain any @author tags. -1 tests included. The patch doesn't appear to include any new or modified tests. Please justify why no new tests are needed for this patch. Also please list what manual steps were performed to verify this patch. +1 javadoc. The javadoc tool did not generate any warning messages. +1 javac. The applied patch does not increase the total number of javac compiler warnings. +1 findbugs. The patch does not introduce any new Findbugs (version 1.3.9) warnings. +1 release audit. The applied patch does not increase the total number of release audit warnings. +1 core tests. The patch passed core unit tests. +1 contrib tests. The patch passed contrib unit tests. Test results: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1413//testReport/ Findbugs warnings: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1413//artifact/trunk/build/test/findbugs/newPatchFindbugsWarnings.html Console output: https://builds.apache.org/job/PreCommit-ZOOKEEPER-Build/1413//console This message is automatically generated.
          Eugene Koontz made changes -
          Status Open [ 1 ] Patch Available [ 10002 ]
          Eugene Koontz made changes -
          Attachment ZOOKEEPER-1657.patch [ 12571652 ]
          Hide
          Eugene Koontz added a comment -

          Incorporate Gunnar's fix : use <string>.equals(<string>), not <string>==<string>.

          Show
          Eugene Koontz added a comment - Incorporate Gunnar's fix : use <string>.equals(<string>), not <string>==<string>.
          Eugene Koontz made changes -
          Attachment ZOOKEEPER-1657.patch [ 12571651 ]
          Hide
          Eugene Koontz added a comment -

          Add new zookeeper.sasl.client system property. True by default; set to "false" to disable SASL on client.

          Show
          Eugene Koontz added a comment - Add new zookeeper.sasl.client system property. True by default; set to "false" to disable SASL on client.
          Hide
          Gunnar Wagenknecht added a comment -

          I got ZooKeeper running using the following additional changes:

          ===================================================================
          --- src/org/apache/zookeeper/ClientCnxn.java	(first patched version)
          +++ src/org/apache/zookeeper/ClientCnxn.java	(working copy)
          @@ -939,7 +939,7 @@
           
                       setName(getName().replaceAll("\\(.*\\)",
                               "(" + addr.getHostName() + ":" + addr.getPort() + ")"));
          -            if (System.getProperty("zookeeper.client.sasl","false") == "true") {
          +            if (System.getProperty("zookeeper.client.sasl","false").equals("true")) {
                           try {
                               zooKeeperSaslClient = new ZooKeeperSaslClient("zookeeper/"+addr.getHostName());
                           } catch (LoginException e) {
          @@ -1234,9 +1234,10 @@
                       }
           
                       // 2. SendThread has not created the authenticating object yet,
          -            // therefore authentication is (at the earliest stage of being) in progress.
          +            // therefore authentication is (at the earliest stage of being) in progress;
          +            // but only if SASL is actually in use.
                       if (zooKeeperSaslClient == null) {
          -                return true;
          +                return System.getProperty("zookeeper.client.sasl","false").equals("true");
                       }
           
                       // 3. authenticating object exists, so ask it for its progress.
          
          Show
          Gunnar Wagenknecht added a comment - I got ZooKeeper running using the following additional changes: =================================================================== --- src/org/apache/zookeeper/ClientCnxn.java (first patched version) +++ src/org/apache/zookeeper/ClientCnxn.java (working copy) @@ -939,7 +939,7 @@ setName(getName().replaceAll("\\(.*\\)", "(" + addr.getHostName() + ":" + addr.getPort() + ")")); - if (System.getProperty("zookeeper.client.sasl","false") == "true") { + if (System.getProperty("zookeeper.client.sasl","false").equals("true")) { try { zooKeeperSaslClient = new ZooKeeperSaslClient("zookeeper/"+addr.getHostName()); } catch (LoginException e) { @@ -1234,9 +1234,10 @@ } // 2. SendThread has not created the authenticating object yet, - // therefore authentication is (at the earliest stage of being) in progress. + // therefore authentication is (at the earliest stage of being) in progress; + // but only if SASL is actually in use. if (zooKeeperSaslClient == null) { - return true; + return System.getProperty("zookeeper.client.sasl","false").equals("true"); } // 3. authenticating object exists, so ask it for its progress.
          Hide
          Gunnar Wagenknecht added a comment -

          The patch does not seem to work:

          22:03:12.589 [ZooKeeper Gate Connect Thread-SendThread(127.0.0.1:2181)] DEBUG o.a.zookeeper.ClientCnxnSocketNIO - deferring non-priming packet: clientPath:null serverPath:null finished:false header:: 0,4  replyHeader:: 0,0,0  request:: '/gyrex/nodes/all/98e14413-6157-440a-aa49-9c61c70099d9,F  response::  until SASL authentication completes.
          22:03:17.899 [ZooKeeper Gate Connect Thread-SendThread(127.0.0.1:2181)] DEBUG o.a.zookeeper.ClientCnxnSocketNIO - deferring non-priming packet: clientPath:null serverPath:null finished:false header:: 0,4  replyHeader:: 0,0,0  request:: '/gyrex/nodes/all/98e14413-6157-440a-aa49-9c61c70099d9,F  response::  until SASL authentication completes.
          22:03:17.901 [ZooKeeper Gate Connect Thread-SendThread(127.0.0.1:2181)] DEBUG o.a.zookeeper.ClientCnxnSocketNIO - deferring non-priming packet: clientPath:null serverPath:null finished:false header:: 0,4  replyHeader:: 0,0,0  request:: '/gyrex/nodes/all/98e14413-6157-440a-aa49-9c61c70099d9,F  response::  until SASL authentication completes.
          22:03:17.902 [ZooKeeper Gate Connect Thread-SendThread(127.0.0.1:2181)] DEBUG o.a.zookeeper.ClientCnxnSocketNIO - deferring non-priming packet: clientPath:null serverPath:null finished:false header:: -2,11  replyHeader:: null request:: null response:: nulluntil SASL authentication completes.
          22:03:27.902 [ZooKeeper Gate Connect Thread-SendThread(127.0.0.1:2181)] DEBUG o.a.zookeeper.ClientCnxnSocketNIO - deferring non-priming packet: clientPath:null serverPath:null finished:false header:: 0,4  replyHeader:: 0,0,0  request:: '/gyrex/nodes/all/98e14413-6157-440a-aa49-9c61c70099d9,F  response::  until SASL authentication completes.
          22:03:27.904 [ZooKeeper Gate Connect Thread-SendThread(127.0.0.1:2181)] DEBUG o.a.zookeeper.ClientCnxnSocketNIO - deferring non-priming packet: clientPath:null serverPath:null finished:false header:: -2,11  replyHeader:: null request:: null response:: nulluntil SASL authentication completes.
          22:03:27.905 [ZooKeeper Gate Connect Thread-SendThread(127.0.0.1:2181)] DEBUG o.a.zookeeper.ClientCnxnSocketNIO - deferring non-priming packet: clientPath:null serverPath:null finished:false header:: 0,4  replyHeader:: 0,0,0  request:: '/gyrex/nodes/all/98e14413-6157-440a-aa49-9c61c70099d9,F  response::  until SASL authentication completes.
          22:03:27.907 [ZooKeeper Gate Connect Thread-SendThread(127.0.0.1:2181)] DEBUG o.a.zookeeper.ClientCnxnSocketNIO - deferring non-priming packet: clientPath:null serverPath:null finished:false header:: -2,11  replyHeader:: null request:: null response:: nulluntil SASL authentication completes.
          22:03:27.908 [ZooKeeper Gate Connect Thread-SendThread(127.0.0.1:2181)] DEBUG o.a.zookeeper.ClientCnxnSocketNIO - deferring non-priming packet: clientPath:null serverPath:null finished:false header:: -2,11  replyHeader:: null request:: null response:: nulluntil SASL authentication completes.
          22:03:28.059 [ZooKeeper Gate Connect Thread-SendThread(127.0.0.1:2181)] DEBUG o.a.zookeeper.ClientCnxnSocketNIO - deferring non-priming packet: clientPath:null serverPath:null finished:false header:: 0,4  replyHeader:: 0,0,0  request:: '/gyrex/nodes/all/98e14413-6157-440a-aa49-9c61c70099d9,F  response::  until SASL authentication completes.
          22:03:28.060 [ZooKeeper Gate Connect Thread-SendThread(127.0.0.1:2181)] DEBUG o.a.zookeeper.ClientCnxnSocketNIO - deferring non-priming packet: clientPath:null serverPath:null finished:false header:: -2,11  replyHeader:: null request:: null response:: nulluntil SASL authentication completes.
          22:03:28.061 [ZooKeeper Gate Connect Thread-SendThread(127.0.0.1:2181)] DEBUG o.a.zookeeper.ClientCnxnSocketNIO - deferring non-priming packet: clientPath:null serverPath:null finished:false header:: -2,11  replyHeader:: null request:: null response:: nulluntil SASL authentication completes.
          22:03:28.062 [ZooKeeper Gate Connect Thread-SendThread(127.0.0.1:2181)] INFO  org.apache.zookeeper.ClientCnxn - Client session timed out, have not heard from server in 20005ms for sessionid 0x13d27c3d5620000, closing socket connection and attempting reconnect
          22:03:28.077 [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181] WARN  o.a.zookeeper.server.NIOServerCnxn - caught end of stream exception
          org.apache.zookeeper.server.ServerCnxn$EndOfStreamException: Unable to read additional data from client sessionid 0x13d27c3d5620000, likely client has closed socket
          	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
          	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208) 
          	at java.lang.Thread.run(Thread.java:662) [na:1.6.0_26]
          22:03:28.079 [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181] INFO  o.a.zookeeper.server.NIOServerCnxn - Closed socket connection for client /127.0.0.1:51730 which had sessionid 0x13d27c3d5620000
          
          Show
          Gunnar Wagenknecht added a comment - The patch does not seem to work: 22:03:12.589 [ZooKeeper Gate Connect Thread-SendThread(127.0.0.1:2181)] DEBUG o.a.zookeeper.ClientCnxnSocketNIO - deferring non-priming packet: clientPath:null serverPath:null finished:false header:: 0,4 replyHeader:: 0,0,0 request:: '/gyrex/nodes/all/98e14413-6157-440a-aa49-9c61c70099d9,F response:: until SASL authentication completes. 22:03:17.899 [ZooKeeper Gate Connect Thread-SendThread(127.0.0.1:2181)] DEBUG o.a.zookeeper.ClientCnxnSocketNIO - deferring non-priming packet: clientPath:null serverPath:null finished:false header:: 0,4 replyHeader:: 0,0,0 request:: '/gyrex/nodes/all/98e14413-6157-440a-aa49-9c61c70099d9,F response:: until SASL authentication completes. 22:03:17.901 [ZooKeeper Gate Connect Thread-SendThread(127.0.0.1:2181)] DEBUG o.a.zookeeper.ClientCnxnSocketNIO - deferring non-priming packet: clientPath:null serverPath:null finished:false header:: 0,4 replyHeader:: 0,0,0 request:: '/gyrex/nodes/all/98e14413-6157-440a-aa49-9c61c70099d9,F response:: until SASL authentication completes. 22:03:17.902 [ZooKeeper Gate Connect Thread-SendThread(127.0.0.1:2181)] DEBUG o.a.zookeeper.ClientCnxnSocketNIO - deferring non-priming packet: clientPath:null serverPath:null finished:false header:: -2,11 replyHeader:: null request:: null response:: nulluntil SASL authentication completes. 22:03:27.902 [ZooKeeper Gate Connect Thread-SendThread(127.0.0.1:2181)] DEBUG o.a.zookeeper.ClientCnxnSocketNIO - deferring non-priming packet: clientPath:null serverPath:null finished:false header:: 0,4 replyHeader:: 0,0,0 request:: '/gyrex/nodes/all/98e14413-6157-440a-aa49-9c61c70099d9,F response:: until SASL authentication completes. 22:03:27.904 [ZooKeeper Gate Connect Thread-SendThread(127.0.0.1:2181)] DEBUG o.a.zookeeper.ClientCnxnSocketNIO - deferring non-priming packet: clientPath:null serverPath:null finished:false header:: -2,11 replyHeader:: null request:: null response:: nulluntil SASL authentication completes. 22:03:27.905 [ZooKeeper Gate Connect Thread-SendThread(127.0.0.1:2181)] DEBUG o.a.zookeeper.ClientCnxnSocketNIO - deferring non-priming packet: clientPath:null serverPath:null finished:false header:: 0,4 replyHeader:: 0,0,0 request:: '/gyrex/nodes/all/98e14413-6157-440a-aa49-9c61c70099d9,F response:: until SASL authentication completes. 22:03:27.907 [ZooKeeper Gate Connect Thread-SendThread(127.0.0.1:2181)] DEBUG o.a.zookeeper.ClientCnxnSocketNIO - deferring non-priming packet: clientPath:null serverPath:null finished:false header:: -2,11 replyHeader:: null request:: null response:: nulluntil SASL authentication completes. 22:03:27.908 [ZooKeeper Gate Connect Thread-SendThread(127.0.0.1:2181)] DEBUG o.a.zookeeper.ClientCnxnSocketNIO - deferring non-priming packet: clientPath:null serverPath:null finished:false header:: -2,11 replyHeader:: null request:: null response:: nulluntil SASL authentication completes. 22:03:28.059 [ZooKeeper Gate Connect Thread-SendThread(127.0.0.1:2181)] DEBUG o.a.zookeeper.ClientCnxnSocketNIO - deferring non-priming packet: clientPath:null serverPath:null finished:false header:: 0,4 replyHeader:: 0,0,0 request:: '/gyrex/nodes/all/98e14413-6157-440a-aa49-9c61c70099d9,F response:: until SASL authentication completes. 22:03:28.060 [ZooKeeper Gate Connect Thread-SendThread(127.0.0.1:2181)] DEBUG o.a.zookeeper.ClientCnxnSocketNIO - deferring non-priming packet: clientPath:null serverPath:null finished:false header:: -2,11 replyHeader:: null request:: null response:: nulluntil SASL authentication completes. 22:03:28.061 [ZooKeeper Gate Connect Thread-SendThread(127.0.0.1:2181)] DEBUG o.a.zookeeper.ClientCnxnSocketNIO - deferring non-priming packet: clientPath:null serverPath:null finished:false header:: -2,11 replyHeader:: null request:: null response:: nulluntil SASL authentication completes. 22:03:28.062 [ZooKeeper Gate Connect Thread-SendThread(127.0.0.1:2181)] INFO org.apache.zookeeper.ClientCnxn - Client session timed out, have not heard from server in 20005ms for sessionid 0x13d27c3d5620000, closing socket connection and attempting reconnect 22:03:28.077 [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181] WARN o.a.zookeeper.server.NIOServerCnxn - caught end of stream exception org.apache.zookeeper.server.ServerCnxn$EndOfStreamException: Unable to read additional data from client sessionid 0x13d27c3d5620000, likely client has closed socket at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220) at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208) at java.lang.Thread.run(Thread.java:662) [na:1.6.0_26] 22:03:28.079 [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181] INFO o.a.zookeeper.server.NIOServerCnxn - Closed socket connection for client /127.0.0.1:51730 which had sessionid 0x13d27c3d5620000
          Hide
          Gunnar Wagenknecht added a comment -

          Eugene, thanks! I'll try to create a custom build and gather some data.

          Show
          Gunnar Wagenknecht added a comment - Eugene, thanks! I'll try to create a custom build and gather some data.
          Gunnar Wagenknecht made changes -
          Description I did some profiling in one of our Java environments and found an interesting footprint in ZooKeeper. The SASL support seems to trigger a lot times on the client although it's not even in use.

          Is there a switch to disable SASL completely?

          The attached screenshot shows a 10-minute profiling session on one of our production Jetty servers. The Jetty server handles ~1k web requests per minute. The average response time per web request is a few milli seconds. The profiling was performed on a machine running for >24h.

          We noticed a significant CPU increase on our servers when deploying an update from ZooKeeper 3.3.2 to ZooKeeper 3.4.5. Thus, we started investigating. The screenshot shows that only 32% CPU time are spent in Jetty. In contrast, 65% are spend in ZooKeeper.

          A few notes/thoughts:
          * {{ClientCnxn$SendThread.clientTunneledAuthenticationInProgress}} seems to be the culprit
          * {{javax.security.auth.login.Configuration.getConfiguration}} seems to be called very often?
          * There is quite a bit reflection involved in {{java.security.AccessController.doPrivileged}}
          * No security manager is installed; I tend to place an if-check in the code before calling {{AccessController.doPrivileged}}. When no SM is installed, the runnable can be called directly which safes cycles.
          I did some profiling in one of our Java environments and found an interesting footprint in ZooKeeper. The SASL support seems to trigger a lot times on the client although it's not even in use.

          Is there a switch to disable SASL completely?

          The attached screenshot shows a 10-minute profiling session on one of our production Jetty servers. The Jetty server handles ~1k web requests per minute. The average response time per web request is a few milli seconds. The profiling was performed on a machine running for >24h.

          We noticed a significant CPU increase on our servers when deploying an update from ZooKeeper 3.3.2 to ZooKeeper 3.4.5. Thus, we started investigating. The screenshot shows that only 32% CPU time are spent in Jetty. In contrast, 65% are spend in ZooKeeper.

          A few notes/thoughts:
          * {{ClientCnxn$SendThread.clientTunneledAuthenticationInProgress}} seems to be the culprit
          * {{javax.security.auth.login.Configuration.getConfiguration}} seems to be called very often?
          * There is quite a bit reflection involved in {{java.security.AccessController.doPrivileged}}
          * No security manager is active in the JVM: I tend to place an if-check in the code before calling {{AccessController.doPrivileged}}. When no SM is installed, the runnable can be called directly which safes cycles.
          Hide
          Eugene Koontz added a comment -

          Hi Gunnar,
          Thanks for providing this profiling data. I wonder if this patch will improve your profiling results?
          -Eugene

          Show
          Eugene Koontz added a comment - Hi Gunnar, Thanks for providing this profiling data. I wonder if this patch will improve your profiling results? -Eugene
          Eugene Koontz made changes -
          Attachment ZOOKEEPER-1657.patch [ 12571625 ]
          Hide
          Eugene Koontz added a comment -

          Client checks system property zookeeper.client.sasl before creating SASL authentication object to reduce wasted time later in ClientCnxn$SendThread.clientTunneledAuthenticationInProgress().

          Show
          Eugene Koontz added a comment - Client checks system property zookeeper.client.sasl before creating SASL authentication object to reduce wasted time later in ClientCnxn$SendThread.clientTunneledAuthenticationInProgress().
          Gunnar Wagenknecht made changes -
          Description I did some profiling in one of our Java environments and found an interesting footprint in ZooKeeper. The SASL support seems to trigger a lot times on the client although it's not even in use.

          Is there a switch to disable SASL completely?

          The attached screenshot shows a 10-minute profiling session on one of our production Jetty servers. The Jetty server handles ~1k web requests per minute. The average response time per web request is a few milli seconds. However, only 32% CPU time are spent in Jetty. In contrast, 65% are spend in ZooKeeper.

          We noticed a significant CPU increase on our servers when deploying an update from ZooKeeper 3.3.2 to ZooKeeper 3.4.5. Thus, we started investigating.
          I did some profiling in one of our Java environments and found an interesting footprint in ZooKeeper. The SASL support seems to trigger a lot times on the client although it's not even in use.

          Is there a switch to disable SASL completely?

          The attached screenshot shows a 10-minute profiling session on one of our production Jetty servers. The Jetty server handles ~1k web requests per minute. The average response time per web request is a few milli seconds. The profiling was performed on a machine running for >24h.

          We noticed a significant CPU increase on our servers when deploying an update from ZooKeeper 3.3.2 to ZooKeeper 3.4.5. Thus, we started investigating. The screenshot shows that only 32% CPU time are spent in Jetty. In contrast, 65% are spend in ZooKeeper.

          A few notes/thoughts:
          * {{ClientCnxn$SendThread.clientTunneledAuthenticationInProgress}} seems to be the culprit
          * {{javax.security.auth.login.Configuration.getConfiguration}} seems to be called very often?
          * There is quite a bit reflection involved in {{java.security.AccessController.doPrivileged}}
          * No security manager is installed; I tend to place an if-check in the code before calling {{AccessController.doPrivileged}}. When no SM is installed, the runnable can be called directly which safes cycles.
          Gunnar Wagenknecht made changes -
          Summary Wasted CPU cycles be unnecessary SASL checks Increased CPU usage by unnecessary SASL checks
          Hide
          Gunnar Wagenknecht added a comment -

          Note, the profiling was performed on a machine running for >24h. Thus, it's fair to say that the machine has been "warmed", i.e. all classes and stuff should be loaded.

          Show
          Gunnar Wagenknecht added a comment - Note, the profiling was performed on a machine running for >24h. Thus, it's fair to say that the machine has been "warmed", i.e. all classes and stuff should be loaded.
          Gunnar Wagenknecht made changes -
          Field Original Value New Value
          Attachment zookeeper-hotspot.png [ 12571607 ]
          Gunnar Wagenknecht created issue -

            People

            • Assignee:
              Philip K. Warren
              Reporter:
              Gunnar Wagenknecht
            • Votes:
              1 Vote for this issue
              Watchers:
              9 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Development