You are viewing a plain text version of this content. The canonical link for it is here.

Posted to user@zookeeper.apache.org by Will Now <wn...@gmail.com> on 2022/08/27 21:55:37 UTC

Read performance of 3.4.6 vs 3.8.0 according to zookeeper-benchmark

Prior to my server upgrade I'm doing some benchmarking of zookeeper server
3.4.6 and 3.8.0 using zookeeper-benchmark
https://github.com/brownsys/zookeeper-benchmark

Methodology: For each server version I extracted it anew from the tar file
onto my linux box, tweaked zoo.cfg to run a single node. On 3.8.0 I enabled
4 letter words. I run it with a fresh (empty) dataDir.  Using default
settings for zookeeper-benchmark.  (Contrary to best practices) I am
running the server and test client on the same node :-/

I perform 3 runs and show the READ average below. I am focussing just on
READ results here; results are in reads/sec, so bigger numbers are better:

27,052: 3.4.6
16,805: 3.8.0, digest.enabled=true:
16,682: 3.8.0: digest.enabled=false

I saw similar results on a windows box and re-ran on linux for additional
confirmation. I find it hard to believe that 3.8.0 is 40% slower on reads!

A while back I performed similar comparisons of 3.4.6 vs 3.6.x and I got
slow results in 3.6.x initially, but disabling digest.enabled fixed it and
the two versions were then comparable. In 3.8.0 I am seeing poor results
with or without digest enabled.

Any thoughts?  Are there some new settings I need to tweak?  Is my
methodology flawed?

Thanks!

Re: Read performance of 3.4.6 vs 3.8.0 according to zookeeper-benchmark

Posted by Will Now <wn...@gmail.com>.

OK Here are all of the results with both zk server 3.6.3 and 3.7.1 added:
No version beyond 3.4.6 is looking so great ;-/

27,052: 3.4.6
*15,993:3.6.3*
*15,943:3.7.1*
16,805: 3.8.0, digest.enabled=true:
16,682: 3.8.0: digest.enabled=false

The 26,000+ results for 3.4.6 continue to be reproduclible.  Weird right?

Re: Read performance of 3.4.6 vs 3.8.0 according to zookeeper-benchmark

Posted by Andrew Purtell <an...@gmail.com>.

See ZOOKEEPER-1505. It went in at 3.5.0. Later related improvements went in to 3.6.0. 

A single host scenario with one server and one collocated client will observe higher dispatch latency, which will produce lower throughput numbers, due to thread scheduling and context switching which could account for the measured difference.

This is all conjecture on my part so bear that in mind. I’ve not personally done a differential performance analysis of this particular change.

> On Sep 3, 2022, at 8:34 AM, Andrew Purtell <an...@gmail.com> wrote:
> 
> Ok. Then in 3.5 the reorganization of request processors such that reads are served in a multithreaded way may be relevant. In 3.4 all requests - reads and writes - are processed serially. In 3.5 there is a dispatch of reads to a thread pool instead. This kind of change could cause this type of result, a reduction in single client / single connection performance in trade for better multiple client / connection scalability. You can plot throughout results against number of concurrent clients for 3.4 vs 3.5 or later to observe this effect and relative improvements 
> 
> If this is what is going on here, it is a reasonable trade off because in production you won’t be facing a single client you’ll be dispatching requests from many. 
> 
>> On Sep 2, 2022, at 10:17 PM, Will Now <wn...@gmail.com> wrote:
>> 
>> For me. 3.5.10 illustrates a drop from 27K to 18K.   See below:
>> 
>> 27,052: 3.4.6
>> 24,392: 3.4.6 Again
>> 18,429: 3.5.10
>> 15,993: 3.6.3, digest.enabled=true
>> 16,159: 3.6.3, *digest.enabled=false*
>> 15,943: 3.7.1
>> 16,805: 3.8.0, digest.enabled=true:
>> 16,682: 3.8.0: digest.enabled=false
>> 16,370: 3.8.0 NullMetricsProvider, *digest.enabled=false*
>> 
>> I re-ran the 3.4.6 benchmark and got a reduced result for some reason:
>> 24,392. However that value still exceeds the performance of subsequent
>> releases.
>> 
>> Admittedly, this is not a super scientific result set: I'm running 1 node
>> ensemble and the client on the same host.
>> 
>> I would love some thirdparty confirmation of my results for sure.
>> 
>> 
>>>> On Fri, Sep 2, 2022 at 6:32 PM Andrew Purtell <ap...@apache.org> wrote:
>>> 
>>> Did you test with any 3.5 version?
>>> 
>>> Would be curious if the dip starts at 3.6. BlueThrottle and
>>> RequestThrottler both went in at 3.6.0.
>>> 
>>> 
>>> 
>>>> On Tue, Aug 30, 2022 at 1:20 PM Will Now <wn...@gmail.com> wrote:
>>>> 
>>>> I've updated the results summary below to include 3.6.3 with and without
>>>> digest.enabled; they are essentially the same.
>>>> 
>>>> 27,052: 3.4.6
>>>> 15,993: 3.6.3, digest.enabled=true
>>>> 16,159: 3.6.3, *digest.enabled=false*
>>>> 15,943: 3.7.1
>>>> 16,805: 3.8.0, digest.enabled=true:
>>>> 16,682: 3.8.0: digest.enabled=false
>>>> 16,370: 3.8.0 NullMetricsProvider, *digest.enabled=false*
>>>> 
>>>> I'm going to re-run my benchmarks in a 3-node ensemble instead of a local
>>>> singleton. I'll also run the test client on a separate node.  This will
>>>> match the environment I used years ago to measure 3.4.6 against 3.6.x,
>>> when
>>>> I found that digest.enabled was having a big impact (a result that I am
>>> not
>>>> reproducing at present)
>>>> 
>>>> The zookeeper benchmark I am reporting is the number of synchronous
>>>> sequential read operations on a single znode that can be completed in 30
>>>> seconds.  No other transactions take place during the benchmark (ie no
>>>> writes, etc)
>>>> 
>>>> I'm optimistic that the anomaly I am reporting is some issue on my end
>>> and
>>>> not in zookeeper. I'm pretty sure a big drop in performance like this
>>> would
>>>> not have gone unnoticed.  Thanks for the responses. I'll report back!
>>>> 
>>>> On Mon, Aug 29, 2022 at 12:37 AM Szalay-Bekő Máté <
>>>> szalay.beko.mate@gmail.com> wrote:
>>>> 
>>>>> Interesting, thanks for sharing the results!
>>>>> 
>>>>> It will be hard to figure out what changed since the 3.4.6 release.
>>> Many
>>>>> new features added. Still, it would be good to find out which version /
>>>>> commit was responsible for the most performance degradation.
>>>>> 
>>>>> You wrote before:
>>>>>> A while back I performed similar comparisons of 3.4.6 vs 3.6.x and I
>>>> got
>>>>>> slow results in 3.6.x initially, but disabling digest.enabled fixed
>>> it
>>>>> and
>>>>>> the two versions were then comparable. In 3.8.0 I am seeing poor
>>>> results
>>>>>> with or without digest enabled.
>>>>> 
>>>>> Then later:
>>>>>> 27,052: 3.4.6
>>>>>> 15,993:3.6.3
>>>>>> 15,943:3.7.1
>>>>>> 16,805: 3.8.0, digest.enabled=true:
>>>>>> 16,682: 3.8.0: digest.enabled=false
>>>>>> *16,370: 3.8.0 NullMetricsProvider*
>>>>> 
>>>>> Was the "15,993:3.6.3" measured with or without digest? It sounds like
>>>>> earlier you were able to get good results with 3.6.x
>>>>> (using digest.enabled=false). Is this still reproducible with 3.6.3? If
>>>>> yes, then still I would look around the digest feature for potential
>>> root
>>>>> cause.
>>>>> 
>>>>> On the other hand, the digest feature should not really affect the read
>>>>> path, as far as I understood. But I also don't know how the
>>> benchmarking
>>>>> tool executes the operations (maybe there are writes running parallel
>>>> with
>>>>> reads?).
>>>>> 
>>>>> Máté
>>>>> 
>>>>> 
>>>>> On Mon, Aug 29, 2022 at 7:00 AM Will Now <wn...@gmail.com> wrote:
>>>>> 
>>>>>> In case it is informative, here is the output from running zookeeper
>>>>> 3.8.0
>>>>>> in my latest test run with NullMetricsProvider.
>>>>>> 
>>>>>> ~/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin$ ./zkServer.sh
>>>>>> start-foreground
>>>>>> /usr/bin/java
>>>>>> ZooKeeper JMX enabled by default
>>>>>> Using config:
>>>>>> 
>>>>> 
>>>> 
>>> /home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../conf/zoo.cfg
>>>>>> 2022-08-28 21:36:13,846 [myid:] - INFO
>>>>>> [main:o.a.z.s.q.QuorumPeerConfig@177]
>>>>>> - Reading configuration from:
>>>>>> 
>>>>> 
>>>> 
>>> /home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../conf/zoo.cfg
>>>>>> 2022-08-28 21:36:13,850 [myid:] - INFO
>>>>>> [main:o.a.z.s.q.QuorumPeerConfig@440]
>>>>>> - clientPortAddress is 0.0.0.0:2181
>>>>>> 2022-08-28 21:36:13,851 [myid:] - INFO
>>>>>> [main:o.a.z.s.q.QuorumPeerConfig@444]
>>>>>> - secureClientPort is not set
>>>>>> 2022-08-28 21:36:13,851 [myid:] - INFO
>>>>>> [main:o.a.z.s.q.QuorumPeerConfig@460]
>>>>>> - observerMasterPort is not set
>>>>>> 2022-08-28 21:36:13,851 [myid:] - INFO
>>>>>> [main:o.a.z.s.q.QuorumPeerConfig@477]
>>>>>> - metricsProvider.className is
>>>>>> org.apache.zookeeper.metrics.impl.NullMetricsProvider
>>>>>> 2022-08-28 21:36:13,852 [myid:] - INFO
>>>>>> [main:o.a.z.s.DatadirCleanupManager@78] - autopurge.snapRetainCount
>>>> set
>>>>>> to
>>>>>> 3
>>>>>> 2022-08-28 21:36:13,852 [myid:] - INFO
>>>>>> [main:o.a.z.s.DatadirCleanupManager@79] - autopurge.purgeInterval
>>> set
>>>>> to
>>>>>> 0
>>>>>> 2022-08-28 21:36:13,852 [myid:] - INFO
>>>>>> [main:o.a.z.s.DatadirCleanupManager@101] - Purge task is not
>>>> scheduled.
>>>>>> 2022-08-28 21:36:13,852 [myid:] - WARN
>>>>> [main:o.a.z.s.q.QuorumPeerMain@139
>>>>>> ]
>>>>>> - Either no config or no quorum defined in config, running in
>>>> standalone
>>>>>> mode
>>>>>> 2022-08-28 21:36:13,853 [myid:] - INFO  [main:o.a.z.j.ManagedUtil@46
>>> ]
>>>> -
>>>>>> Log4j 1.2 jmx support not found; jmx disabled.
>>>>>> 2022-08-28 21:36:13,853 [myid:] - INFO
>>>>>> [main:o.a.z.s.q.QuorumPeerConfig@177]
>>>>>> - Reading configuration from:
>>>>>> 
>>>>> 
>>>> 
>>> /home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../conf/zoo.cfg
>>>>>> 2022-08-28 21:36:13,854 [myid:] - INFO
>>>>>> [main:o.a.z.s.q.QuorumPeerConfig@440]
>>>>>> - clientPortAddress is 0.0.0.0:2181
>>>>>> 2022-08-28 21:36:13,854 [myid:] - INFO
>>>>>> [main:o.a.z.s.q.QuorumPeerConfig@444]
>>>>>> - secureClientPort is not set
>>>>>> 2022-08-28 21:36:13,854 [myid:] - INFO
>>>>>> [main:o.a.z.s.q.QuorumPeerConfig@460]
>>>>>> - observerMasterPort is not set
>>>>>> 2022-08-28 21:36:13,854 [myid:] - INFO
>>>>>> [main:o.a.z.s.q.QuorumPeerConfig@477]
>>>>>> - metricsProvider.className is
>>>>>> org.apache.zookeeper.metrics.impl.NullMetricsProvider
>>>>>> 2022-08-28 21:36:13,854 [myid:] - INFO
>>>>>> [main:o.a.z.s.ZooKeeperServerMain@123] - Starting server
>>>>>> 2022-08-28 21:36:13,861 [myid:] - INFO
>>> [main:o.a.z.s.ServerMetrics@64
>>>> ]
>>>>> -
>>>>>> ServerMetrics initialized with provider
>>>>>> org.apache.zookeeper.metrics.impl.NullMetricsProvider@4d5d943d
>>>>>> 2022-08-28 21:36:13,862 [myid:] - INFO
>>>>>> [main:o.a.z.s.a.DigestAuthenticationProvider@47] - ACL digest
>>>> algorithm
>>>>>> is: SHA1
>>>>>> 2022-08-28 21:36:13,862 [myid:] - INFO
>>>>>> [main:o.a.z.s.a.DigestAuthenticationProvider@61] -
>>>>>> zookeeper.DigestAuthenticationProvider.enabled = true
>>>>>> 2022-08-28 21:36:13,863 [myid:] - INFO
>>>>> [main:o.a.z.s.p.FileTxnSnapLog@124
>>>>>> ]
>>>>>> - zookeeper.snapshot.trust.empty : false
>>>>>> 2022-08-28 21:36:13,869 [myid:] - INFO
>>> [main:o.a.z.ZookeeperBanner@42
>>>> ]
>>>>> -
>>>>>> 2022-08-28 21:36:13,869 [myid:] - INFO
>>> [main:o.a.z.ZookeeperBanner@42
>>>> ]
>>>>> -
>>>>>> ______                  _
>>>>>> 2022-08-28 21:36:13,869 [myid:] - INFO
>>> [main:o.a.z.ZookeeperBanner@42
>>>> ]
>>>>> -
>>>>>> |___  /                 | |
>>>>>> 2022-08-28 21:36:13,869 [myid:] - INFO
>>> [main:o.a.z.ZookeeperBanner@42
>>>> ]
>>>>> -
>>>>>> / /    ___     ___   | | __   ___    ___   _ __     ___   _ __
>>>>>> 2022-08-28 21:36:13,869 [myid:] - INFO
>>> [main:o.a.z.ZookeeperBanner@42
>>>> ]
>>>>> -
>>>>>> / /    / _ \   / _ \  | |/ /  / _ \  / _ \ | '_ \   / _ \ | '__|
>>>>>> 2022-08-28 21:36:13,869 [myid:] - INFO
>>> [main:o.a.z.ZookeeperBanner@42
>>>> ]
>>>>> -
>>>>>> / /__  | (_) | | (_) | |   <  |  __/ |  __/ | |_) | |  __/ | |
>>>>>> 2022-08-28 21:36:13,870 [myid:] - INFO
>>> [main:o.a.z.ZookeeperBanner@42
>>>> ]
>>>>> -
>>>>>> /_____|  \___/   \___/  |_|\_\  \___|  \___| | .__/   \___| |_|
>>>>>> 2022-08-28 21:36:13,870 [myid:] - INFO
>>> [main:o.a.z.ZookeeperBanner@42
>>>> ]
>>>>> -
>>>>>>                                           | |
>>>>>> 2022-08-28 21:36:13,870 [myid:] - INFO
>>> [main:o.a.z.ZookeeperBanner@42
>>>> ]
>>>>> -
>>>>>>                                           |_|
>>>>>> 2022-08-28 21:36:13,870 [myid:] - INFO
>>> [main:o.a.z.ZookeeperBanner@42
>>>> ]
>>>>> -
>>>>>> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
>>> -
>>>>>> Server
>>>>>> 
>>>>>> 
>>>>> 
>>>> 
>>> environment:zookeeper.version=3.8.0-5a02a05eddb59aee6ac762f7ea82e92a68eb9c0f,
>>>>>> built on 2022-02-25 08:49 UTC
>>>>>> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
>>> -
>>>>>> Server environment:host.name=host
>>>>>> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
>>> -
>>>>>> Server environment:java.version=11.0.16
>>>>>> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
>>> -
>>>>>> Server environment:java.vendor=Ubuntu
>>>>>> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
>>> -
>>>>>> Server environment:java.home=/usr/lib/jvm/java-11-openjdk-amd64
>>>>>> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
>>> -
>>>>>> Server
>>>>>> 
>>>>>> 
>>>>> 
>>>> 
>>> environment:java.class.path=/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../zookeeper-server/target/classes:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../build/classes:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../zookeeper-server/target/lib/*.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../build/lib/*.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/zookeeper-prometheus-metrics-3.8.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/zookeeper-jute-3.8.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/zookeeper-3.8.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/snappy-java-1.1.7.7.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/slf4j-api-1.7.30.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/simpleclient_servlet-0.9.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/simpleclient_hotspot-0.9.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/simpleclient_common-0.9.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/simpleclient-0.9.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-transport-native-unix-common-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-transport-native-epoll-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-transport-classes-epoll-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-transport-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-tcnative-classes-2.0.48.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-tcnative-2.0.48.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-resolver-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-handler-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-common-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-codec-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-buffer-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/metrics-core-4.1.12.1.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/logback-core-1.2.10.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/logback-classic-1.2.10.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jline-2.14.6.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-util-ajax-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-util-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-servlet-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-server-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-security-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-io-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-http-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/javax.servlet-api-3.1.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jackson-databind-2.13.1.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jackson-core-2.13.1.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jackson-annotations-2.13.1.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/commons-io-2.11.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/commons-cli-1.4.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/audience-annotations-0.12.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../zookeeper-*.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../zookeeper-server/src/main/resources/lib/*.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../conf:
>>>>>> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
>>> -
>>>>>> Server
>>>>>> 
>>>>>> 
>>>>> 
>>>> 
>>> environment:java.library.path=/usr/java/packages/lib:/usr/lib/x86_64-linux-gnu/jni:/lib/x86_64-linux-gnu:/usr/lib/x86_64-linux-gnu:/usr/lib/jni:/lib:/usr/lib
>>>>>> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
>>> -
>>>>>> Server environment:java.io.tmpdir=/tmp
>>>>>> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
>>> -
>>>>>> Server environment:java.compiler=<NA>
>>>>>> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
>>> -
>>>>>> Server environment:os.name=Linux
>>>>>> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
>>> -
>>>>>> Server environment:os.arch=amd64
>>>>>> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
>>> -
>>>>>> Server environment:os.version=5.15.0-46-generic
>>>>>> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
>>> -
>>>>>> Server
>>>>>> 
>>>>>> 
>>>>> 
>>>> 
>>> environment:user.dir=/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin
>>>>>> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
>>> -
>>>>>> Server environment:os.memory.free=231MB
>>>>>> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
>>> -
>>>>>> Server environment:os.memory.max=1000MB
>>>>>> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
>>> -
>>>>>> Server environment:os.memory.total=250MB
>>>>>> 2022-08-28 21:36:13,871 [myid:] - INFO
>>>> [main:o.a.z.s.ZooKeeperServer@140
>>>>> ]
>>>>>> - zookeeper.enableEagerACLCheck = false
>>>>>> 2022-08-28 21:36:13,872 [myid:] - INFO
>>>> [main:o.a.z.s.ZooKeeperServer@153
>>>>> ]
>>>>>> - zookeeper.digest.enabled = true
>>>>>> 2022-08-28 21:36:13,872 [myid:] - INFO
>>>> [main:o.a.z.s.ZooKeeperServer@157
>>>>> ]
>>>>>> - zookeeper.closeSessionTxn.enabled = true
>>>>>> 2022-08-28 21:36:13,872 [myid:] - INFO
>>>>> [main:o.a.z.s.ZooKeeperServer@1496
>>>>>> ]
>>>>>> - zookeeper.flushDelay = 0 ms
>>>>>> 2022-08-28 21:36:13,872 [myid:] - INFO
>>>>> [main:o.a.z.s.ZooKeeperServer@1505
>>>>>> ]
>>>>>> - zookeeper.maxWriteQueuePollTime = 0 ms
>>>>>> 2022-08-28 21:36:13,872 [myid:] - INFO
>>>>> [main:o.a.z.s.ZooKeeperServer@1514
>>>>>> ]
>>>>>> - zookeeper.maxBatchSize=1000
>>>>>> 2022-08-28 21:36:13,872 [myid:] - INFO
>>>> [main:o.a.z.s.ZooKeeperServer@264
>>>>> ]
>>>>>> - zookeeper.intBufferStartingSizeBytes = 1024
>>>>>> 2022-08-28 21:36:13,872 [myid:] - INFO
>>> [main:o.a.z.s.BlueThrottle@141
>>>> ]
>>>>> -
>>>>>> Weighed connection throttling is disabled
>>>>>> 2022-08-28 21:36:13,873 [myid:] - INFO
>>>>> [main:o.a.z.s.ZooKeeperServer@1297
>>>>>> ]
>>>>>> - minSessionTimeout set to 4000 ms
>>>>>> 2022-08-28 21:36:13,873 [myid:] - INFO
>>>>> [main:o.a.z.s.ZooKeeperServer@1306
>>>>>> ]
>>>>>> - maxSessionTimeout set to 40000 ms
>>>>>> 2022-08-28 21:36:13,874 [myid:] - INFO
>>> [main:o.a.z.s.ResponseCache@45
>>>> ]
>>>>> -
>>>>>> getData response cache size is initialized with value 400.
>>>>>> 2022-08-28 21:36:13,874 [myid:] - INFO
>>> [main:o.a.z.s.ResponseCache@45
>>>> ]
>>>>> -
>>>>>> getChildren response cache size is initialized with value 400.
>>>>>> 2022-08-28 21:36:13,874 [myid:] - INFO
>>>>>> [main:o.a.z.s.u.RequestPathMetricsCollector@109] -
>>>>>> zookeeper.pathStats.slotCapacity = 60
>>>>>> 2022-08-28 21:36:13,874 [myid:] - INFO
>>>>>> [main:o.a.z.s.u.RequestPathMetricsCollector@110] -
>>>>>> zookeeper.pathStats.slotDuration = 15
>>>>>> 2022-08-28 21:36:13,875 [myid:] - INFO
>>>>>> [main:o.a.z.s.u.RequestPathMetricsCollector@111] -
>>>>>> zookeeper.pathStats.maxDepth = 6
>>>>>> 2022-08-28 21:36:13,875 [myid:] - INFO
>>>>>> [main:o.a.z.s.u.RequestPathMetricsCollector@112] -
>>>>>> zookeeper.pathStats.initialDelay = 5
>>>>>> 2022-08-28 21:36:13,875 [myid:] - INFO
>>>>>> [main:o.a.z.s.u.RequestPathMetricsCollector@113] -
>>>>>> zookeeper.pathStats.delay = 5
>>>>>> 2022-08-28 21:36:13,875 [myid:] - INFO
>>>>>> [main:o.a.z.s.u.RequestPathMetricsCollector@114] -
>>>>>> zookeeper.pathStats.enabled = false
>>>>>> 2022-08-28 21:36:13,876 [myid:] - INFO
>>>>> [main:o.a.z.s.ZooKeeperServer@1533
>>>>>> ]
>>>>>> - The max bytes for all large requests are set to 104857600
>>>>>> 2022-08-28 21:36:13,876 [myid:] - INFO
>>>>> [main:o.a.z.s.ZooKeeperServer@1547
>>>>>> ]
>>>>>> - The large request threshold is set to -1
>>>>>> 2022-08-28 21:36:13,877 [myid:] - INFO
>>>>>> [main:o.a.z.s.AuthenticationHelper@66] -
>>>>> zookeeper.enforce.auth.enabled =
>>>>>> false
>>>>>> 2022-08-28 21:36:13,877 [myid:] - INFO
>>>>>> [main:o.a.z.s.AuthenticationHelper@67] -
>>>>> zookeeper.enforce.auth.schemes =
>>>>>> []
>>>>>> 2022-08-28 21:36:13,877 [myid:] - INFO
>>>> [main:o.a.z.s.ZooKeeperServer@365
>>>>> ]
>>>>>> - Created server with tickTime 2000 ms minSessionTimeout 4000 ms
>>>>>> maxSessionTimeout 40000 ms clientPortListenBacklog -1 datadir
>>>>>> /tmp/zookeeper/3.8.0/version-2 snapdir /tmp/zookeeper/3.8.0/version-2
>>>>>> 2022-08-28 21:36:13,890 [myid:] - INFO  [main:o.e.j.u.l.Log@170] -
>>>>> Logging
>>>>>> initialized @348ms to org.eclipse.jetty.util.log.Slf4jLog
>>>>>> 2022-08-28 21:36:13,929 [myid:] - WARN
>>>>> [main:o.e.j.s.h.ContextHandler@1656
>>>>>> ]
>>>>>> - o.e.j.s.ServletContextHandler@3cebbb30{/,null,STOPPED} contextPath
>>>>> ends
>>>>>> with /*
>>>>>> 2022-08-28 21:36:13,930 [myid:] - WARN
>>>>> [main:o.e.j.s.h.ContextHandler@1667
>>>>>> ]
>>>>>> - Empty contextPath
>>>>>> 2022-08-28 21:36:13,951 [myid:] - INFO  [main:o.e.j.s.Server@375] -
>>>>>> jetty-9.4.43.v20210629; built: 2021-06-30T11:07:22.254Z; git:
>>>>>> 526006ecfa3af7f1a27ef3a288e2bef7ea9dd7e8; jvm
>>>>>> 11.0.16+8-post-Ubuntu-0ubuntu120.04
>>>>>> 2022-08-28 21:36:13,967 [myid:] - INFO
>>>>>> [main:o.e.j.s.s.DefaultSessionIdManager@334] -
>>>> DefaultSessionIdManager
>>>>>> workerName=node0
>>>>>> 2022-08-28 21:36:13,967 [myid:] - INFO
>>>>>> [main:o.e.j.s.s.DefaultSessionIdManager@339] - No SessionScavenger
>>>> set,
>>>>>> using defaults
>>>>>> 2022-08-28 21:36:13,968 [myid:] - INFO
>>> [main:o.e.j.s.s.HouseKeeper@132
>>>> ]
>>>>> -
>>>>>> node0 Scavenging every 600000ms
>>>>>> 2022-08-28 21:36:13,970 [myid:] - WARN
>>>>>> [main:o.e.j.s.ConstraintSecurityHandler@759] -
>>>>>> ServletContext@o.e.j.s.ServletContextHandler
>>> @3cebbb30{/,null,STARTING}
>>>>> has
>>>>>> uncovered http methods for path: /*
>>>>>> 2022-08-28 21:36:13,975 [myid:] - INFO
>>>>> [main:o.e.j.s.h.ContextHandler@915
>>>>>> ]
>>>>>> - Started o.e.j.s.ServletContextHandler@3cebbb30{/,null,AVAILABLE}
>>>>>> 2022-08-28 21:36:13,983 [myid:] - INFO
>>>>> [main:o.e.j.s.AbstractConnector@331
>>>>>> ]
>>>>>> - Started ServerConnector@29d89d5d{HTTP/1.1, (http/1.1)}{
>>> 0.0.0.0:8080}
>>>>>> 2022-08-28 21:36:13,983 [myid:] - INFO  [main:o.e.j.s.Server@415] -
>>>>>> Started
>>>>>> @441ms
>>>>>> 2022-08-28 21:36:13,983 [myid:] - INFO
>>>>>> [main:o.a.z.s.a.JettyAdminServer@196]
>>>>>> - Started AdminServer on address 0.0.0.0, port 8080 and command URL
>>>>>> /commands
>>>>>> 2022-08-28 21:36:13,986 [myid:] - INFO
>>>>> [main:o.a.z.s.ServerCnxnFactory@169
>>>>>> ]
>>>>>> - Using org.apache.zookeeper.server.NIOServerCnxnFactory as server
>>>>>> connection factory
>>>>>> 2022-08-28 21:36:13,987 [myid:] - WARN
>>>>> [main:o.a.z.s.ServerCnxnFactory@309
>>>>>> ]
>>>>>> - maxCnxns is not configured, using default value 0.
>>>>>> 2022-08-28 21:36:13,988 [myid:] - INFO
>>>>>> [main:o.a.z.s.NIOServerCnxnFactory@652] - Configuring NIO
>>> connection
>>>>>> handler with 10s sessionless connection timeout, 2 selector
>>> thread(s),
>>>> 24
>>>>>> worker threads, and 64 kB direct buffers.
>>>>>> 2022-08-28 21:36:13,988 [myid:] - INFO
>>>>>> [main:o.a.z.s.NIOServerCnxnFactory@660] - binding to port
>>>>>> 0.0.0.0/0.0.0.0:2181
>>>>>> 2022-08-28 21:36:13,997 [myid:] - INFO
>>>>>> [main:o.a.z.s.w.WatchManagerFactory@42] - Using
>>>>>> org.apache.zookeeper.server.watch.WatchManager as watch manager
>>>>>> 2022-08-28 21:36:13,997 [myid:] - INFO
>>>>>> [main:o.a.z.s.w.WatchManagerFactory@42] - Using
>>>>>> org.apache.zookeeper.server.watch.WatchManager as watch manager
>>>>>> 2022-08-28 21:36:13,998 [myid:] - INFO  [main:o.a.z.s.ZKDatabase@132
>>> ]
>>>> -
>>>>>> zookeeper.snapshotSizeFactor = 0.33
>>>>>> 2022-08-28 21:36:13,998 [myid:] - INFO  [main:o.a.z.s.ZKDatabase@152
>>> ]
>>>> -
>>>>>> zookeeper.commitLogCount=500
>>>>>> 2022-08-28 21:36:14,002 [myid:] - INFO  [main:o.a.z.s.p.SnapStream@61
>>> ]
>>>> -
>>>>>> zookeeper.snapshot.compression.method = CHECKED
>>>>>> 
>>>>>> Also here is my 3.8.0 zoo.cfg file:
>>>>>> 
>>>>>> # The number of milliseconds of each tick
>>>>>> tickTime=2000
>>>>>> # The number of ticks that the initial
>>>>>> # synchronization phase can take
>>>>>> initLimit=10
>>>>>> # The number of ticks that can pass between
>>>>>> # sending a request and getting an acknowledgement
>>>>>> syncLimit=5
>>>>>> # the directory where the snapshot is stored.
>>>>>> # do not use /tmp for storage, /tmp here is just
>>>>>> # example sakes.
>>>>>> dataDir=/tmp/zookeeper/3.8.0
>>>>>> # the port at which the clients will connect
>>>>>> clientPort=2181
>>>>>> # the maximum number of client connections.
>>>>>> # increase this if you need to handle more clients
>>>>>> #maxClientCnxns=60
>>>>>> #
>>>>>> # Be sure to read the maintenance section of the
>>>>>> # administrator guide before turning on autopurge.
>>>>>> #
>>>>>> #
>>>>>> 
>>>>> 
>>>> 
>>> https://zookeeper.apache.org/doc/current/zookeeperAdmin.html#sc_maintenance
>>>>>> #
>>>>>> # The number of snapshots to retain in dataDir
>>>>>> #autopurge.snapRetainCount=3
>>>>>> # Purge task interval in hours
>>>>>> # Set to "0" to disable auto purge feature
>>>>>> #autopurge.purgeInterval=1
>>>>>> 
>>>>>> ## Metrics Providers
>>>>>> #
>>>>>> # https://prometheus.io Metrics Exporter
>>>>>> 
>>>>>> 
>>>>> 
>>>> 
>>> #metricsProvider.className=org.apache.zookeeper.metrics.prometheus.PrometheusMetricsProvider
>>>>>> #metricsProvider.httpHost=0.0.0.0
>>>>>> #metricsProvider.httpPort=7000
>>>>>> #metricsProvider.exportJvmInfo=true
>>>>>> 
>>>>>> 4lw.commands.whitelist=*
>>>>>> digest.enabled=true
>>>>>> 
>>>>>> 
>>>>>> 
>>>>> 
>>>> 
>>> metricsProvider.className=org.apache.zookeeper.metrics.impl.NullMetricsProvider
>>>>>> 
>>>>> 
>>>> 
>>> 
>>> 
>>> --
>>> Best regards,
>>> Andrew
>>> 
>>> Unrest, ignorance distilled, nihilistic imbeciles -
>>>   It's what we’ve earned
>>> Welcome, apocalypse, what’s taken you so long?
>>> Bring us the fitting end that we’ve been counting on
>>>  - A23, Welcome, Apocalypse
>>>

Re: Read performance of 3.4.6 vs 3.8.0 according to zookeeper-benchmark

Posted by Andrew Purtell <an...@gmail.com>.

Ok. Then in 3.5 the reorganization of request processors such that reads are served in a multithreaded way may be relevant. In 3.4 all requests - reads and writes - are processed serially. In 3.5 there is a dispatch of reads to a thread pool instead. This kind of change could cause this type of result, a reduction in single client / single connection performance in trade for better multiple client / connection scalability. You can plot throughout results against number of concurrent clients for 3.4 vs 3.5 or later to observe this effect and relative improvements 

If this is what is going on here, it is a reasonable trade off because in production you won’t be facing a single client you’ll be dispatching requests from many. 

> On Sep 2, 2022, at 10:17 PM, Will Now <wn...@gmail.com> wrote:
> 
> For me. 3.5.10 illustrates a drop from 27K to 18K.   See below:
> 
> 27,052: 3.4.6
> 24,392: 3.4.6 Again
> 18,429: 3.5.10
> 15,993: 3.6.3, digest.enabled=true
> 16,159: 3.6.3, *digest.enabled=false*
> 15,943: 3.7.1
> 16,805: 3.8.0, digest.enabled=true:
> 16,682: 3.8.0: digest.enabled=false
> 16,370: 3.8.0 NullMetricsProvider, *digest.enabled=false*
> 
> I re-ran the 3.4.6 benchmark and got a reduced result for some reason:
> 24,392. However that value still exceeds the performance of subsequent
> releases.
> 
> Admittedly, this is not a super scientific result set: I'm running 1 node
> ensemble and the client on the same host.
> 
> I would love some thirdparty confirmation of my results for sure.
> 
> 
>> On Fri, Sep 2, 2022 at 6:32 PM Andrew Purtell <ap...@apache.org> wrote:
>> 
>> Did you test with any 3.5 version?
>> 
>> Would be curious if the dip starts at 3.6. BlueThrottle and
>> RequestThrottler both went in at 3.6.0.
>> 
>> 
>> 
>>> On Tue, Aug 30, 2022 at 1:20 PM Will Now <wn...@gmail.com> wrote:
>>> 
>>> I've updated the results summary below to include 3.6.3 with and without
>>> digest.enabled; they are essentially the same.
>>> 
>>> 27,052: 3.4.6
>>> 15,993: 3.6.3, digest.enabled=true
>>> 16,159: 3.6.3, *digest.enabled=false*
>>> 15,943: 3.7.1
>>> 16,805: 3.8.0, digest.enabled=true:
>>> 16,682: 3.8.0: digest.enabled=false
>>> 16,370: 3.8.0 NullMetricsProvider, *digest.enabled=false*
>>> 
>>> I'm going to re-run my benchmarks in a 3-node ensemble instead of a local
>>> singleton. I'll also run the test client on a separate node.  This will
>>> match the environment I used years ago to measure 3.4.6 against 3.6.x,
>> when
>>> I found that digest.enabled was having a big impact (a result that I am
>> not
>>> reproducing at present)
>>> 
>>> The zookeeper benchmark I am reporting is the number of synchronous
>>> sequential read operations on a single znode that can be completed in 30
>>> seconds.  No other transactions take place during the benchmark (ie no
>>> writes, etc)
>>> 
>>> I'm optimistic that the anomaly I am reporting is some issue on my end
>> and
>>> not in zookeeper. I'm pretty sure a big drop in performance like this
>> would
>>> not have gone unnoticed.  Thanks for the responses. I'll report back!
>>> 
>>> On Mon, Aug 29, 2022 at 12:37 AM Szalay-Bekő Máté <
>>> szalay.beko.mate@gmail.com> wrote:
>>> 
>>>> Interesting, thanks for sharing the results!
>>>> 
>>>> It will be hard to figure out what changed since the 3.4.6 release.
>> Many
>>>> new features added. Still, it would be good to find out which version /
>>>> commit was responsible for the most performance degradation.
>>>> 
>>>> You wrote before:
>>>>> A while back I performed similar comparisons of 3.4.6 vs 3.6.x and I
>>> got
>>>>> slow results in 3.6.x initially, but disabling digest.enabled fixed
>> it
>>>> and
>>>>> the two versions were then comparable. In 3.8.0 I am seeing poor
>>> results
>>>>> with or without digest enabled.
>>>> 
>>>> Then later:
>>>>> 27,052: 3.4.6
>>>>> 15,993:3.6.3
>>>>> 15,943:3.7.1
>>>>> 16,805: 3.8.0, digest.enabled=true:
>>>>> 16,682: 3.8.0: digest.enabled=false
>>>>> *16,370: 3.8.0 NullMetricsProvider*
>>>> 
>>>> Was the "15,993:3.6.3" measured with or without digest? It sounds like
>>>> earlier you were able to get good results with 3.6.x
>>>> (using digest.enabled=false). Is this still reproducible with 3.6.3? If
>>>> yes, then still I would look around the digest feature for potential
>> root
>>>> cause.
>>>> 
>>>> On the other hand, the digest feature should not really affect the read
>>>> path, as far as I understood. But I also don't know how the
>> benchmarking
>>>> tool executes the operations (maybe there are writes running parallel
>>> with
>>>> reads?).
>>>> 
>>>> Máté
>>>> 
>>>> 
>>>> On Mon, Aug 29, 2022 at 7:00 AM Will Now <wn...@gmail.com> wrote:
>>>> 
>>>>> In case it is informative, here is the output from running zookeeper
>>>> 3.8.0
>>>>> in my latest test run with NullMetricsProvider.
>>>>> 
>>>>> ~/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin$ ./zkServer.sh
>>>>> start-foreground
>>>>> /usr/bin/java
>>>>> ZooKeeper JMX enabled by default
>>>>> Using config:
>>>>> 
>>>> 
>>> 
>> /home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../conf/zoo.cfg
>>>>> 2022-08-28 21:36:13,846 [myid:] - INFO
>>>>> [main:o.a.z.s.q.QuorumPeerConfig@177]
>>>>> - Reading configuration from:
>>>>> 
>>>> 
>>> 
>> /home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../conf/zoo.cfg
>>>>> 2022-08-28 21:36:13,850 [myid:] - INFO
>>>>> [main:o.a.z.s.q.QuorumPeerConfig@440]
>>>>> - clientPortAddress is 0.0.0.0:2181
>>>>> 2022-08-28 21:36:13,851 [myid:] - INFO
>>>>> [main:o.a.z.s.q.QuorumPeerConfig@444]
>>>>> - secureClientPort is not set
>>>>> 2022-08-28 21:36:13,851 [myid:] - INFO
>>>>> [main:o.a.z.s.q.QuorumPeerConfig@460]
>>>>> - observerMasterPort is not set
>>>>> 2022-08-28 21:36:13,851 [myid:] - INFO
>>>>> [main:o.a.z.s.q.QuorumPeerConfig@477]
>>>>> - metricsProvider.className is
>>>>> org.apache.zookeeper.metrics.impl.NullMetricsProvider
>>>>> 2022-08-28 21:36:13,852 [myid:] - INFO
>>>>> [main:o.a.z.s.DatadirCleanupManager@78] - autopurge.snapRetainCount
>>> set
>>>>> to
>>>>> 3
>>>>> 2022-08-28 21:36:13,852 [myid:] - INFO
>>>>> [main:o.a.z.s.DatadirCleanupManager@79] - autopurge.purgeInterval
>> set
>>>> to
>>>>> 0
>>>>> 2022-08-28 21:36:13,852 [myid:] - INFO
>>>>> [main:o.a.z.s.DatadirCleanupManager@101] - Purge task is not
>>> scheduled.
>>>>> 2022-08-28 21:36:13,852 [myid:] - WARN
>>>> [main:o.a.z.s.q.QuorumPeerMain@139
>>>>> ]
>>>>> - Either no config or no quorum defined in config, running in
>>> standalone
>>>>> mode
>>>>> 2022-08-28 21:36:13,853 [myid:] - INFO  [main:o.a.z.j.ManagedUtil@46
>> ]
>>> -
>>>>> Log4j 1.2 jmx support not found; jmx disabled.
>>>>> 2022-08-28 21:36:13,853 [myid:] - INFO
>>>>> [main:o.a.z.s.q.QuorumPeerConfig@177]
>>>>> - Reading configuration from:
>>>>> 
>>>> 
>>> 
>> /home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../conf/zoo.cfg
>>>>> 2022-08-28 21:36:13,854 [myid:] - INFO
>>>>> [main:o.a.z.s.q.QuorumPeerConfig@440]
>>>>> - clientPortAddress is 0.0.0.0:2181
>>>>> 2022-08-28 21:36:13,854 [myid:] - INFO
>>>>> [main:o.a.z.s.q.QuorumPeerConfig@444]
>>>>> - secureClientPort is not set
>>>>> 2022-08-28 21:36:13,854 [myid:] - INFO
>>>>> [main:o.a.z.s.q.QuorumPeerConfig@460]
>>>>> - observerMasterPort is not set
>>>>> 2022-08-28 21:36:13,854 [myid:] - INFO
>>>>> [main:o.a.z.s.q.QuorumPeerConfig@477]
>>>>> - metricsProvider.className is
>>>>> org.apache.zookeeper.metrics.impl.NullMetricsProvider
>>>>> 2022-08-28 21:36:13,854 [myid:] - INFO
>>>>> [main:o.a.z.s.ZooKeeperServerMain@123] - Starting server
>>>>> 2022-08-28 21:36:13,861 [myid:] - INFO
>> [main:o.a.z.s.ServerMetrics@64
>>> ]
>>>> -
>>>>> ServerMetrics initialized with provider
>>>>> org.apache.zookeeper.metrics.impl.NullMetricsProvider@4d5d943d
>>>>> 2022-08-28 21:36:13,862 [myid:] - INFO
>>>>> [main:o.a.z.s.a.DigestAuthenticationProvider@47] - ACL digest
>>> algorithm
>>>>> is: SHA1
>>>>> 2022-08-28 21:36:13,862 [myid:] - INFO
>>>>> [main:o.a.z.s.a.DigestAuthenticationProvider@61] -
>>>>> zookeeper.DigestAuthenticationProvider.enabled = true
>>>>> 2022-08-28 21:36:13,863 [myid:] - INFO
>>>> [main:o.a.z.s.p.FileTxnSnapLog@124
>>>>> ]
>>>>> - zookeeper.snapshot.trust.empty : false
>>>>> 2022-08-28 21:36:13,869 [myid:] - INFO
>> [main:o.a.z.ZookeeperBanner@42
>>> ]
>>>> -
>>>>> 2022-08-28 21:36:13,869 [myid:] - INFO
>> [main:o.a.z.ZookeeperBanner@42
>>> ]
>>>> -
>>>>> ______                  _
>>>>> 2022-08-28 21:36:13,869 [myid:] - INFO
>> [main:o.a.z.ZookeeperBanner@42
>>> ]
>>>> -
>>>>> |___  /                 | |
>>>>> 2022-08-28 21:36:13,869 [myid:] - INFO
>> [main:o.a.z.ZookeeperBanner@42
>>> ]
>>>> -
>>>>>  / /    ___     ___   | | __   ___    ___   _ __     ___   _ __
>>>>> 2022-08-28 21:36:13,869 [myid:] - INFO
>> [main:o.a.z.ZookeeperBanner@42
>>> ]
>>>> -
>>>>> / /    / _ \   / _ \  | |/ /  / _ \  / _ \ | '_ \   / _ \ | '__|
>>>>> 2022-08-28 21:36:13,869 [myid:] - INFO
>> [main:o.a.z.ZookeeperBanner@42
>>> ]
>>>> -
>>>>> / /__  | (_) | | (_) | |   <  |  __/ |  __/ | |_) | |  __/ | |
>>>>> 2022-08-28 21:36:13,870 [myid:] - INFO
>> [main:o.a.z.ZookeeperBanner@42
>>> ]
>>>> -
>>>>> /_____|  \___/   \___/  |_|\_\  \___|  \___| | .__/   \___| |_|
>>>>> 2022-08-28 21:36:13,870 [myid:] - INFO
>> [main:o.a.z.ZookeeperBanner@42
>>> ]
>>>> -
>>>>>                                            | |
>>>>> 2022-08-28 21:36:13,870 [myid:] - INFO
>> [main:o.a.z.ZookeeperBanner@42
>>> ]
>>>> -
>>>>>                                            |_|
>>>>> 2022-08-28 21:36:13,870 [myid:] - INFO
>> [main:o.a.z.ZookeeperBanner@42
>>> ]
>>>> -
>>>>> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
>> -
>>>>> Server
>>>>> 
>>>>> 
>>>> 
>>> 
>> environment:zookeeper.version=3.8.0-5a02a05eddb59aee6ac762f7ea82e92a68eb9c0f,
>>>>> built on 2022-02-25 08:49 UTC
>>>>> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
>> -
>>>>> Server environment:host.name=host
>>>>> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
>> -
>>>>> Server environment:java.version=11.0.16
>>>>> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
>> -
>>>>> Server environment:java.vendor=Ubuntu
>>>>> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
>> -
>>>>> Server environment:java.home=/usr/lib/jvm/java-11-openjdk-amd64
>>>>> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
>> -
>>>>> Server
>>>>> 
>>>>> 
>>>> 
>>> 
>> environment:java.class.path=/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../zookeeper-server/target/classes:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../build/classes:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../zookeeper-server/target/lib/*.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../build/lib/*.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/zookeeper-prometheus-metrics-3.8.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/zookeeper-jute-3.8.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/zookeeper-3.8.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/snappy-java-1.1.7.7.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/slf4j-api-1.7.30.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/simpleclient_servlet-0.9.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/simpleclient_hotspot-0.9.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/simpleclient_common-0.9.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/simpleclient-0.9.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-transport-native-unix-common-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-transport-native-epoll-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-transport-classes-epoll-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-transport-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-tcnative-classes-2.0.48.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-tcnative-2.0.48.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-resolver-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-handler-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-common-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-codec-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-buffer-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/metrics-core-4.1.12.1.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/logback-core-1.2.10.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/logback-classic-1.2.10.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jline-2.14.6.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-util-ajax-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-util-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-servlet-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-server-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-security-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-io-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-http-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/javax.servlet-api-3.1.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jackson-databind-2.13.1.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jackson-core-2.13.1.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jackson-annotations-2.13.1.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/commons-io-2.11.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/commons-cli-1.4.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/audience-annotations-0.12.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../zookeeper-*.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../zookeeper-server/src/main/resources/lib/*.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../conf:
>>>>> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
>> -
>>>>> Server
>>>>> 
>>>>> 
>>>> 
>>> 
>> environment:java.library.path=/usr/java/packages/lib:/usr/lib/x86_64-linux-gnu/jni:/lib/x86_64-linux-gnu:/usr/lib/x86_64-linux-gnu:/usr/lib/jni:/lib:/usr/lib
>>>>> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
>> -
>>>>> Server environment:java.io.tmpdir=/tmp
>>>>> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
>> -
>>>>> Server environment:java.compiler=<NA>
>>>>> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
>> -
>>>>> Server environment:os.name=Linux
>>>>> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
>> -
>>>>> Server environment:os.arch=amd64
>>>>> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
>> -
>>>>> Server environment:os.version=5.15.0-46-generic
>>>>> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
>> -
>>>>> Server
>>>>> 
>>>>> 
>>>> 
>>> 
>> environment:user.dir=/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin
>>>>> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
>> -
>>>>> Server environment:os.memory.free=231MB
>>>>> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
>> -
>>>>> Server environment:os.memory.max=1000MB
>>>>> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
>> -
>>>>> Server environment:os.memory.total=250MB
>>>>> 2022-08-28 21:36:13,871 [myid:] - INFO
>>> [main:o.a.z.s.ZooKeeperServer@140
>>>> ]
>>>>> - zookeeper.enableEagerACLCheck = false
>>>>> 2022-08-28 21:36:13,872 [myid:] - INFO
>>> [main:o.a.z.s.ZooKeeperServer@153
>>>> ]
>>>>> - zookeeper.digest.enabled = true
>>>>> 2022-08-28 21:36:13,872 [myid:] - INFO
>>> [main:o.a.z.s.ZooKeeperServer@157
>>>> ]
>>>>> - zookeeper.closeSessionTxn.enabled = true
>>>>> 2022-08-28 21:36:13,872 [myid:] - INFO
>>>> [main:o.a.z.s.ZooKeeperServer@1496
>>>>> ]
>>>>> - zookeeper.flushDelay = 0 ms
>>>>> 2022-08-28 21:36:13,872 [myid:] - INFO
>>>> [main:o.a.z.s.ZooKeeperServer@1505
>>>>> ]
>>>>> - zookeeper.maxWriteQueuePollTime = 0 ms
>>>>> 2022-08-28 21:36:13,872 [myid:] - INFO
>>>> [main:o.a.z.s.ZooKeeperServer@1514
>>>>> ]
>>>>> - zookeeper.maxBatchSize=1000
>>>>> 2022-08-28 21:36:13,872 [myid:] - INFO
>>> [main:o.a.z.s.ZooKeeperServer@264
>>>> ]
>>>>> - zookeeper.intBufferStartingSizeBytes = 1024
>>>>> 2022-08-28 21:36:13,872 [myid:] - INFO
>> [main:o.a.z.s.BlueThrottle@141
>>> ]
>>>> -
>>>>> Weighed connection throttling is disabled
>>>>> 2022-08-28 21:36:13,873 [myid:] - INFO
>>>> [main:o.a.z.s.ZooKeeperServer@1297
>>>>> ]
>>>>> - minSessionTimeout set to 4000 ms
>>>>> 2022-08-28 21:36:13,873 [myid:] - INFO
>>>> [main:o.a.z.s.ZooKeeperServer@1306
>>>>> ]
>>>>> - maxSessionTimeout set to 40000 ms
>>>>> 2022-08-28 21:36:13,874 [myid:] - INFO
>> [main:o.a.z.s.ResponseCache@45
>>> ]
>>>> -
>>>>> getData response cache size is initialized with value 400.
>>>>> 2022-08-28 21:36:13,874 [myid:] - INFO
>> [main:o.a.z.s.ResponseCache@45
>>> ]
>>>> -
>>>>> getChildren response cache size is initialized with value 400.
>>>>> 2022-08-28 21:36:13,874 [myid:] - INFO
>>>>> [main:o.a.z.s.u.RequestPathMetricsCollector@109] -
>>>>> zookeeper.pathStats.slotCapacity = 60
>>>>> 2022-08-28 21:36:13,874 [myid:] - INFO
>>>>> [main:o.a.z.s.u.RequestPathMetricsCollector@110] -
>>>>> zookeeper.pathStats.slotDuration = 15
>>>>> 2022-08-28 21:36:13,875 [myid:] - INFO
>>>>> [main:o.a.z.s.u.RequestPathMetricsCollector@111] -
>>>>> zookeeper.pathStats.maxDepth = 6
>>>>> 2022-08-28 21:36:13,875 [myid:] - INFO
>>>>> [main:o.a.z.s.u.RequestPathMetricsCollector@112] -
>>>>> zookeeper.pathStats.initialDelay = 5
>>>>> 2022-08-28 21:36:13,875 [myid:] - INFO
>>>>> [main:o.a.z.s.u.RequestPathMetricsCollector@113] -
>>>>> zookeeper.pathStats.delay = 5
>>>>> 2022-08-28 21:36:13,875 [myid:] - INFO
>>>>> [main:o.a.z.s.u.RequestPathMetricsCollector@114] -
>>>>> zookeeper.pathStats.enabled = false
>>>>> 2022-08-28 21:36:13,876 [myid:] - INFO
>>>> [main:o.a.z.s.ZooKeeperServer@1533
>>>>> ]
>>>>> - The max bytes for all large requests are set to 104857600
>>>>> 2022-08-28 21:36:13,876 [myid:] - INFO
>>>> [main:o.a.z.s.ZooKeeperServer@1547
>>>>> ]
>>>>> - The large request threshold is set to -1
>>>>> 2022-08-28 21:36:13,877 [myid:] - INFO
>>>>> [main:o.a.z.s.AuthenticationHelper@66] -
>>>> zookeeper.enforce.auth.enabled =
>>>>> false
>>>>> 2022-08-28 21:36:13,877 [myid:] - INFO
>>>>> [main:o.a.z.s.AuthenticationHelper@67] -
>>>> zookeeper.enforce.auth.schemes =
>>>>> []
>>>>> 2022-08-28 21:36:13,877 [myid:] - INFO
>>> [main:o.a.z.s.ZooKeeperServer@365
>>>> ]
>>>>> - Created server with tickTime 2000 ms minSessionTimeout 4000 ms
>>>>> maxSessionTimeout 40000 ms clientPortListenBacklog -1 datadir
>>>>> /tmp/zookeeper/3.8.0/version-2 snapdir /tmp/zookeeper/3.8.0/version-2
>>>>> 2022-08-28 21:36:13,890 [myid:] - INFO  [main:o.e.j.u.l.Log@170] -
>>>> Logging
>>>>> initialized @348ms to org.eclipse.jetty.util.log.Slf4jLog
>>>>> 2022-08-28 21:36:13,929 [myid:] - WARN
>>>> [main:o.e.j.s.h.ContextHandler@1656
>>>>> ]
>>>>> - o.e.j.s.ServletContextHandler@3cebbb30{/,null,STOPPED} contextPath
>>>> ends
>>>>> with /*
>>>>> 2022-08-28 21:36:13,930 [myid:] - WARN
>>>> [main:o.e.j.s.h.ContextHandler@1667
>>>>> ]
>>>>> - Empty contextPath
>>>>> 2022-08-28 21:36:13,951 [myid:] - INFO  [main:o.e.j.s.Server@375] -
>>>>> jetty-9.4.43.v20210629; built: 2021-06-30T11:07:22.254Z; git:
>>>>> 526006ecfa3af7f1a27ef3a288e2bef7ea9dd7e8; jvm
>>>>> 11.0.16+8-post-Ubuntu-0ubuntu120.04
>>>>> 2022-08-28 21:36:13,967 [myid:] - INFO
>>>>> [main:o.e.j.s.s.DefaultSessionIdManager@334] -
>>> DefaultSessionIdManager
>>>>> workerName=node0
>>>>> 2022-08-28 21:36:13,967 [myid:] - INFO
>>>>> [main:o.e.j.s.s.DefaultSessionIdManager@339] - No SessionScavenger
>>> set,
>>>>> using defaults
>>>>> 2022-08-28 21:36:13,968 [myid:] - INFO
>> [main:o.e.j.s.s.HouseKeeper@132
>>> ]
>>>> -
>>>>> node0 Scavenging every 600000ms
>>>>> 2022-08-28 21:36:13,970 [myid:] - WARN
>>>>> [main:o.e.j.s.ConstraintSecurityHandler@759] -
>>>>> ServletContext@o.e.j.s.ServletContextHandler
>> @3cebbb30{/,null,STARTING}
>>>> has
>>>>> uncovered http methods for path: /*
>>>>> 2022-08-28 21:36:13,975 [myid:] - INFO
>>>> [main:o.e.j.s.h.ContextHandler@915
>>>>> ]
>>>>> - Started o.e.j.s.ServletContextHandler@3cebbb30{/,null,AVAILABLE}
>>>>> 2022-08-28 21:36:13,983 [myid:] - INFO
>>>> [main:o.e.j.s.AbstractConnector@331
>>>>> ]
>>>>> - Started ServerConnector@29d89d5d{HTTP/1.1, (http/1.1)}{
>> 0.0.0.0:8080}
>>>>> 2022-08-28 21:36:13,983 [myid:] - INFO  [main:o.e.j.s.Server@415] -
>>>>> Started
>>>>> @441ms
>>>>> 2022-08-28 21:36:13,983 [myid:] - INFO
>>>>> [main:o.a.z.s.a.JettyAdminServer@196]
>>>>> - Started AdminServer on address 0.0.0.0, port 8080 and command URL
>>>>> /commands
>>>>> 2022-08-28 21:36:13,986 [myid:] - INFO
>>>> [main:o.a.z.s.ServerCnxnFactory@169
>>>>> ]
>>>>> - Using org.apache.zookeeper.server.NIOServerCnxnFactory as server
>>>>> connection factory
>>>>> 2022-08-28 21:36:13,987 [myid:] - WARN
>>>> [main:o.a.z.s.ServerCnxnFactory@309
>>>>> ]
>>>>> - maxCnxns is not configured, using default value 0.
>>>>> 2022-08-28 21:36:13,988 [myid:] - INFO
>>>>> [main:o.a.z.s.NIOServerCnxnFactory@652] - Configuring NIO
>> connection
>>>>> handler with 10s sessionless connection timeout, 2 selector
>> thread(s),
>>> 24
>>>>> worker threads, and 64 kB direct buffers.
>>>>> 2022-08-28 21:36:13,988 [myid:] - INFO
>>>>> [main:o.a.z.s.NIOServerCnxnFactory@660] - binding to port
>>>>> 0.0.0.0/0.0.0.0:2181
>>>>> 2022-08-28 21:36:13,997 [myid:] - INFO
>>>>> [main:o.a.z.s.w.WatchManagerFactory@42] - Using
>>>>> org.apache.zookeeper.server.watch.WatchManager as watch manager
>>>>> 2022-08-28 21:36:13,997 [myid:] - INFO
>>>>> [main:o.a.z.s.w.WatchManagerFactory@42] - Using
>>>>> org.apache.zookeeper.server.watch.WatchManager as watch manager
>>>>> 2022-08-28 21:36:13,998 [myid:] - INFO  [main:o.a.z.s.ZKDatabase@132
>> ]
>>> -
>>>>> zookeeper.snapshotSizeFactor = 0.33
>>>>> 2022-08-28 21:36:13,998 [myid:] - INFO  [main:o.a.z.s.ZKDatabase@152
>> ]
>>> -
>>>>> zookeeper.commitLogCount=500
>>>>> 2022-08-28 21:36:14,002 [myid:] - INFO  [main:o.a.z.s.p.SnapStream@61
>> ]
>>> -
>>>>> zookeeper.snapshot.compression.method = CHECKED
>>>>> 
>>>>> Also here is my 3.8.0 zoo.cfg file:
>>>>> 
>>>>> # The number of milliseconds of each tick
>>>>> tickTime=2000
>>>>> # The number of ticks that the initial
>>>>> # synchronization phase can take
>>>>> initLimit=10
>>>>> # The number of ticks that can pass between
>>>>> # sending a request and getting an acknowledgement
>>>>> syncLimit=5
>>>>> # the directory where the snapshot is stored.
>>>>> # do not use /tmp for storage, /tmp here is just
>>>>> # example sakes.
>>>>> dataDir=/tmp/zookeeper/3.8.0
>>>>> # the port at which the clients will connect
>>>>> clientPort=2181
>>>>> # the maximum number of client connections.
>>>>> # increase this if you need to handle more clients
>>>>> #maxClientCnxns=60
>>>>> #
>>>>> # Be sure to read the maintenance section of the
>>>>> # administrator guide before turning on autopurge.
>>>>> #
>>>>> #
>>>>> 
>>>> 
>>> 
>> https://zookeeper.apache.org/doc/current/zookeeperAdmin.html#sc_maintenance
>>>>> #
>>>>> # The number of snapshots to retain in dataDir
>>>>> #autopurge.snapRetainCount=3
>>>>> # Purge task interval in hours
>>>>> # Set to "0" to disable auto purge feature
>>>>> #autopurge.purgeInterval=1
>>>>> 
>>>>> ## Metrics Providers
>>>>> #
>>>>> # https://prometheus.io Metrics Exporter
>>>>> 
>>>>> 
>>>> 
>>> 
>> #metricsProvider.className=org.apache.zookeeper.metrics.prometheus.PrometheusMetricsProvider
>>>>> #metricsProvider.httpHost=0.0.0.0
>>>>> #metricsProvider.httpPort=7000
>>>>> #metricsProvider.exportJvmInfo=true
>>>>> 
>>>>> 4lw.commands.whitelist=*
>>>>> digest.enabled=true
>>>>> 
>>>>> 
>>>>> 
>>>> 
>>> 
>> metricsProvider.className=org.apache.zookeeper.metrics.impl.NullMetricsProvider
>>>>> 
>>>> 
>>> 
>> 
>> 
>> --
>> Best regards,
>> Andrew
>> 
>> Unrest, ignorance distilled, nihilistic imbeciles -
>>    It's what we’ve earned
>> Welcome, apocalypse, what’s taken you so long?
>> Bring us the fitting end that we’ve been counting on
>>   - A23, Welcome, Apocalypse
>>

Re: Read performance of 3.4.6 vs 3.8.0 according to zookeeper-benchmark

Posted by Will Now <wn...@gmail.com>.

For me. 3.5.10 illustrates a drop from 27K to 18K.   See below:

27,052: 3.4.6
24,392: 3.4.6 Again
18,429: 3.5.10
15,993: 3.6.3, digest.enabled=true
16,159: 3.6.3, *digest.enabled=false*
15,943: 3.7.1
16,805: 3.8.0, digest.enabled=true:
16,682: 3.8.0: digest.enabled=false
16,370: 3.8.0 NullMetricsProvider, *digest.enabled=false*

I re-ran the 3.4.6 benchmark and got a reduced result for some reason:
24,392. However that value still exceeds the performance of subsequent
releases.

Admittedly, this is not a super scientific result set: I'm running 1 node
ensemble and the client on the same host.

I would love some thirdparty confirmation of my results for sure.


On Fri, Sep 2, 2022 at 6:32 PM Andrew Purtell <ap...@apache.org> wrote:

> Did you test with any 3.5 version?
>
> Would be curious if the dip starts at 3.6. BlueThrottle and
> RequestThrottler both went in at 3.6.0.
>
>
>
> On Tue, Aug 30, 2022 at 1:20 PM Will Now <wn...@gmail.com> wrote:
>
> > I've updated the results summary below to include 3.6.3 with and without
> > digest.enabled; they are essentially the same.
> >
> > 27,052: 3.4.6
> > 15,993: 3.6.3, digest.enabled=true
> > 16,159: 3.6.3, *digest.enabled=false*
> > 15,943: 3.7.1
> > 16,805: 3.8.0, digest.enabled=true:
> > 16,682: 3.8.0: digest.enabled=false
> > 16,370: 3.8.0 NullMetricsProvider, *digest.enabled=false*
> >
> > I'm going to re-run my benchmarks in a 3-node ensemble instead of a local
> > singleton. I'll also run the test client on a separate node.  This will
> > match the environment I used years ago to measure 3.4.6 against 3.6.x,
> when
> > I found that digest.enabled was having a big impact (a result that I am
> not
> > reproducing at present)
> >
> > The zookeeper benchmark I am reporting is the number of synchronous
> > sequential read operations on a single znode that can be completed in 30
> > seconds.  No other transactions take place during the benchmark (ie no
> > writes, etc)
> >
> > I'm optimistic that the anomaly I am reporting is some issue on my end
> and
> > not in zookeeper. I'm pretty sure a big drop in performance like this
> would
> > not have gone unnoticed.  Thanks for the responses. I'll report back!
> >
> > On Mon, Aug 29, 2022 at 12:37 AM Szalay-Bekő Máté <
> > szalay.beko.mate@gmail.com> wrote:
> >
> > > Interesting, thanks for sharing the results!
> > >
> > > It will be hard to figure out what changed since the 3.4.6 release.
> Many
> > > new features added. Still, it would be good to find out which version /
> > > commit was responsible for the most performance degradation.
> > >
> > > You wrote before:
> > > > A while back I performed similar comparisons of 3.4.6 vs 3.6.x and I
> > got
> > > > slow results in 3.6.x initially, but disabling digest.enabled fixed
> it
> > > and
> > > > the two versions were then comparable. In 3.8.0 I am seeing poor
> > results
> > > > with or without digest enabled.
> > >
> > > Then later:
> > > > 27,052: 3.4.6
> > > > 15,993:3.6.3
> > > > 15,943:3.7.1
> > > > 16,805: 3.8.0, digest.enabled=true:
> > > > 16,682: 3.8.0: digest.enabled=false
> > > > *16,370: 3.8.0 NullMetricsProvider*
> > >
> > > Was the "15,993:3.6.3" measured with or without digest? It sounds like
> > > earlier you were able to get good results with 3.6.x
> > > (using digest.enabled=false). Is this still reproducible with 3.6.3? If
> > > yes, then still I would look around the digest feature for potential
> root
> > > cause.
> > >
> > > On the other hand, the digest feature should not really affect the read
> > > path, as far as I understood. But I also don't know how the
> benchmarking
> > > tool executes the operations (maybe there are writes running parallel
> > with
> > > reads?).
> > >
> > > Máté
> > >
> > >
> > > On Mon, Aug 29, 2022 at 7:00 AM Will Now <wn...@gmail.com> wrote:
> > >
> > > > In case it is informative, here is the output from running zookeeper
> > > 3.8.0
> > > > in my latest test run with NullMetricsProvider.
> > > >
> > > > ~/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin$ ./zkServer.sh
> > > > start-foreground
> > > > /usr/bin/java
> > > > ZooKeeper JMX enabled by default
> > > > Using config:
> > > >
> > >
> >
> /home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../conf/zoo.cfg
> > > > 2022-08-28 21:36:13,846 [myid:] - INFO
> > > > [main:o.a.z.s.q.QuorumPeerConfig@177]
> > > > - Reading configuration from:
> > > >
> > >
> >
> /home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../conf/zoo.cfg
> > > > 2022-08-28 21:36:13,850 [myid:] - INFO
> > > > [main:o.a.z.s.q.QuorumPeerConfig@440]
> > > > - clientPortAddress is 0.0.0.0:2181
> > > > 2022-08-28 21:36:13,851 [myid:] - INFO
> > > > [main:o.a.z.s.q.QuorumPeerConfig@444]
> > > > - secureClientPort is not set
> > > > 2022-08-28 21:36:13,851 [myid:] - INFO
> > > > [main:o.a.z.s.q.QuorumPeerConfig@460]
> > > > - observerMasterPort is not set
> > > > 2022-08-28 21:36:13,851 [myid:] - INFO
> > > > [main:o.a.z.s.q.QuorumPeerConfig@477]
> > > > - metricsProvider.className is
> > > > org.apache.zookeeper.metrics.impl.NullMetricsProvider
> > > > 2022-08-28 21:36:13,852 [myid:] - INFO
> > > >  [main:o.a.z.s.DatadirCleanupManager@78] - autopurge.snapRetainCount
> > set
> > > > to
> > > > 3
> > > > 2022-08-28 21:36:13,852 [myid:] - INFO
> > > >  [main:o.a.z.s.DatadirCleanupManager@79] - autopurge.purgeInterval
> set
> > > to
> > > > 0
> > > > 2022-08-28 21:36:13,852 [myid:] - INFO
> > > >  [main:o.a.z.s.DatadirCleanupManager@101] - Purge task is not
> > scheduled.
> > > > 2022-08-28 21:36:13,852 [myid:] - WARN
> > > [main:o.a.z.s.q.QuorumPeerMain@139
> > > > ]
> > > > - Either no config or no quorum defined in config, running in
> > standalone
> > > > mode
> > > > 2022-08-28 21:36:13,853 [myid:] - INFO  [main:o.a.z.j.ManagedUtil@46
> ]
> > -
> > > > Log4j 1.2 jmx support not found; jmx disabled.
> > > > 2022-08-28 21:36:13,853 [myid:] - INFO
> > > > [main:o.a.z.s.q.QuorumPeerConfig@177]
> > > > - Reading configuration from:
> > > >
> > >
> >
> /home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../conf/zoo.cfg
> > > > 2022-08-28 21:36:13,854 [myid:] - INFO
> > > > [main:o.a.z.s.q.QuorumPeerConfig@440]
> > > > - clientPortAddress is 0.0.0.0:2181
> > > > 2022-08-28 21:36:13,854 [myid:] - INFO
> > > > [main:o.a.z.s.q.QuorumPeerConfig@444]
> > > > - secureClientPort is not set
> > > > 2022-08-28 21:36:13,854 [myid:] - INFO
> > > > [main:o.a.z.s.q.QuorumPeerConfig@460]
> > > > - observerMasterPort is not set
> > > > 2022-08-28 21:36:13,854 [myid:] - INFO
> > > > [main:o.a.z.s.q.QuorumPeerConfig@477]
> > > > - metricsProvider.className is
> > > > org.apache.zookeeper.metrics.impl.NullMetricsProvider
> > > > 2022-08-28 21:36:13,854 [myid:] - INFO
> > > >  [main:o.a.z.s.ZooKeeperServerMain@123] - Starting server
> > > > 2022-08-28 21:36:13,861 [myid:] - INFO
> [main:o.a.z.s.ServerMetrics@64
> > ]
> > > -
> > > > ServerMetrics initialized with provider
> > > > org.apache.zookeeper.metrics.impl.NullMetricsProvider@4d5d943d
> > > > 2022-08-28 21:36:13,862 [myid:] - INFO
> > > >  [main:o.a.z.s.a.DigestAuthenticationProvider@47] - ACL digest
> > algorithm
> > > > is: SHA1
> > > > 2022-08-28 21:36:13,862 [myid:] - INFO
> > > >  [main:o.a.z.s.a.DigestAuthenticationProvider@61] -
> > > > zookeeper.DigestAuthenticationProvider.enabled = true
> > > > 2022-08-28 21:36:13,863 [myid:] - INFO
> > > [main:o.a.z.s.p.FileTxnSnapLog@124
> > > > ]
> > > > - zookeeper.snapshot.trust.empty : false
> > > > 2022-08-28 21:36:13,869 [myid:] - INFO
> [main:o.a.z.ZookeeperBanner@42
> > ]
> > > -
> > > > 2022-08-28 21:36:13,869 [myid:] - INFO
> [main:o.a.z.ZookeeperBanner@42
> > ]
> > > -
> > > > ______                  _
> > > > 2022-08-28 21:36:13,869 [myid:] - INFO
> [main:o.a.z.ZookeeperBanner@42
> > ]
> > > -
> > > >  |___  /                 | |
> > > > 2022-08-28 21:36:13,869 [myid:] - INFO
> [main:o.a.z.ZookeeperBanner@42
> > ]
> > > -
> > > >   / /    ___     ___   | | __   ___    ___   _ __     ___   _ __
> > > > 2022-08-28 21:36:13,869 [myid:] - INFO
> [main:o.a.z.ZookeeperBanner@42
> > ]
> > > -
> > > >  / /    / _ \   / _ \  | |/ /  / _ \  / _ \ | '_ \   / _ \ | '__|
> > > > 2022-08-28 21:36:13,869 [myid:] - INFO
> [main:o.a.z.ZookeeperBanner@42
> > ]
> > > -
> > > > / /__  | (_) | | (_) | |   <  |  __/ |  __/ | |_) | |  __/ | |
> > > > 2022-08-28 21:36:13,870 [myid:] - INFO
> [main:o.a.z.ZookeeperBanner@42
> > ]
> > > -
> > > >  /_____|  \___/   \___/  |_|\_\  \___|  \___| | .__/   \___| |_|
> > > > 2022-08-28 21:36:13,870 [myid:] - INFO
> [main:o.a.z.ZookeeperBanner@42
> > ]
> > > -
> > > >                                             | |
> > > > 2022-08-28 21:36:13,870 [myid:] - INFO
> [main:o.a.z.ZookeeperBanner@42
> > ]
> > > -
> > > >                                             |_|
> > > > 2022-08-28 21:36:13,870 [myid:] - INFO
> [main:o.a.z.ZookeeperBanner@42
> > ]
> > > -
> > > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
> -
> > > > Server
> > > >
> > > >
> > >
> >
> environment:zookeeper.version=3.8.0-5a02a05eddb59aee6ac762f7ea82e92a68eb9c0f,
> > > > built on 2022-02-25 08:49 UTC
> > > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
> -
> > > > Server environment:host.name=host
> > > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
> -
> > > > Server environment:java.version=11.0.16
> > > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
> -
> > > > Server environment:java.vendor=Ubuntu
> > > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
> -
> > > > Server environment:java.home=/usr/lib/jvm/java-11-openjdk-amd64
> > > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
> -
> > > > Server
> > > >
> > > >
> > >
> >
> environment:java.class.path=/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../zookeeper-server/target/classes:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../build/classes:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../zookeeper-server/target/lib/*.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../build/lib/*.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/zookeeper-prometheus-metrics-3.8.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/zookeeper-jute-3.8.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/zookeeper-3.8.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/snappy-java-1.1.7.7.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/slf4j-api-1.7.30.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/simpleclient_servlet-0.9.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/simpleclient_hotspot-0.9.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/simpleclient_common-0.9.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/simpleclient-0.9.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-transport-native-unix-common-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-transport-native-epoll-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-transport-classes-epoll-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-transport-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-tcnative-classes-2.0.48.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-tcnative-2.0.48.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-resolver-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-handler-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-common-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-codec-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-buffer-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/metrics-core-4.1.12.1.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/logback-core-1.2.10.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/logback-classic-1.2.10.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jline-2.14.6.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-util-ajax-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-util-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-servlet-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-server-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-security-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-io-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-http-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/javax.servlet-api-3.1.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jackson-databind-2.13.1.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jackson-core-2.13.1.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jackson-annotations-2.13.1.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/commons-io-2.11.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/commons-cli-1.4.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/audience-annotations-0.12.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../zookeeper-*.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../zookeeper-server/src/main/resources/lib/*.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../conf:
> > > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
> -
> > > > Server
> > > >
> > > >
> > >
> >
> environment:java.library.path=/usr/java/packages/lib:/usr/lib/x86_64-linux-gnu/jni:/lib/x86_64-linux-gnu:/usr/lib/x86_64-linux-gnu:/usr/lib/jni:/lib:/usr/lib
> > > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
> -
> > > > Server environment:java.io.tmpdir=/tmp
> > > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
> -
> > > > Server environment:java.compiler=<NA>
> > > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
> -
> > > > Server environment:os.name=Linux
> > > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
> -
> > > > Server environment:os.arch=amd64
> > > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
> -
> > > > Server environment:os.version=5.15.0-46-generic
> > > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
> -
> > > > Server
> > > >
> > > >
> > >
> >
> environment:user.dir=/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin
> > > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
> -
> > > > Server environment:os.memory.free=231MB
> > > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
> -
> > > > Server environment:os.memory.max=1000MB
> > > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98]
> -
> > > > Server environment:os.memory.total=250MB
> > > > 2022-08-28 21:36:13,871 [myid:] - INFO
> > [main:o.a.z.s.ZooKeeperServer@140
> > > ]
> > > > - zookeeper.enableEagerACLCheck = false
> > > > 2022-08-28 21:36:13,872 [myid:] - INFO
> > [main:o.a.z.s.ZooKeeperServer@153
> > > ]
> > > > - zookeeper.digest.enabled = true
> > > > 2022-08-28 21:36:13,872 [myid:] - INFO
> > [main:o.a.z.s.ZooKeeperServer@157
> > > ]
> > > > - zookeeper.closeSessionTxn.enabled = true
> > > > 2022-08-28 21:36:13,872 [myid:] - INFO
> > > [main:o.a.z.s.ZooKeeperServer@1496
> > > > ]
> > > > - zookeeper.flushDelay = 0 ms
> > > > 2022-08-28 21:36:13,872 [myid:] - INFO
> > > [main:o.a.z.s.ZooKeeperServer@1505
> > > > ]
> > > > - zookeeper.maxWriteQueuePollTime = 0 ms
> > > > 2022-08-28 21:36:13,872 [myid:] - INFO
> > > [main:o.a.z.s.ZooKeeperServer@1514
> > > > ]
> > > > - zookeeper.maxBatchSize=1000
> > > > 2022-08-28 21:36:13,872 [myid:] - INFO
> > [main:o.a.z.s.ZooKeeperServer@264
> > > ]
> > > > - zookeeper.intBufferStartingSizeBytes = 1024
> > > > 2022-08-28 21:36:13,872 [myid:] - INFO
> [main:o.a.z.s.BlueThrottle@141
> > ]
> > > -
> > > > Weighed connection throttling is disabled
> > > > 2022-08-28 21:36:13,873 [myid:] - INFO
> > > [main:o.a.z.s.ZooKeeperServer@1297
> > > > ]
> > > > - minSessionTimeout set to 4000 ms
> > > > 2022-08-28 21:36:13,873 [myid:] - INFO
> > > [main:o.a.z.s.ZooKeeperServer@1306
> > > > ]
> > > > - maxSessionTimeout set to 40000 ms
> > > > 2022-08-28 21:36:13,874 [myid:] - INFO
> [main:o.a.z.s.ResponseCache@45
> > ]
> > > -
> > > > getData response cache size is initialized with value 400.
> > > > 2022-08-28 21:36:13,874 [myid:] - INFO
> [main:o.a.z.s.ResponseCache@45
> > ]
> > > -
> > > > getChildren response cache size is initialized with value 400.
> > > > 2022-08-28 21:36:13,874 [myid:] - INFO
> > > >  [main:o.a.z.s.u.RequestPathMetricsCollector@109] -
> > > > zookeeper.pathStats.slotCapacity = 60
> > > > 2022-08-28 21:36:13,874 [myid:] - INFO
> > > >  [main:o.a.z.s.u.RequestPathMetricsCollector@110] -
> > > > zookeeper.pathStats.slotDuration = 15
> > > > 2022-08-28 21:36:13,875 [myid:] - INFO
> > > >  [main:o.a.z.s.u.RequestPathMetricsCollector@111] -
> > > > zookeeper.pathStats.maxDepth = 6
> > > > 2022-08-28 21:36:13,875 [myid:] - INFO
> > > >  [main:o.a.z.s.u.RequestPathMetricsCollector@112] -
> > > > zookeeper.pathStats.initialDelay = 5
> > > > 2022-08-28 21:36:13,875 [myid:] - INFO
> > > >  [main:o.a.z.s.u.RequestPathMetricsCollector@113] -
> > > > zookeeper.pathStats.delay = 5
> > > > 2022-08-28 21:36:13,875 [myid:] - INFO
> > > >  [main:o.a.z.s.u.RequestPathMetricsCollector@114] -
> > > > zookeeper.pathStats.enabled = false
> > > > 2022-08-28 21:36:13,876 [myid:] - INFO
> > > [main:o.a.z.s.ZooKeeperServer@1533
> > > > ]
> > > > - The max bytes for all large requests are set to 104857600
> > > > 2022-08-28 21:36:13,876 [myid:] - INFO
> > > [main:o.a.z.s.ZooKeeperServer@1547
> > > > ]
> > > > - The large request threshold is set to -1
> > > > 2022-08-28 21:36:13,877 [myid:] - INFO
> > > >  [main:o.a.z.s.AuthenticationHelper@66] -
> > > zookeeper.enforce.auth.enabled =
> > > > false
> > > > 2022-08-28 21:36:13,877 [myid:] - INFO
> > > >  [main:o.a.z.s.AuthenticationHelper@67] -
> > > zookeeper.enforce.auth.schemes =
> > > > []
> > > > 2022-08-28 21:36:13,877 [myid:] - INFO
> > [main:o.a.z.s.ZooKeeperServer@365
> > > ]
> > > > - Created server with tickTime 2000 ms minSessionTimeout 4000 ms
> > > > maxSessionTimeout 40000 ms clientPortListenBacklog -1 datadir
> > > > /tmp/zookeeper/3.8.0/version-2 snapdir /tmp/zookeeper/3.8.0/version-2
> > > > 2022-08-28 21:36:13,890 [myid:] - INFO  [main:o.e.j.u.l.Log@170] -
> > > Logging
> > > > initialized @348ms to org.eclipse.jetty.util.log.Slf4jLog
> > > > 2022-08-28 21:36:13,929 [myid:] - WARN
> > > [main:o.e.j.s.h.ContextHandler@1656
> > > > ]
> > > > - o.e.j.s.ServletContextHandler@3cebbb30{/,null,STOPPED} contextPath
> > > ends
> > > > with /*
> > > > 2022-08-28 21:36:13,930 [myid:] - WARN
> > > [main:o.e.j.s.h.ContextHandler@1667
> > > > ]
> > > > - Empty contextPath
> > > > 2022-08-28 21:36:13,951 [myid:] - INFO  [main:o.e.j.s.Server@375] -
> > > > jetty-9.4.43.v20210629; built: 2021-06-30T11:07:22.254Z; git:
> > > > 526006ecfa3af7f1a27ef3a288e2bef7ea9dd7e8; jvm
> > > > 11.0.16+8-post-Ubuntu-0ubuntu120.04
> > > > 2022-08-28 21:36:13,967 [myid:] - INFO
> > > >  [main:o.e.j.s.s.DefaultSessionIdManager@334] -
> > DefaultSessionIdManager
> > > > workerName=node0
> > > > 2022-08-28 21:36:13,967 [myid:] - INFO
> > > >  [main:o.e.j.s.s.DefaultSessionIdManager@339] - No SessionScavenger
> > set,
> > > > using defaults
> > > > 2022-08-28 21:36:13,968 [myid:] - INFO
> [main:o.e.j.s.s.HouseKeeper@132
> > ]
> > > -
> > > > node0 Scavenging every 600000ms
> > > > 2022-08-28 21:36:13,970 [myid:] - WARN
> > > >  [main:o.e.j.s.ConstraintSecurityHandler@759] -
> > > > ServletContext@o.e.j.s.ServletContextHandler
> @3cebbb30{/,null,STARTING}
> > > has
> > > > uncovered http methods for path: /*
> > > > 2022-08-28 21:36:13,975 [myid:] - INFO
> > > [main:o.e.j.s.h.ContextHandler@915
> > > > ]
> > > > - Started o.e.j.s.ServletContextHandler@3cebbb30{/,null,AVAILABLE}
> > > > 2022-08-28 21:36:13,983 [myid:] - INFO
> > > [main:o.e.j.s.AbstractConnector@331
> > > > ]
> > > > - Started ServerConnector@29d89d5d{HTTP/1.1, (http/1.1)}{
> 0.0.0.0:8080}
> > > > 2022-08-28 21:36:13,983 [myid:] - INFO  [main:o.e.j.s.Server@415] -
> > > > Started
> > > > @441ms
> > > > 2022-08-28 21:36:13,983 [myid:] - INFO
> > > > [main:o.a.z.s.a.JettyAdminServer@196]
> > > > - Started AdminServer on address 0.0.0.0, port 8080 and command URL
> > > > /commands
> > > > 2022-08-28 21:36:13,986 [myid:] - INFO
> > > [main:o.a.z.s.ServerCnxnFactory@169
> > > > ]
> > > > - Using org.apache.zookeeper.server.NIOServerCnxnFactory as server
> > > > connection factory
> > > > 2022-08-28 21:36:13,987 [myid:] - WARN
> > > [main:o.a.z.s.ServerCnxnFactory@309
> > > > ]
> > > > - maxCnxns is not configured, using default value 0.
> > > > 2022-08-28 21:36:13,988 [myid:] - INFO
> > > >  [main:o.a.z.s.NIOServerCnxnFactory@652] - Configuring NIO
> connection
> > > > handler with 10s sessionless connection timeout, 2 selector
> thread(s),
> > 24
> > > > worker threads, and 64 kB direct buffers.
> > > > 2022-08-28 21:36:13,988 [myid:] - INFO
> > > >  [main:o.a.z.s.NIOServerCnxnFactory@660] - binding to port
> > > > 0.0.0.0/0.0.0.0:2181
> > > > 2022-08-28 21:36:13,997 [myid:] - INFO
> > > >  [main:o.a.z.s.w.WatchManagerFactory@42] - Using
> > > > org.apache.zookeeper.server.watch.WatchManager as watch manager
> > > > 2022-08-28 21:36:13,997 [myid:] - INFO
> > > >  [main:o.a.z.s.w.WatchManagerFactory@42] - Using
> > > > org.apache.zookeeper.server.watch.WatchManager as watch manager
> > > > 2022-08-28 21:36:13,998 [myid:] - INFO  [main:o.a.z.s.ZKDatabase@132
> ]
> > -
> > > > zookeeper.snapshotSizeFactor = 0.33
> > > > 2022-08-28 21:36:13,998 [myid:] - INFO  [main:o.a.z.s.ZKDatabase@152
> ]
> > -
> > > > zookeeper.commitLogCount=500
> > > > 2022-08-28 21:36:14,002 [myid:] - INFO  [main:o.a.z.s.p.SnapStream@61
> ]
> > -
> > > > zookeeper.snapshot.compression.method = CHECKED
> > > >
> > > > Also here is my 3.8.0 zoo.cfg file:
> > > >
> > > > # The number of milliseconds of each tick
> > > > tickTime=2000
> > > > # The number of ticks that the initial
> > > > # synchronization phase can take
> > > > initLimit=10
> > > > # The number of ticks that can pass between
> > > > # sending a request and getting an acknowledgement
> > > > syncLimit=5
> > > > # the directory where the snapshot is stored.
> > > > # do not use /tmp for storage, /tmp here is just
> > > > # example sakes.
> > > > dataDir=/tmp/zookeeper/3.8.0
> > > > # the port at which the clients will connect
> > > > clientPort=2181
> > > > # the maximum number of client connections.
> > > > # increase this if you need to handle more clients
> > > > #maxClientCnxns=60
> > > > #
> > > > # Be sure to read the maintenance section of the
> > > > # administrator guide before turning on autopurge.
> > > > #
> > > > #
> > > >
> > >
> >
> https://zookeeper.apache.org/doc/current/zookeeperAdmin.html#sc_maintenance
> > > > #
> > > > # The number of snapshots to retain in dataDir
> > > > #autopurge.snapRetainCount=3
> > > > # Purge task interval in hours
> > > > # Set to "0" to disable auto purge feature
> > > > #autopurge.purgeInterval=1
> > > >
> > > > ## Metrics Providers
> > > > #
> > > > # https://prometheus.io Metrics Exporter
> > > >
> > > >
> > >
> >
> #metricsProvider.className=org.apache.zookeeper.metrics.prometheus.PrometheusMetricsProvider
> > > > #metricsProvider.httpHost=0.0.0.0
> > > > #metricsProvider.httpPort=7000
> > > > #metricsProvider.exportJvmInfo=true
> > > >
> > > > 4lw.commands.whitelist=*
> > > > digest.enabled=true
> > > >
> > > >
> > > >
> > >
> >
> metricsProvider.className=org.apache.zookeeper.metrics.impl.NullMetricsProvider
> > > >
> > >
> >
>
>
> --
> Best regards,
> Andrew
>
> Unrest, ignorance distilled, nihilistic imbeciles -
>     It's what we’ve earned
> Welcome, apocalypse, what’s taken you so long?
> Bring us the fitting end that we’ve been counting on
>    - A23, Welcome, Apocalypse
>

Re: Read performance of 3.4.6 vs 3.8.0 according to zookeeper-benchmark

Posted by Andrew Purtell <ap...@apache.org>.

Did you test with any 3.5 version?

Would be curious if the dip starts at 3.6. BlueThrottle and
RequestThrottler both went in at 3.6.0.



On Tue, Aug 30, 2022 at 1:20 PM Will Now <wn...@gmail.com> wrote:

> I've updated the results summary below to include 3.6.3 with and without
> digest.enabled; they are essentially the same.
>
> 27,052: 3.4.6
> 15,993: 3.6.3, digest.enabled=true
> 16,159: 3.6.3, *digest.enabled=false*
> 15,943: 3.7.1
> 16,805: 3.8.0, digest.enabled=true:
> 16,682: 3.8.0: digest.enabled=false
> 16,370: 3.8.0 NullMetricsProvider, *digest.enabled=false*
>
> I'm going to re-run my benchmarks in a 3-node ensemble instead of a local
> singleton. I'll also run the test client on a separate node.  This will
> match the environment I used years ago to measure 3.4.6 against 3.6.x, when
> I found that digest.enabled was having a big impact (a result that I am not
> reproducing at present)
>
> The zookeeper benchmark I am reporting is the number of synchronous
> sequential read operations on a single znode that can be completed in 30
> seconds.  No other transactions take place during the benchmark (ie no
> writes, etc)
>
> I'm optimistic that the anomaly I am reporting is some issue on my end and
> not in zookeeper. I'm pretty sure a big drop in performance like this would
> not have gone unnoticed.  Thanks for the responses. I'll report back!
>
> On Mon, Aug 29, 2022 at 12:37 AM Szalay-Bekő Máté <
> szalay.beko.mate@gmail.com> wrote:
>
> > Interesting, thanks for sharing the results!
> >
> > It will be hard to figure out what changed since the 3.4.6 release. Many
> > new features added. Still, it would be good to find out which version /
> > commit was responsible for the most performance degradation.
> >
> > You wrote before:
> > > A while back I performed similar comparisons of 3.4.6 vs 3.6.x and I
> got
> > > slow results in 3.6.x initially, but disabling digest.enabled fixed it
> > and
> > > the two versions were then comparable. In 3.8.0 I am seeing poor
> results
> > > with or without digest enabled.
> >
> > Then later:
> > > 27,052: 3.4.6
> > > 15,993:3.6.3
> > > 15,943:3.7.1
> > > 16,805: 3.8.0, digest.enabled=true:
> > > 16,682: 3.8.0: digest.enabled=false
> > > *16,370: 3.8.0 NullMetricsProvider*
> >
> > Was the "15,993:3.6.3" measured with or without digest? It sounds like
> > earlier you were able to get good results with 3.6.x
> > (using digest.enabled=false). Is this still reproducible with 3.6.3? If
> > yes, then still I would look around the digest feature for potential root
> > cause.
> >
> > On the other hand, the digest feature should not really affect the read
> > path, as far as I understood. But I also don't know how the benchmarking
> > tool executes the operations (maybe there are writes running parallel
> with
> > reads?).
> >
> > Máté
> >
> >
> > On Mon, Aug 29, 2022 at 7:00 AM Will Now <wn...@gmail.com> wrote:
> >
> > > In case it is informative, here is the output from running zookeeper
> > 3.8.0
> > > in my latest test run with NullMetricsProvider.
> > >
> > > ~/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin$ ./zkServer.sh
> > > start-foreground
> > > /usr/bin/java
> > > ZooKeeper JMX enabled by default
> > > Using config:
> > >
> >
> /home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../conf/zoo.cfg
> > > 2022-08-28 21:36:13,846 [myid:] - INFO
> > > [main:o.a.z.s.q.QuorumPeerConfig@177]
> > > - Reading configuration from:
> > >
> >
> /home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../conf/zoo.cfg
> > > 2022-08-28 21:36:13,850 [myid:] - INFO
> > > [main:o.a.z.s.q.QuorumPeerConfig@440]
> > > - clientPortAddress is 0.0.0.0:2181
> > > 2022-08-28 21:36:13,851 [myid:] - INFO
> > > [main:o.a.z.s.q.QuorumPeerConfig@444]
> > > - secureClientPort is not set
> > > 2022-08-28 21:36:13,851 [myid:] - INFO
> > > [main:o.a.z.s.q.QuorumPeerConfig@460]
> > > - observerMasterPort is not set
> > > 2022-08-28 21:36:13,851 [myid:] - INFO
> > > [main:o.a.z.s.q.QuorumPeerConfig@477]
> > > - metricsProvider.className is
> > > org.apache.zookeeper.metrics.impl.NullMetricsProvider
> > > 2022-08-28 21:36:13,852 [myid:] - INFO
> > >  [main:o.a.z.s.DatadirCleanupManager@78] - autopurge.snapRetainCount
> set
> > > to
> > > 3
> > > 2022-08-28 21:36:13,852 [myid:] - INFO
> > >  [main:o.a.z.s.DatadirCleanupManager@79] - autopurge.purgeInterval set
> > to
> > > 0
> > > 2022-08-28 21:36:13,852 [myid:] - INFO
> > >  [main:o.a.z.s.DatadirCleanupManager@101] - Purge task is not
> scheduled.
> > > 2022-08-28 21:36:13,852 [myid:] - WARN
> > [main:o.a.z.s.q.QuorumPeerMain@139
> > > ]
> > > - Either no config or no quorum defined in config, running in
> standalone
> > > mode
> > > 2022-08-28 21:36:13,853 [myid:] - INFO  [main:o.a.z.j.ManagedUtil@46]
> -
> > > Log4j 1.2 jmx support not found; jmx disabled.
> > > 2022-08-28 21:36:13,853 [myid:] - INFO
> > > [main:o.a.z.s.q.QuorumPeerConfig@177]
> > > - Reading configuration from:
> > >
> >
> /home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../conf/zoo.cfg
> > > 2022-08-28 21:36:13,854 [myid:] - INFO
> > > [main:o.a.z.s.q.QuorumPeerConfig@440]
> > > - clientPortAddress is 0.0.0.0:2181
> > > 2022-08-28 21:36:13,854 [myid:] - INFO
> > > [main:o.a.z.s.q.QuorumPeerConfig@444]
> > > - secureClientPort is not set
> > > 2022-08-28 21:36:13,854 [myid:] - INFO
> > > [main:o.a.z.s.q.QuorumPeerConfig@460]
> > > - observerMasterPort is not set
> > > 2022-08-28 21:36:13,854 [myid:] - INFO
> > > [main:o.a.z.s.q.QuorumPeerConfig@477]
> > > - metricsProvider.className is
> > > org.apache.zookeeper.metrics.impl.NullMetricsProvider
> > > 2022-08-28 21:36:13,854 [myid:] - INFO
> > >  [main:o.a.z.s.ZooKeeperServerMain@123] - Starting server
> > > 2022-08-28 21:36:13,861 [myid:] - INFO  [main:o.a.z.s.ServerMetrics@64
> ]
> > -
> > > ServerMetrics initialized with provider
> > > org.apache.zookeeper.metrics.impl.NullMetricsProvider@4d5d943d
> > > 2022-08-28 21:36:13,862 [myid:] - INFO
> > >  [main:o.a.z.s.a.DigestAuthenticationProvider@47] - ACL digest
> algorithm
> > > is: SHA1
> > > 2022-08-28 21:36:13,862 [myid:] - INFO
> > >  [main:o.a.z.s.a.DigestAuthenticationProvider@61] -
> > > zookeeper.DigestAuthenticationProvider.enabled = true
> > > 2022-08-28 21:36:13,863 [myid:] - INFO
> > [main:o.a.z.s.p.FileTxnSnapLog@124
> > > ]
> > > - zookeeper.snapshot.trust.empty : false
> > > 2022-08-28 21:36:13,869 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42
> ]
> > -
> > > 2022-08-28 21:36:13,869 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42
> ]
> > -
> > > ______                  _
> > > 2022-08-28 21:36:13,869 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42
> ]
> > -
> > >  |___  /                 | |
> > > 2022-08-28 21:36:13,869 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42
> ]
> > -
> > >   / /    ___     ___   | | __   ___    ___   _ __     ___   _ __
> > > 2022-08-28 21:36:13,869 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42
> ]
> > -
> > >  / /    / _ \   / _ \  | |/ /  / _ \  / _ \ | '_ \   / _ \ | '__|
> > > 2022-08-28 21:36:13,869 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42
> ]
> > -
> > > / /__  | (_) | | (_) | |   <  |  __/ |  __/ | |_) | |  __/ | |
> > > 2022-08-28 21:36:13,870 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42
> ]
> > -
> > >  /_____|  \___/   \___/  |_|\_\  \___|  \___| | .__/   \___| |_|
> > > 2022-08-28 21:36:13,870 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42
> ]
> > -
> > >                                             | |
> > > 2022-08-28 21:36:13,870 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42
> ]
> > -
> > >                                             |_|
> > > 2022-08-28 21:36:13,870 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42
> ]
> > -
> > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > > Server
> > >
> > >
> >
> environment:zookeeper.version=3.8.0-5a02a05eddb59aee6ac762f7ea82e92a68eb9c0f,
> > > built on 2022-02-25 08:49 UTC
> > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > > Server environment:host.name=host
> > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > > Server environment:java.version=11.0.16
> > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > > Server environment:java.vendor=Ubuntu
> > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > > Server environment:java.home=/usr/lib/jvm/java-11-openjdk-amd64
> > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > > Server
> > >
> > >
> >
> environment:java.class.path=/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../zookeeper-server/target/classes:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../build/classes:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../zookeeper-server/target/lib/*.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../build/lib/*.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/zookeeper-prometheus-metrics-3.8.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/zookeeper-jute-3.8.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/zookeeper-3.8.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/snappy-java-1.1.7.7.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/slf4j-api-1.7.30.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/simpleclient_servlet-0.9.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/simpleclient_hotspot-0.9.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/simpleclient_common-0.9.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/simpleclient-0.9.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-transport-native-unix-common-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-transport-native-epoll-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-transport-classes-epoll-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-transport-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-tcnative-classes-2.0.48.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-tcnative-2.0.48.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-resolver-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-handler-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-common-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-codec-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-buffer-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/metrics-core-4.1.12.1.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/logback-core-1.2.10.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/logback-classic-1.2.10.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jline-2.14.6.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-util-ajax-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-util-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-servlet-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-server-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-security-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-io-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-http-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/javax.servlet-api-3.1.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jackson-databind-2.13.1.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jackson-core-2.13.1.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jackson-annotations-2.13.1.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/commons-io-2.11.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/commons-cli-1.4.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/audience-annotations-0.12.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../zookeeper-*.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../zookeeper-server/src/main/resources/lib/*.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../conf:
> > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > > Server
> > >
> > >
> >
> environment:java.library.path=/usr/java/packages/lib:/usr/lib/x86_64-linux-gnu/jni:/lib/x86_64-linux-gnu:/usr/lib/x86_64-linux-gnu:/usr/lib/jni:/lib:/usr/lib
> > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > > Server environment:java.io.tmpdir=/tmp
> > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > > Server environment:java.compiler=<NA>
> > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > > Server environment:os.name=Linux
> > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > > Server environment:os.arch=amd64
> > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > > Server environment:os.version=5.15.0-46-generic
> > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > > Server
> > >
> > >
> >
> environment:user.dir=/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin
> > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > > Server environment:os.memory.free=231MB
> > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > > Server environment:os.memory.max=1000MB
> > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > > Server environment:os.memory.total=250MB
> > > 2022-08-28 21:36:13,871 [myid:] - INFO
> [main:o.a.z.s.ZooKeeperServer@140
> > ]
> > > - zookeeper.enableEagerACLCheck = false
> > > 2022-08-28 21:36:13,872 [myid:] - INFO
> [main:o.a.z.s.ZooKeeperServer@153
> > ]
> > > - zookeeper.digest.enabled = true
> > > 2022-08-28 21:36:13,872 [myid:] - INFO
> [main:o.a.z.s.ZooKeeperServer@157
> > ]
> > > - zookeeper.closeSessionTxn.enabled = true
> > > 2022-08-28 21:36:13,872 [myid:] - INFO
> > [main:o.a.z.s.ZooKeeperServer@1496
> > > ]
> > > - zookeeper.flushDelay = 0 ms
> > > 2022-08-28 21:36:13,872 [myid:] - INFO
> > [main:o.a.z.s.ZooKeeperServer@1505
> > > ]
> > > - zookeeper.maxWriteQueuePollTime = 0 ms
> > > 2022-08-28 21:36:13,872 [myid:] - INFO
> > [main:o.a.z.s.ZooKeeperServer@1514
> > > ]
> > > - zookeeper.maxBatchSize=1000
> > > 2022-08-28 21:36:13,872 [myid:] - INFO
> [main:o.a.z.s.ZooKeeperServer@264
> > ]
> > > - zookeeper.intBufferStartingSizeBytes = 1024
> > > 2022-08-28 21:36:13,872 [myid:] - INFO  [main:o.a.z.s.BlueThrottle@141
> ]
> > -
> > > Weighed connection throttling is disabled
> > > 2022-08-28 21:36:13,873 [myid:] - INFO
> > [main:o.a.z.s.ZooKeeperServer@1297
> > > ]
> > > - minSessionTimeout set to 4000 ms
> > > 2022-08-28 21:36:13,873 [myid:] - INFO
> > [main:o.a.z.s.ZooKeeperServer@1306
> > > ]
> > > - maxSessionTimeout set to 40000 ms
> > > 2022-08-28 21:36:13,874 [myid:] - INFO  [main:o.a.z.s.ResponseCache@45
> ]
> > -
> > > getData response cache size is initialized with value 400.
> > > 2022-08-28 21:36:13,874 [myid:] - INFO  [main:o.a.z.s.ResponseCache@45
> ]
> > -
> > > getChildren response cache size is initialized with value 400.
> > > 2022-08-28 21:36:13,874 [myid:] - INFO
> > >  [main:o.a.z.s.u.RequestPathMetricsCollector@109] -
> > > zookeeper.pathStats.slotCapacity = 60
> > > 2022-08-28 21:36:13,874 [myid:] - INFO
> > >  [main:o.a.z.s.u.RequestPathMetricsCollector@110] -
> > > zookeeper.pathStats.slotDuration = 15
> > > 2022-08-28 21:36:13,875 [myid:] - INFO
> > >  [main:o.a.z.s.u.RequestPathMetricsCollector@111] -
> > > zookeeper.pathStats.maxDepth = 6
> > > 2022-08-28 21:36:13,875 [myid:] - INFO
> > >  [main:o.a.z.s.u.RequestPathMetricsCollector@112] -
> > > zookeeper.pathStats.initialDelay = 5
> > > 2022-08-28 21:36:13,875 [myid:] - INFO
> > >  [main:o.a.z.s.u.RequestPathMetricsCollector@113] -
> > > zookeeper.pathStats.delay = 5
> > > 2022-08-28 21:36:13,875 [myid:] - INFO
> > >  [main:o.a.z.s.u.RequestPathMetricsCollector@114] -
> > > zookeeper.pathStats.enabled = false
> > > 2022-08-28 21:36:13,876 [myid:] - INFO
> > [main:o.a.z.s.ZooKeeperServer@1533
> > > ]
> > > - The max bytes for all large requests are set to 104857600
> > > 2022-08-28 21:36:13,876 [myid:] - INFO
> > [main:o.a.z.s.ZooKeeperServer@1547
> > > ]
> > > - The large request threshold is set to -1
> > > 2022-08-28 21:36:13,877 [myid:] - INFO
> > >  [main:o.a.z.s.AuthenticationHelper@66] -
> > zookeeper.enforce.auth.enabled =
> > > false
> > > 2022-08-28 21:36:13,877 [myid:] - INFO
> > >  [main:o.a.z.s.AuthenticationHelper@67] -
> > zookeeper.enforce.auth.schemes =
> > > []
> > > 2022-08-28 21:36:13,877 [myid:] - INFO
> [main:o.a.z.s.ZooKeeperServer@365
> > ]
> > > - Created server with tickTime 2000 ms minSessionTimeout 4000 ms
> > > maxSessionTimeout 40000 ms clientPortListenBacklog -1 datadir
> > > /tmp/zookeeper/3.8.0/version-2 snapdir /tmp/zookeeper/3.8.0/version-2
> > > 2022-08-28 21:36:13,890 [myid:] - INFO  [main:o.e.j.u.l.Log@170] -
> > Logging
> > > initialized @348ms to org.eclipse.jetty.util.log.Slf4jLog
> > > 2022-08-28 21:36:13,929 [myid:] - WARN
> > [main:o.e.j.s.h.ContextHandler@1656
> > > ]
> > > - o.e.j.s.ServletContextHandler@3cebbb30{/,null,STOPPED} contextPath
> > ends
> > > with /*
> > > 2022-08-28 21:36:13,930 [myid:] - WARN
> > [main:o.e.j.s.h.ContextHandler@1667
> > > ]
> > > - Empty contextPath
> > > 2022-08-28 21:36:13,951 [myid:] - INFO  [main:o.e.j.s.Server@375] -
> > > jetty-9.4.43.v20210629; built: 2021-06-30T11:07:22.254Z; git:
> > > 526006ecfa3af7f1a27ef3a288e2bef7ea9dd7e8; jvm
> > > 11.0.16+8-post-Ubuntu-0ubuntu120.04
> > > 2022-08-28 21:36:13,967 [myid:] - INFO
> > >  [main:o.e.j.s.s.DefaultSessionIdManager@334] -
> DefaultSessionIdManager
> > > workerName=node0
> > > 2022-08-28 21:36:13,967 [myid:] - INFO
> > >  [main:o.e.j.s.s.DefaultSessionIdManager@339] - No SessionScavenger
> set,
> > > using defaults
> > > 2022-08-28 21:36:13,968 [myid:] - INFO  [main:o.e.j.s.s.HouseKeeper@132
> ]
> > -
> > > node0 Scavenging every 600000ms
> > > 2022-08-28 21:36:13,970 [myid:] - WARN
> > >  [main:o.e.j.s.ConstraintSecurityHandler@759] -
> > > ServletContext@o.e.j.s.ServletContextHandler@3cebbb30{/,null,STARTING}
> > has
> > > uncovered http methods for path: /*
> > > 2022-08-28 21:36:13,975 [myid:] - INFO
> > [main:o.e.j.s.h.ContextHandler@915
> > > ]
> > > - Started o.e.j.s.ServletContextHandler@3cebbb30{/,null,AVAILABLE}
> > > 2022-08-28 21:36:13,983 [myid:] - INFO
> > [main:o.e.j.s.AbstractConnector@331
> > > ]
> > > - Started ServerConnector@29d89d5d{HTTP/1.1, (http/1.1)}{0.0.0.0:8080}
> > > 2022-08-28 21:36:13,983 [myid:] - INFO  [main:o.e.j.s.Server@415] -
> > > Started
> > > @441ms
> > > 2022-08-28 21:36:13,983 [myid:] - INFO
> > > [main:o.a.z.s.a.JettyAdminServer@196]
> > > - Started AdminServer on address 0.0.0.0, port 8080 and command URL
> > > /commands
> > > 2022-08-28 21:36:13,986 [myid:] - INFO
> > [main:o.a.z.s.ServerCnxnFactory@169
> > > ]
> > > - Using org.apache.zookeeper.server.NIOServerCnxnFactory as server
> > > connection factory
> > > 2022-08-28 21:36:13,987 [myid:] - WARN
> > [main:o.a.z.s.ServerCnxnFactory@309
> > > ]
> > > - maxCnxns is not configured, using default value 0.
> > > 2022-08-28 21:36:13,988 [myid:] - INFO
> > >  [main:o.a.z.s.NIOServerCnxnFactory@652] - Configuring NIO connection
> > > handler with 10s sessionless connection timeout, 2 selector thread(s),
> 24
> > > worker threads, and 64 kB direct buffers.
> > > 2022-08-28 21:36:13,988 [myid:] - INFO
> > >  [main:o.a.z.s.NIOServerCnxnFactory@660] - binding to port
> > > 0.0.0.0/0.0.0.0:2181
> > > 2022-08-28 21:36:13,997 [myid:] - INFO
> > >  [main:o.a.z.s.w.WatchManagerFactory@42] - Using
> > > org.apache.zookeeper.server.watch.WatchManager as watch manager
> > > 2022-08-28 21:36:13,997 [myid:] - INFO
> > >  [main:o.a.z.s.w.WatchManagerFactory@42] - Using
> > > org.apache.zookeeper.server.watch.WatchManager as watch manager
> > > 2022-08-28 21:36:13,998 [myid:] - INFO  [main:o.a.z.s.ZKDatabase@132]
> -
> > > zookeeper.snapshotSizeFactor = 0.33
> > > 2022-08-28 21:36:13,998 [myid:] - INFO  [main:o.a.z.s.ZKDatabase@152]
> -
> > > zookeeper.commitLogCount=500
> > > 2022-08-28 21:36:14,002 [myid:] - INFO  [main:o.a.z.s.p.SnapStream@61]
> -
> > > zookeeper.snapshot.compression.method = CHECKED
> > >
> > > Also here is my 3.8.0 zoo.cfg file:
> > >
> > > # The number of milliseconds of each tick
> > > tickTime=2000
> > > # The number of ticks that the initial
> > > # synchronization phase can take
> > > initLimit=10
> > > # The number of ticks that can pass between
> > > # sending a request and getting an acknowledgement
> > > syncLimit=5
> > > # the directory where the snapshot is stored.
> > > # do not use /tmp for storage, /tmp here is just
> > > # example sakes.
> > > dataDir=/tmp/zookeeper/3.8.0
> > > # the port at which the clients will connect
> > > clientPort=2181
> > > # the maximum number of client connections.
> > > # increase this if you need to handle more clients
> > > #maxClientCnxns=60
> > > #
> > > # Be sure to read the maintenance section of the
> > > # administrator guide before turning on autopurge.
> > > #
> > > #
> > >
> >
> https://zookeeper.apache.org/doc/current/zookeeperAdmin.html#sc_maintenance
> > > #
> > > # The number of snapshots to retain in dataDir
> > > #autopurge.snapRetainCount=3
> > > # Purge task interval in hours
> > > # Set to "0" to disable auto purge feature
> > > #autopurge.purgeInterval=1
> > >
> > > ## Metrics Providers
> > > #
> > > # https://prometheus.io Metrics Exporter
> > >
> > >
> >
> #metricsProvider.className=org.apache.zookeeper.metrics.prometheus.PrometheusMetricsProvider
> > > #metricsProvider.httpHost=0.0.0.0
> > > #metricsProvider.httpPort=7000
> > > #metricsProvider.exportJvmInfo=true
> > >
> > > 4lw.commands.whitelist=*
> > > digest.enabled=true
> > >
> > >
> > >
> >
> metricsProvider.className=org.apache.zookeeper.metrics.impl.NullMetricsProvider
> > >
> >
>


-- 
Best regards,
Andrew

Unrest, ignorance distilled, nihilistic imbeciles -
    It's what we’ve earned
Welcome, apocalypse, what’s taken you so long?
Bring us the fitting end that we’ve been counting on
   - A23, Welcome, Apocalypse

Re: Read performance of 3.4.6 vs 3.8.0 according to zookeeper-benchmark

Posted by Paul Brebner <pa...@instaclustr.com>.

Hi all - I'm giving my "Zookeer meets the dining philosophers" talk at
ApacheCon in the USA in Oct, which contains some (old) benchmarking results
(and specific to the application I built).
However, I noticed the discussion on recent ZK benchmarking and wondering
if I should perhaps add a slide at the end with some up to date results
from the community - happy to add something nearer the time if anyone could
update me/point me to the lastest results with a short explanation of how
they were produced, what they mean, what version etc? Regards, Paul
Brebner, Instaclustr

On Wed, 31 Aug 2022 at 06:20, Will Now <wn...@gmail.com> wrote:

> I've updated the results summary below to include 3.6.3 with and without
> digest.enabled; they are essentially the same.
>
> 27,052: 3.4.6
> 15,993: 3.6.3, digest.enabled=true
> 16,159: 3.6.3, *digest.enabled=false*
> 15,943: 3.7.1
> 16,805: 3.8.0, digest.enabled=true:
> 16,682: 3.8.0: digest.enabled=false
> 16,370: 3.8.0 NullMetricsProvider, *digest.enabled=false*
>
> I'm going to re-run my benchmarks in a 3-node ensemble instead of a local
> singleton. I'll also run the test client on a separate node.  This will
> match the environment I used years ago to measure 3.4.6 against 3.6.x, when
> I found that digest.enabled was having a big impact (a result that I am not
> reproducing at present)
>
> The zookeeper benchmark I am reporting is the number of synchronous
> sequential read operations on a single znode that can be completed in 30
> seconds.  No other transactions take place during the benchmark (ie no
> writes, etc)
>
> I'm optimistic that the anomaly I am reporting is some issue on my end and
> not in zookeeper. I'm pretty sure a big drop in performance like this would
> not have gone unnoticed.  Thanks for the responses. I'll report back!
>
> On Mon, Aug 29, 2022 at 12:37 AM Szalay-Bekő Máté <
> szalay.beko.mate@gmail.com> wrote:
>
> > Interesting, thanks for sharing the results!
> >
> > It will be hard to figure out what changed since the 3.4.6 release. Many
> > new features added. Still, it would be good to find out which version /
> > commit was responsible for the most performance degradation.
> >
> > You wrote before:
> > > A while back I performed similar comparisons of 3.4.6 vs 3.6.x and I
> got
> > > slow results in 3.6.x initially, but disabling digest.enabled fixed it
> > and
> > > the two versions were then comparable. In 3.8.0 I am seeing poor
> results
> > > with or without digest enabled.
> >
> > Then later:
> > > 27,052: 3.4.6
> > > 15,993:3.6.3
> > > 15,943:3.7.1
> > > 16,805: 3.8.0, digest.enabled=true:
> > > 16,682: 3.8.0: digest.enabled=false
> > > *16,370: 3.8.0 NullMetricsProvider*
> >
> > Was the "15,993:3.6.3" measured with or without digest? It sounds like
> > earlier you were able to get good results with 3.6.x
> > (using digest.enabled=false). Is this still reproducible with 3.6.3? If
> > yes, then still I would look around the digest feature for potential root
> > cause.
> >
> > On the other hand, the digest feature should not really affect the read
> > path, as far as I understood. But I also don't know how the benchmarking
> > tool executes the operations (maybe there are writes running parallel
> with
> > reads?).
> >
> > Máté
> >
> >
> > On Mon, Aug 29, 2022 at 7:00 AM Will Now <wn...@gmail.com> wrote:
> >
> > > In case it is informative, here is the output from running zookeeper
> > 3.8.0
> > > in my latest test run with NullMetricsProvider.
> > >
> > > ~/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin$ ./zkServer.sh
> > > start-foreground
> > > /usr/bin/java
> > > ZooKeeper JMX enabled by default
> > > Using config:
> > >
> >
> /home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../conf/zoo.cfg
> > > 2022-08-28 21:36:13,846 [myid:] - INFO
> > > [main:o.a.z.s.q.QuorumPeerConfig@177]
> > > - Reading configuration from:
> > >
> >
> /home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../conf/zoo.cfg
> > > 2022-08-28 21:36:13,850 [myid:] - INFO
> > > [main:o.a.z.s.q.QuorumPeerConfig@440]
> > > - clientPortAddress is 0.0.0.0:2181
> > > 2022-08-28 21:36:13,851 [myid:] - INFO
> > > [main:o.a.z.s.q.QuorumPeerConfig@444]
> > > - secureClientPort is not set
> > > 2022-08-28 21:36:13,851 [myid:] - INFO
> > > [main:o.a.z.s.q.QuorumPeerConfig@460]
> > > - observerMasterPort is not set
> > > 2022-08-28 21:36:13,851 [myid:] - INFO
> > > [main:o.a.z.s.q.QuorumPeerConfig@477]
> > > - metricsProvider.className is
> > > org.apache.zookeeper.metrics.impl.NullMetricsProvider
> > > 2022-08-28 21:36:13,852 [myid:] - INFO
> > >  [main:o.a.z.s.DatadirCleanupManager@78] - autopurge.snapRetainCount
> set
> > > to
> > > 3
> > > 2022-08-28 21:36:13,852 [myid:] - INFO
> > >  [main:o.a.z.s.DatadirCleanupManager@79] - autopurge.purgeInterval set
> > to
> > > 0
> > > 2022-08-28 21:36:13,852 [myid:] - INFO
> > >  [main:o.a.z.s.DatadirCleanupManager@101] - Purge task is not
> scheduled.
> > > 2022-08-28 21:36:13,852 [myid:] - WARN
> > [main:o.a.z.s.q.QuorumPeerMain@139
> > > ]
> > > - Either no config or no quorum defined in config, running in
> standalone
> > > mode
> > > 2022-08-28 21:36:13,853 [myid:] - INFO  [main:o.a.z.j.ManagedUtil@46]
> -
> > > Log4j 1.2 jmx support not found; jmx disabled.
> > > 2022-08-28 21:36:13,853 [myid:] - INFO
> > > [main:o.a.z.s.q.QuorumPeerConfig@177]
> > > - Reading configuration from:
> > >
> >
> /home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../conf/zoo.cfg
> > > 2022-08-28 21:36:13,854 [myid:] - INFO
> > > [main:o.a.z.s.q.QuorumPeerConfig@440]
> > > - clientPortAddress is 0.0.0.0:2181
> > > 2022-08-28 21:36:13,854 [myid:] - INFO
> > > [main:o.a.z.s.q.QuorumPeerConfig@444]
> > > - secureClientPort is not set
> > > 2022-08-28 21:36:13,854 [myid:] - INFO
> > > [main:o.a.z.s.q.QuorumPeerConfig@460]
> > > - observerMasterPort is not set
> > > 2022-08-28 21:36:13,854 [myid:] - INFO
> > > [main:o.a.z.s.q.QuorumPeerConfig@477]
> > > - metricsProvider.className is
> > > org.apache.zookeeper.metrics.impl.NullMetricsProvider
> > > 2022-08-28 21:36:13,854 [myid:] - INFO
> > >  [main:o.a.z.s.ZooKeeperServerMain@123] - Starting server
> > > 2022-08-28 21:36:13,861 [myid:] - INFO  [main:o.a.z.s.ServerMetrics@64
> ]
> > -
> > > ServerMetrics initialized with provider
> > > org.apache.zookeeper.metrics.impl.NullMetricsProvider@4d5d943d
> > > 2022-08-28 21:36:13,862 [myid:] - INFO
> > >  [main:o.a.z.s.a.DigestAuthenticationProvider@47] - ACL digest
> algorithm
> > > is: SHA1
> > > 2022-08-28 21:36:13,862 [myid:] - INFO
> > >  [main:o.a.z.s.a.DigestAuthenticationProvider@61] -
> > > zookeeper.DigestAuthenticationProvider.enabled = true
> > > 2022-08-28 21:36:13,863 [myid:] - INFO
> > [main:o.a.z.s.p.FileTxnSnapLog@124
> > > ]
> > > - zookeeper.snapshot.trust.empty : false
> > > 2022-08-28 21:36:13,869 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42
> ]
> > -
> > > 2022-08-28 21:36:13,869 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42
> ]
> > -
> > > ______                  _
> > > 2022-08-28 21:36:13,869 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42
> ]
> > -
> > >  |___  /                 | |
> > > 2022-08-28 21:36:13,869 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42
> ]
> > -
> > >   / /    ___     ___   | | __   ___    ___   _ __     ___   _ __
> > > 2022-08-28 21:36:13,869 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42
> ]
> > -
> > >  / /    / _ \   / _ \  | |/ /  / _ \  / _ \ | '_ \   / _ \ | '__|
> > > 2022-08-28 21:36:13,869 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42
> ]
> > -
> > > / /__  | (_) | | (_) | |   <  |  __/ |  __/ | |_) | |  __/ | |
> > > 2022-08-28 21:36:13,870 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42
> ]
> > -
> > >  /_____|  \___/   \___/  |_|\_\  \___|  \___| | .__/   \___| |_|
> > > 2022-08-28 21:36:13,870 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42
> ]
> > -
> > >                                             | |
> > > 2022-08-28 21:36:13,870 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42
> ]
> > -
> > >                                             |_|
> > > 2022-08-28 21:36:13,870 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42
> ]
> > -
> > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > > Server
> > >
> > >
> >
> environment:zookeeper.version=3.8.0-5a02a05eddb59aee6ac762f7ea82e92a68eb9c0f,
> > > built on 2022-02-25 08:49 UTC
> > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > > Server environment:host.name=host
> > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > > Server environment:java.version=11.0.16
> > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > > Server environment:java.vendor=Ubuntu
> > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > > Server environment:java.home=/usr/lib/jvm/java-11-openjdk-amd64
> > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > > Server
> > >
> > >
> >
> environment:java.class.path=/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../zookeeper-server/target/classes:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../build/classes:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../zookeeper-server/target/lib/*.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../build/lib/*.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/zookeeper-prometheus-metrics-3.8.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/zookeeper-jute-3.8.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/zookeeper-3.8.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/snappy-java-1.1.7.7.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/slf4j-api-1.7.30.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/simpleclient_servlet-0.9.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/simpleclient_hotspot-0.9.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/simpleclient_common-0.9.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/simpleclient-0.9.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-transport-native-unix-common-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-transport-native-epoll-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-transport-classes-epoll-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-transport-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-tcnative-classes-2.0.48.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-tcnative-2.0.48.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-resolver-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-handler-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-common-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-codec-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-buffer-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/metrics-core-4.1.12.1.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/logback-core-1.2.10.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/logback-classic-1.2.10.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jline-2.14.6.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-util-ajax-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-util-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-servlet-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-server-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-security-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-io-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-http-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/javax.servlet-api-3.1.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jackson-databind-2.13.1.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jackson-core-2.13.1.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jackson-annotations-2.13.1.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/commons-io-2.11.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/commons-cli-1.4.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/audience-annotations-0.12.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../zookeeper-*.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../zookeeper-server/src/main/resources/lib/*.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../conf:
> > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > > Server
> > >
> > >
> >
> environment:java.library.path=/usr/java/packages/lib:/usr/lib/x86_64-linux-gnu/jni:/lib/x86_64-linux-gnu:/usr/lib/x86_64-linux-gnu:/usr/lib/jni:/lib:/usr/lib
> > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > > Server environment:java.io.tmpdir=/tmp
> > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > > Server environment:java.compiler=<NA>
> > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > > Server environment:os.name=Linux
> > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > > Server environment:os.arch=amd64
> > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > > Server environment:os.version=5.15.0-46-generic
> > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > > Server
> > >
> > >
> >
> environment:user.dir=/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin
> > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > > Server environment:os.memory.free=231MB
> > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > > Server environment:os.memory.max=1000MB
> > > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > > Server environment:os.memory.total=250MB
> > > 2022-08-28 21:36:13,871 [myid:] - INFO
> [main:o.a.z.s.ZooKeeperServer@140
> > ]
> > > - zookeeper.enableEagerACLCheck = false
> > > 2022-08-28 21:36:13,872 [myid:] - INFO
> [main:o.a.z.s.ZooKeeperServer@153
> > ]
> > > - zookeeper.digest.enabled = true
> > > 2022-08-28 21:36:13,872 [myid:] - INFO
> [main:o.a.z.s.ZooKeeperServer@157
> > ]
> > > - zookeeper.closeSessionTxn.enabled = true
> > > 2022-08-28 21:36:13,872 [myid:] - INFO
> > [main:o.a.z.s.ZooKeeperServer@1496
> > > ]
> > > - zookeeper.flushDelay = 0 ms
> > > 2022-08-28 21:36:13,872 [myid:] - INFO
> > [main:o.a.z.s.ZooKeeperServer@1505
> > > ]
> > > - zookeeper.maxWriteQueuePollTime = 0 ms
> > > 2022-08-28 21:36:13,872 [myid:] - INFO
> > [main:o.a.z.s.ZooKeeperServer@1514
> > > ]
> > > - zookeeper.maxBatchSize=1000
> > > 2022-08-28 21:36:13,872 [myid:] - INFO
> [main:o.a.z.s.ZooKeeperServer@264
> > ]
> > > - zookeeper.intBufferStartingSizeBytes = 1024
> > > 2022-08-28 21:36:13,872 [myid:] - INFO  [main:o.a.z.s.BlueThrottle@141
> ]
> > -
> > > Weighed connection throttling is disabled
> > > 2022-08-28 21:36:13,873 [myid:] - INFO
> > [main:o.a.z.s.ZooKeeperServer@1297
> > > ]
> > > - minSessionTimeout set to 4000 ms
> > > 2022-08-28 21:36:13,873 [myid:] - INFO
> > [main:o.a.z.s.ZooKeeperServer@1306
> > > ]
> > > - maxSessionTimeout set to 40000 ms
> > > 2022-08-28 21:36:13,874 [myid:] - INFO  [main:o.a.z.s.ResponseCache@45
> ]
> > -
> > > getData response cache size is initialized with value 400.
> > > 2022-08-28 21:36:13,874 [myid:] - INFO  [main:o.a.z.s.ResponseCache@45
> ]
> > -
> > > getChildren response cache size is initialized with value 400.
> > > 2022-08-28 21:36:13,874 [myid:] - INFO
> > >  [main:o.a.z.s.u.RequestPathMetricsCollector@109] -
> > > zookeeper.pathStats.slotCapacity = 60
> > > 2022-08-28 21:36:13,874 [myid:] - INFO
> > >  [main:o.a.z.s.u.RequestPathMetricsCollector@110] -
> > > zookeeper.pathStats.slotDuration = 15
> > > 2022-08-28 21:36:13,875 [myid:] - INFO
> > >  [main:o.a.z.s.u.RequestPathMetricsCollector@111] -
> > > zookeeper.pathStats.maxDepth = 6
> > > 2022-08-28 21:36:13,875 [myid:] - INFO
> > >  [main:o.a.z.s.u.RequestPathMetricsCollector@112] -
> > > zookeeper.pathStats.initialDelay = 5
> > > 2022-08-28 21:36:13,875 [myid:] - INFO
> > >  [main:o.a.z.s.u.RequestPathMetricsCollector@113] -
> > > zookeeper.pathStats.delay = 5
> > > 2022-08-28 21:36:13,875 [myid:] - INFO
> > >  [main:o.a.z.s.u.RequestPathMetricsCollector@114] -
> > > zookeeper.pathStats.enabled = false
> > > 2022-08-28 21:36:13,876 [myid:] - INFO
> > [main:o.a.z.s.ZooKeeperServer@1533
> > > ]
> > > - The max bytes for all large requests are set to 104857600
> > > 2022-08-28 21:36:13,876 [myid:] - INFO
> > [main:o.a.z.s.ZooKeeperServer@1547
> > > ]
> > > - The large request threshold is set to -1
> > > 2022-08-28 21:36:13,877 [myid:] - INFO
> > >  [main:o.a.z.s.AuthenticationHelper@66] -
> > zookeeper.enforce.auth.enabled =
> > > false
> > > 2022-08-28 21:36:13,877 [myid:] - INFO
> > >  [main:o.a.z.s.AuthenticationHelper@67] -
> > zookeeper.enforce.auth.schemes =
> > > []
> > > 2022-08-28 21:36:13,877 [myid:] - INFO
> [main:o.a.z.s.ZooKeeperServer@365
> > ]
> > > - Created server with tickTime 2000 ms minSessionTimeout 4000 ms
> > > maxSessionTimeout 40000 ms clientPortListenBacklog -1 datadir
> > > /tmp/zookeeper/3.8.0/version-2 snapdir /tmp/zookeeper/3.8.0/version-2
> > > 2022-08-28 21:36:13,890 [myid:] - INFO  [main:o.e.j.u.l.Log@170] -
> > Logging
> > > initialized @348ms to org.eclipse.jetty.util.log.Slf4jLog
> > > 2022-08-28 21:36:13,929 [myid:] - WARN
> > [main:o.e.j.s.h.ContextHandler@1656
> > > ]
> > > - o.e.j.s.ServletContextHandler@3cebbb30{/,null,STOPPED} contextPath
> > ends
> > > with /*
> > > 2022-08-28 21:36:13,930 [myid:] - WARN
> > [main:o.e.j.s.h.ContextHandler@1667
> > > ]
> > > - Empty contextPath
> > > 2022-08-28 21:36:13,951 [myid:] - INFO  [main:o.e.j.s.Server@375] -
> > > jetty-9.4.43.v20210629; built: 2021-06-30T11:07:22.254Z; git:
> > > 526006ecfa3af7f1a27ef3a288e2bef7ea9dd7e8; jvm
> > > 11.0.16+8-post-Ubuntu-0ubuntu120.04
> > > 2022-08-28 21:36:13,967 [myid:] - INFO
> > >  [main:o.e.j.s.s.DefaultSessionIdManager@334] -
> DefaultSessionIdManager
> > > workerName=node0
> > > 2022-08-28 21:36:13,967 [myid:] - INFO
> > >  [main:o.e.j.s.s.DefaultSessionIdManager@339] - No SessionScavenger
> set,
> > > using defaults
> > > 2022-08-28 21:36:13,968 [myid:] - INFO  [main:o.e.j.s.s.HouseKeeper@132
> ]
> > -
> > > node0 Scavenging every 600000ms
> > > 2022-08-28 21:36:13,970 [myid:] - WARN
> > >  [main:o.e.j.s.ConstraintSecurityHandler@759] -
> > > ServletContext@o.e.j.s.ServletContextHandler@3cebbb30{/,null,STARTING}
> > has
> > > uncovered http methods for path: /*
> > > 2022-08-28 21:36:13,975 [myid:] - INFO
> > [main:o.e.j.s.h.ContextHandler@915
> > > ]
> > > - Started o.e.j.s.ServletContextHandler@3cebbb30{/,null,AVAILABLE}
> > > 2022-08-28 21:36:13,983 [myid:] - INFO
> > [main:o.e.j.s.AbstractConnector@331
> > > ]
> > > - Started ServerConnector@29d89d5d{HTTP/1.1, (http/1.1)}{0.0.0.0:8080}
> > > 2022-08-28 21:36:13,983 [myid:] - INFO  [main:o.e.j.s.Server@415] -
> > > Started
> > > @441ms
> > > 2022-08-28 21:36:13,983 [myid:] - INFO
> > > [main:o.a.z.s.a.JettyAdminServer@196]
> > > - Started AdminServer on address 0.0.0.0, port 8080 and command URL
> > > /commands
> > > 2022-08-28 21:36:13,986 [myid:] - INFO
> > [main:o.a.z.s.ServerCnxnFactory@169
> > > ]
> > > - Using org.apache.zookeeper.server.NIOServerCnxnFactory as server
> > > connection factory
> > > 2022-08-28 21:36:13,987 [myid:] - WARN
> > [main:o.a.z.s.ServerCnxnFactory@309
> > > ]
> > > - maxCnxns is not configured, using default value 0.
> > > 2022-08-28 21:36:13,988 [myid:] - INFO
> > >  [main:o.a.z.s.NIOServerCnxnFactory@652] - Configuring NIO connection
> > > handler with 10s sessionless connection timeout, 2 selector thread(s),
> 24
> > > worker threads, and 64 kB direct buffers.
> > > 2022-08-28 21:36:13,988 [myid:] - INFO
> > >  [main:o.a.z.s.NIOServerCnxnFactory@660] - binding to port
> > > 0.0.0.0/0.0.0.0:2181
> > > 2022-08-28 21:36:13,997 [myid:] - INFO
> > >  [main:o.a.z.s.w.WatchManagerFactory@42] - Using
> > > org.apache.zookeeper.server.watch.WatchManager as watch manager
> > > 2022-08-28 21:36:13,997 [myid:] - INFO
> > >  [main:o.a.z.s.w.WatchManagerFactory@42] - Using
> > > org.apache.zookeeper.server.watch.WatchManager as watch manager
> > > 2022-08-28 21:36:13,998 [myid:] - INFO  [main:o.a.z.s.ZKDatabase@132]
> -
> > > zookeeper.snapshotSizeFactor = 0.33
> > > 2022-08-28 21:36:13,998 [myid:] - INFO  [main:o.a.z.s.ZKDatabase@152]
> -
> > > zookeeper.commitLogCount=500
> > > 2022-08-28 21:36:14,002 [myid:] - INFO  [main:o.a.z.s.p.SnapStream@61]
> -
> > > zookeeper.snapshot.compression.method = CHECKED
> > >
> > > Also here is my 3.8.0 zoo.cfg file:
> > >
> > > # The number of milliseconds of each tick
> > > tickTime=2000
> > > # The number of ticks that the initial
> > > # synchronization phase can take
> > > initLimit=10
> > > # The number of ticks that can pass between
> > > # sending a request and getting an acknowledgement
> > > syncLimit=5
> > > # the directory where the snapshot is stored.
> > > # do not use /tmp for storage, /tmp here is just
> > > # example sakes.
> > > dataDir=/tmp/zookeeper/3.8.0
> > > # the port at which the clients will connect
> > > clientPort=2181
> > > # the maximum number of client connections.
> > > # increase this if you need to handle more clients
> > > #maxClientCnxns=60
> > > #
> > > # Be sure to read the maintenance section of the
> > > # administrator guide before turning on autopurge.
> > > #
> > > #
> > >
> >
> https://zookeeper.apache.org/doc/current/zookeeperAdmin.html#sc_maintenance
> > > #
> > > # The number of snapshots to retain in dataDir
> > > #autopurge.snapRetainCount=3
> > > # Purge task interval in hours
> > > # Set to "0" to disable auto purge feature
> > > #autopurge.purgeInterval=1
> > >
> > > ## Metrics Providers
> > > #
> > > # https://prometheus.io Metrics Exporter
> > >
> > >
> >
> #metricsProvider.className=org.apache.zookeeper.metrics.prometheus.PrometheusMetricsProvider
> > > #metricsProvider.httpHost=0.0.0.0
> > > #metricsProvider.httpPort=7000
> > > #metricsProvider.exportJvmInfo=true
> > >
> > > 4lw.commands.whitelist=*
> > > digest.enabled=true
> > >
> > >
> > >
> >
> metricsProvider.className=org.apache.zookeeper.metrics.impl.NullMetricsProvider
> > >
> >
>

Re: Read performance of 3.4.6 vs 3.8.0 according to zookeeper-benchmark

Posted by Will Now <wn...@gmail.com>.

I've updated the results summary below to include 3.6.3 with and without
digest.enabled; they are essentially the same.

27,052: 3.4.6
15,993: 3.6.3, digest.enabled=true
16,159: 3.6.3, *digest.enabled=false*
15,943: 3.7.1
16,805: 3.8.0, digest.enabled=true:
16,682: 3.8.0: digest.enabled=false
16,370: 3.8.0 NullMetricsProvider, *digest.enabled=false*

I'm going to re-run my benchmarks in a 3-node ensemble instead of a local
singleton. I'll also run the test client on a separate node.  This will
match the environment I used years ago to measure 3.4.6 against 3.6.x, when
I found that digest.enabled was having a big impact (a result that I am not
reproducing at present)

The zookeeper benchmark I am reporting is the number of synchronous
sequential read operations on a single znode that can be completed in 30
seconds.  No other transactions take place during the benchmark (ie no
writes, etc)

I'm optimistic that the anomaly I am reporting is some issue on my end and
not in zookeeper. I'm pretty sure a big drop in performance like this would
not have gone unnoticed.  Thanks for the responses. I'll report back!

On Mon, Aug 29, 2022 at 12:37 AM Szalay-Bekő Máté <
szalay.beko.mate@gmail.com> wrote:

> Interesting, thanks for sharing the results!
>
> It will be hard to figure out what changed since the 3.4.6 release. Many
> new features added. Still, it would be good to find out which version /
> commit was responsible for the most performance degradation.
>
> You wrote before:
> > A while back I performed similar comparisons of 3.4.6 vs 3.6.x and I got
> > slow results in 3.6.x initially, but disabling digest.enabled fixed it
> and
> > the two versions were then comparable. In 3.8.0 I am seeing poor results
> > with or without digest enabled.
>
> Then later:
> > 27,052: 3.4.6
> > 15,993:3.6.3
> > 15,943:3.7.1
> > 16,805: 3.8.0, digest.enabled=true:
> > 16,682: 3.8.0: digest.enabled=false
> > *16,370: 3.8.0 NullMetricsProvider*
>
> Was the "15,993:3.6.3" measured with or without digest? It sounds like
> earlier you were able to get good results with 3.6.x
> (using digest.enabled=false). Is this still reproducible with 3.6.3? If
> yes, then still I would look around the digest feature for potential root
> cause.
>
> On the other hand, the digest feature should not really affect the read
> path, as far as I understood. But I also don't know how the benchmarking
> tool executes the operations (maybe there are writes running parallel with
> reads?).
>
> Máté
>
>
> On Mon, Aug 29, 2022 at 7:00 AM Will Now <wn...@gmail.com> wrote:
>
> > In case it is informative, here is the output from running zookeeper
> 3.8.0
> > in my latest test run with NullMetricsProvider.
> >
> > ~/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin$ ./zkServer.sh
> > start-foreground
> > /usr/bin/java
> > ZooKeeper JMX enabled by default
> > Using config:
> >
> /home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../conf/zoo.cfg
> > 2022-08-28 21:36:13,846 [myid:] - INFO
> > [main:o.a.z.s.q.QuorumPeerConfig@177]
> > - Reading configuration from:
> >
> /home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../conf/zoo.cfg
> > 2022-08-28 21:36:13,850 [myid:] - INFO
> > [main:o.a.z.s.q.QuorumPeerConfig@440]
> > - clientPortAddress is 0.0.0.0:2181
> > 2022-08-28 21:36:13,851 [myid:] - INFO
> > [main:o.a.z.s.q.QuorumPeerConfig@444]
> > - secureClientPort is not set
> > 2022-08-28 21:36:13,851 [myid:] - INFO
> > [main:o.a.z.s.q.QuorumPeerConfig@460]
> > - observerMasterPort is not set
> > 2022-08-28 21:36:13,851 [myid:] - INFO
> > [main:o.a.z.s.q.QuorumPeerConfig@477]
> > - metricsProvider.className is
> > org.apache.zookeeper.metrics.impl.NullMetricsProvider
> > 2022-08-28 21:36:13,852 [myid:] - INFO
> >  [main:o.a.z.s.DatadirCleanupManager@78] - autopurge.snapRetainCount set
> > to
> > 3
> > 2022-08-28 21:36:13,852 [myid:] - INFO
> >  [main:o.a.z.s.DatadirCleanupManager@79] - autopurge.purgeInterval set
> to
> > 0
> > 2022-08-28 21:36:13,852 [myid:] - INFO
> >  [main:o.a.z.s.DatadirCleanupManager@101] - Purge task is not scheduled.
> > 2022-08-28 21:36:13,852 [myid:] - WARN
> [main:o.a.z.s.q.QuorumPeerMain@139
> > ]
> > - Either no config or no quorum defined in config, running in standalone
> > mode
> > 2022-08-28 21:36:13,853 [myid:] - INFO  [main:o.a.z.j.ManagedUtil@46] -
> > Log4j 1.2 jmx support not found; jmx disabled.
> > 2022-08-28 21:36:13,853 [myid:] - INFO
> > [main:o.a.z.s.q.QuorumPeerConfig@177]
> > - Reading configuration from:
> >
> /home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../conf/zoo.cfg
> > 2022-08-28 21:36:13,854 [myid:] - INFO
> > [main:o.a.z.s.q.QuorumPeerConfig@440]
> > - clientPortAddress is 0.0.0.0:2181
> > 2022-08-28 21:36:13,854 [myid:] - INFO
> > [main:o.a.z.s.q.QuorumPeerConfig@444]
> > - secureClientPort is not set
> > 2022-08-28 21:36:13,854 [myid:] - INFO
> > [main:o.a.z.s.q.QuorumPeerConfig@460]
> > - observerMasterPort is not set
> > 2022-08-28 21:36:13,854 [myid:] - INFO
> > [main:o.a.z.s.q.QuorumPeerConfig@477]
> > - metricsProvider.className is
> > org.apache.zookeeper.metrics.impl.NullMetricsProvider
> > 2022-08-28 21:36:13,854 [myid:] - INFO
> >  [main:o.a.z.s.ZooKeeperServerMain@123] - Starting server
> > 2022-08-28 21:36:13,861 [myid:] - INFO  [main:o.a.z.s.ServerMetrics@64]
> -
> > ServerMetrics initialized with provider
> > org.apache.zookeeper.metrics.impl.NullMetricsProvider@4d5d943d
> > 2022-08-28 21:36:13,862 [myid:] - INFO
> >  [main:o.a.z.s.a.DigestAuthenticationProvider@47] - ACL digest algorithm
> > is: SHA1
> > 2022-08-28 21:36:13,862 [myid:] - INFO
> >  [main:o.a.z.s.a.DigestAuthenticationProvider@61] -
> > zookeeper.DigestAuthenticationProvider.enabled = true
> > 2022-08-28 21:36:13,863 [myid:] - INFO
> [main:o.a.z.s.p.FileTxnSnapLog@124
> > ]
> > - zookeeper.snapshot.trust.empty : false
> > 2022-08-28 21:36:13,869 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42]
> -
> > 2022-08-28 21:36:13,869 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42]
> -
> > ______                  _
> > 2022-08-28 21:36:13,869 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42]
> -
> >  |___  /                 | |
> > 2022-08-28 21:36:13,869 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42]
> -
> >   / /    ___     ___   | | __   ___    ___   _ __     ___   _ __
> > 2022-08-28 21:36:13,869 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42]
> -
> >  / /    / _ \   / _ \  | |/ /  / _ \  / _ \ | '_ \   / _ \ | '__|
> > 2022-08-28 21:36:13,869 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42]
> -
> > / /__  | (_) | | (_) | |   <  |  __/ |  __/ | |_) | |  __/ | |
> > 2022-08-28 21:36:13,870 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42]
> -
> >  /_____|  \___/   \___/  |_|\_\  \___|  \___| | .__/   \___| |_|
> > 2022-08-28 21:36:13,870 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42]
> -
> >                                             | |
> > 2022-08-28 21:36:13,870 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42]
> -
> >                                             |_|
> > 2022-08-28 21:36:13,870 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42]
> -
> > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > Server
> >
> >
> environment:zookeeper.version=3.8.0-5a02a05eddb59aee6ac762f7ea82e92a68eb9c0f,
> > built on 2022-02-25 08:49 UTC
> > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > Server environment:host.name=host
> > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > Server environment:java.version=11.0.16
> > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > Server environment:java.vendor=Ubuntu
> > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > Server environment:java.home=/usr/lib/jvm/java-11-openjdk-amd64
> > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > Server
> >
> >
> environment:java.class.path=/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../zookeeper-server/target/classes:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../build/classes:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../zookeeper-server/target/lib/*.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../build/lib/*.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/zookeeper-prometheus-metrics-3.8.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/zookeeper-jute-3.8.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/zookeeper-3.8.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/snappy-java-1.1.7.7.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/slf4j-api-1.7.30.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/simpleclient_servlet-0.9.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/simpleclient_hotspot-0.9.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/simpleclient_common-0.9.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/simpleclient-0.9.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-transport-native-unix-common-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-transport-native-epoll-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-transport-classes-epoll-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-transport-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-tcnative-classes-2.0.48.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-tcnative-2.0.48.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-resolver-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-handler-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-common-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-codec-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-buffer-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/metrics-core-4.1.12.1.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/logback-core-1.2.10.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/logback-classic-1.2.10.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jline-2.14.6.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-util-ajax-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-util-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-servlet-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-server-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-security-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-io-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-http-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/javax.servlet-api-3.1.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jackson-databind-2.13.1.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jackson-core-2.13.1.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jackson-annotations-2.13.1.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/commons-io-2.11.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/commons-cli-1.4.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/audience-annotations-0.12.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../zookeeper-*.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../zookeeper-server/src/main/resources/lib/*.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../conf:
> > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > Server
> >
> >
> environment:java.library.path=/usr/java/packages/lib:/usr/lib/x86_64-linux-gnu/jni:/lib/x86_64-linux-gnu:/usr/lib/x86_64-linux-gnu:/usr/lib/jni:/lib:/usr/lib
> > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > Server environment:java.io.tmpdir=/tmp
> > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > Server environment:java.compiler=<NA>
> > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > Server environment:os.name=Linux
> > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > Server environment:os.arch=amd64
> > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > Server environment:os.version=5.15.0-46-generic
> > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > Server
> >
> >
> environment:user.dir=/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin
> > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > Server environment:os.memory.free=231MB
> > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > Server environment:os.memory.max=1000MB
> > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> > Server environment:os.memory.total=250MB
> > 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.s.ZooKeeperServer@140
> ]
> > - zookeeper.enableEagerACLCheck = false
> > 2022-08-28 21:36:13,872 [myid:] - INFO  [main:o.a.z.s.ZooKeeperServer@153
> ]
> > - zookeeper.digest.enabled = true
> > 2022-08-28 21:36:13,872 [myid:] - INFO  [main:o.a.z.s.ZooKeeperServer@157
> ]
> > - zookeeper.closeSessionTxn.enabled = true
> > 2022-08-28 21:36:13,872 [myid:] - INFO
> [main:o.a.z.s.ZooKeeperServer@1496
> > ]
> > - zookeeper.flushDelay = 0 ms
> > 2022-08-28 21:36:13,872 [myid:] - INFO
> [main:o.a.z.s.ZooKeeperServer@1505
> > ]
> > - zookeeper.maxWriteQueuePollTime = 0 ms
> > 2022-08-28 21:36:13,872 [myid:] - INFO
> [main:o.a.z.s.ZooKeeperServer@1514
> > ]
> > - zookeeper.maxBatchSize=1000
> > 2022-08-28 21:36:13,872 [myid:] - INFO  [main:o.a.z.s.ZooKeeperServer@264
> ]
> > - zookeeper.intBufferStartingSizeBytes = 1024
> > 2022-08-28 21:36:13,872 [myid:] - INFO  [main:o.a.z.s.BlueThrottle@141]
> -
> > Weighed connection throttling is disabled
> > 2022-08-28 21:36:13,873 [myid:] - INFO
> [main:o.a.z.s.ZooKeeperServer@1297
> > ]
> > - minSessionTimeout set to 4000 ms
> > 2022-08-28 21:36:13,873 [myid:] - INFO
> [main:o.a.z.s.ZooKeeperServer@1306
> > ]
> > - maxSessionTimeout set to 40000 ms
> > 2022-08-28 21:36:13,874 [myid:] - INFO  [main:o.a.z.s.ResponseCache@45]
> -
> > getData response cache size is initialized with value 400.
> > 2022-08-28 21:36:13,874 [myid:] - INFO  [main:o.a.z.s.ResponseCache@45]
> -
> > getChildren response cache size is initialized with value 400.
> > 2022-08-28 21:36:13,874 [myid:] - INFO
> >  [main:o.a.z.s.u.RequestPathMetricsCollector@109] -
> > zookeeper.pathStats.slotCapacity = 60
> > 2022-08-28 21:36:13,874 [myid:] - INFO
> >  [main:o.a.z.s.u.RequestPathMetricsCollector@110] -
> > zookeeper.pathStats.slotDuration = 15
> > 2022-08-28 21:36:13,875 [myid:] - INFO
> >  [main:o.a.z.s.u.RequestPathMetricsCollector@111] -
> > zookeeper.pathStats.maxDepth = 6
> > 2022-08-28 21:36:13,875 [myid:] - INFO
> >  [main:o.a.z.s.u.RequestPathMetricsCollector@112] -
> > zookeeper.pathStats.initialDelay = 5
> > 2022-08-28 21:36:13,875 [myid:] - INFO
> >  [main:o.a.z.s.u.RequestPathMetricsCollector@113] -
> > zookeeper.pathStats.delay = 5
> > 2022-08-28 21:36:13,875 [myid:] - INFO
> >  [main:o.a.z.s.u.RequestPathMetricsCollector@114] -
> > zookeeper.pathStats.enabled = false
> > 2022-08-28 21:36:13,876 [myid:] - INFO
> [main:o.a.z.s.ZooKeeperServer@1533
> > ]
> > - The max bytes for all large requests are set to 104857600
> > 2022-08-28 21:36:13,876 [myid:] - INFO
> [main:o.a.z.s.ZooKeeperServer@1547
> > ]
> > - The large request threshold is set to -1
> > 2022-08-28 21:36:13,877 [myid:] - INFO
> >  [main:o.a.z.s.AuthenticationHelper@66] -
> zookeeper.enforce.auth.enabled =
> > false
> > 2022-08-28 21:36:13,877 [myid:] - INFO
> >  [main:o.a.z.s.AuthenticationHelper@67] -
> zookeeper.enforce.auth.schemes =
> > []
> > 2022-08-28 21:36:13,877 [myid:] - INFO  [main:o.a.z.s.ZooKeeperServer@365
> ]
> > - Created server with tickTime 2000 ms minSessionTimeout 4000 ms
> > maxSessionTimeout 40000 ms clientPortListenBacklog -1 datadir
> > /tmp/zookeeper/3.8.0/version-2 snapdir /tmp/zookeeper/3.8.0/version-2
> > 2022-08-28 21:36:13,890 [myid:] - INFO  [main:o.e.j.u.l.Log@170] -
> Logging
> > initialized @348ms to org.eclipse.jetty.util.log.Slf4jLog
> > 2022-08-28 21:36:13,929 [myid:] - WARN
> [main:o.e.j.s.h.ContextHandler@1656
> > ]
> > - o.e.j.s.ServletContextHandler@3cebbb30{/,null,STOPPED} contextPath
> ends
> > with /*
> > 2022-08-28 21:36:13,930 [myid:] - WARN
> [main:o.e.j.s.h.ContextHandler@1667
> > ]
> > - Empty contextPath
> > 2022-08-28 21:36:13,951 [myid:] - INFO  [main:o.e.j.s.Server@375] -
> > jetty-9.4.43.v20210629; built: 2021-06-30T11:07:22.254Z; git:
> > 526006ecfa3af7f1a27ef3a288e2bef7ea9dd7e8; jvm
> > 11.0.16+8-post-Ubuntu-0ubuntu120.04
> > 2022-08-28 21:36:13,967 [myid:] - INFO
> >  [main:o.e.j.s.s.DefaultSessionIdManager@334] - DefaultSessionIdManager
> > workerName=node0
> > 2022-08-28 21:36:13,967 [myid:] - INFO
> >  [main:o.e.j.s.s.DefaultSessionIdManager@339] - No SessionScavenger set,
> > using defaults
> > 2022-08-28 21:36:13,968 [myid:] - INFO  [main:o.e.j.s.s.HouseKeeper@132]
> -
> > node0 Scavenging every 600000ms
> > 2022-08-28 21:36:13,970 [myid:] - WARN
> >  [main:o.e.j.s.ConstraintSecurityHandler@759] -
> > ServletContext@o.e.j.s.ServletContextHandler@3cebbb30{/,null,STARTING}
> has
> > uncovered http methods for path: /*
> > 2022-08-28 21:36:13,975 [myid:] - INFO
> [main:o.e.j.s.h.ContextHandler@915
> > ]
> > - Started o.e.j.s.ServletContextHandler@3cebbb30{/,null,AVAILABLE}
> > 2022-08-28 21:36:13,983 [myid:] - INFO
> [main:o.e.j.s.AbstractConnector@331
> > ]
> > - Started ServerConnector@29d89d5d{HTTP/1.1, (http/1.1)}{0.0.0.0:8080}
> > 2022-08-28 21:36:13,983 [myid:] - INFO  [main:o.e.j.s.Server@415] -
> > Started
> > @441ms
> > 2022-08-28 21:36:13,983 [myid:] - INFO
> > [main:o.a.z.s.a.JettyAdminServer@196]
> > - Started AdminServer on address 0.0.0.0, port 8080 and command URL
> > /commands
> > 2022-08-28 21:36:13,986 [myid:] - INFO
> [main:o.a.z.s.ServerCnxnFactory@169
> > ]
> > - Using org.apache.zookeeper.server.NIOServerCnxnFactory as server
> > connection factory
> > 2022-08-28 21:36:13,987 [myid:] - WARN
> [main:o.a.z.s.ServerCnxnFactory@309
> > ]
> > - maxCnxns is not configured, using default value 0.
> > 2022-08-28 21:36:13,988 [myid:] - INFO
> >  [main:o.a.z.s.NIOServerCnxnFactory@652] - Configuring NIO connection
> > handler with 10s sessionless connection timeout, 2 selector thread(s), 24
> > worker threads, and 64 kB direct buffers.
> > 2022-08-28 21:36:13,988 [myid:] - INFO
> >  [main:o.a.z.s.NIOServerCnxnFactory@660] - binding to port
> > 0.0.0.0/0.0.0.0:2181
> > 2022-08-28 21:36:13,997 [myid:] - INFO
> >  [main:o.a.z.s.w.WatchManagerFactory@42] - Using
> > org.apache.zookeeper.server.watch.WatchManager as watch manager
> > 2022-08-28 21:36:13,997 [myid:] - INFO
> >  [main:o.a.z.s.w.WatchManagerFactory@42] - Using
> > org.apache.zookeeper.server.watch.WatchManager as watch manager
> > 2022-08-28 21:36:13,998 [myid:] - INFO  [main:o.a.z.s.ZKDatabase@132] -
> > zookeeper.snapshotSizeFactor = 0.33
> > 2022-08-28 21:36:13,998 [myid:] - INFO  [main:o.a.z.s.ZKDatabase@152] -
> > zookeeper.commitLogCount=500
> > 2022-08-28 21:36:14,002 [myid:] - INFO  [main:o.a.z.s.p.SnapStream@61] -
> > zookeeper.snapshot.compression.method = CHECKED
> >
> > Also here is my 3.8.0 zoo.cfg file:
> >
> > # The number of milliseconds of each tick
> > tickTime=2000
> > # The number of ticks that the initial
> > # synchronization phase can take
> > initLimit=10
> > # The number of ticks that can pass between
> > # sending a request and getting an acknowledgement
> > syncLimit=5
> > # the directory where the snapshot is stored.
> > # do not use /tmp for storage, /tmp here is just
> > # example sakes.
> > dataDir=/tmp/zookeeper/3.8.0
> > # the port at which the clients will connect
> > clientPort=2181
> > # the maximum number of client connections.
> > # increase this if you need to handle more clients
> > #maxClientCnxns=60
> > #
> > # Be sure to read the maintenance section of the
> > # administrator guide before turning on autopurge.
> > #
> > #
> >
> https://zookeeper.apache.org/doc/current/zookeeperAdmin.html#sc_maintenance
> > #
> > # The number of snapshots to retain in dataDir
> > #autopurge.snapRetainCount=3
> > # Purge task interval in hours
> > # Set to "0" to disable auto purge feature
> > #autopurge.purgeInterval=1
> >
> > ## Metrics Providers
> > #
> > # https://prometheus.io Metrics Exporter
> >
> >
> #metricsProvider.className=org.apache.zookeeper.metrics.prometheus.PrometheusMetricsProvider
> > #metricsProvider.httpHost=0.0.0.0
> > #metricsProvider.httpPort=7000
> > #metricsProvider.exportJvmInfo=true
> >
> > 4lw.commands.whitelist=*
> > digest.enabled=true
> >
> >
> >
> metricsProvider.className=org.apache.zookeeper.metrics.impl.NullMetricsProvider
> >
>

Re: Read performance of 3.4.6 vs 3.8.0 according to zookeeper-benchmark

Posted by Szalay-Bekő Máté <sz...@gmail.com>.

Interesting, thanks for sharing the results!

It will be hard to figure out what changed since the 3.4.6 release. Many
new features added. Still, it would be good to find out which version /
commit was responsible for the most performance degradation.

You wrote before:
> A while back I performed similar comparisons of 3.4.6 vs 3.6.x and I got
> slow results in 3.6.x initially, but disabling digest.enabled fixed it and
> the two versions were then comparable. In 3.8.0 I am seeing poor results
> with or without digest enabled.

Then later:
> 27,052: 3.4.6
> 15,993:3.6.3
> 15,943:3.7.1
> 16,805: 3.8.0, digest.enabled=true:
> 16,682: 3.8.0: digest.enabled=false
> *16,370: 3.8.0 NullMetricsProvider*

Was the "15,993:3.6.3" measured with or without digest? It sounds like
earlier you were able to get good results with 3.6.x
(using digest.enabled=false). Is this still reproducible with 3.6.3? If
yes, then still I would look around the digest feature for potential root
cause.

On the other hand, the digest feature should not really affect the read
path, as far as I understood. But I also don't know how the benchmarking
tool executes the operations (maybe there are writes running parallel with
reads?).

Máté


On Mon, Aug 29, 2022 at 7:00 AM Will Now <wn...@gmail.com> wrote:

> In case it is informative, here is the output from running zookeeper 3.8.0
> in my latest test run with NullMetricsProvider.
>
> ~/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin$ ./zkServer.sh
> start-foreground
> /usr/bin/java
> ZooKeeper JMX enabled by default
> Using config:
> /home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../conf/zoo.cfg
> 2022-08-28 21:36:13,846 [myid:] - INFO
> [main:o.a.z.s.q.QuorumPeerConfig@177]
> - Reading configuration from:
> /home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../conf/zoo.cfg
> 2022-08-28 21:36:13,850 [myid:] - INFO
> [main:o.a.z.s.q.QuorumPeerConfig@440]
> - clientPortAddress is 0.0.0.0:2181
> 2022-08-28 21:36:13,851 [myid:] - INFO
> [main:o.a.z.s.q.QuorumPeerConfig@444]
> - secureClientPort is not set
> 2022-08-28 21:36:13,851 [myid:] - INFO
> [main:o.a.z.s.q.QuorumPeerConfig@460]
> - observerMasterPort is not set
> 2022-08-28 21:36:13,851 [myid:] - INFO
> [main:o.a.z.s.q.QuorumPeerConfig@477]
> - metricsProvider.className is
> org.apache.zookeeper.metrics.impl.NullMetricsProvider
> 2022-08-28 21:36:13,852 [myid:] - INFO
>  [main:o.a.z.s.DatadirCleanupManager@78] - autopurge.snapRetainCount set
> to
> 3
> 2022-08-28 21:36:13,852 [myid:] - INFO
>  [main:o.a.z.s.DatadirCleanupManager@79] - autopurge.purgeInterval set to
> 0
> 2022-08-28 21:36:13,852 [myid:] - INFO
>  [main:o.a.z.s.DatadirCleanupManager@101] - Purge task is not scheduled.
> 2022-08-28 21:36:13,852 [myid:] - WARN  [main:o.a.z.s.q.QuorumPeerMain@139
> ]
> - Either no config or no quorum defined in config, running in standalone
> mode
> 2022-08-28 21:36:13,853 [myid:] - INFO  [main:o.a.z.j.ManagedUtil@46] -
> Log4j 1.2 jmx support not found; jmx disabled.
> 2022-08-28 21:36:13,853 [myid:] - INFO
> [main:o.a.z.s.q.QuorumPeerConfig@177]
> - Reading configuration from:
> /home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../conf/zoo.cfg
> 2022-08-28 21:36:13,854 [myid:] - INFO
> [main:o.a.z.s.q.QuorumPeerConfig@440]
> - clientPortAddress is 0.0.0.0:2181
> 2022-08-28 21:36:13,854 [myid:] - INFO
> [main:o.a.z.s.q.QuorumPeerConfig@444]
> - secureClientPort is not set
> 2022-08-28 21:36:13,854 [myid:] - INFO
> [main:o.a.z.s.q.QuorumPeerConfig@460]
> - observerMasterPort is not set
> 2022-08-28 21:36:13,854 [myid:] - INFO
> [main:o.a.z.s.q.QuorumPeerConfig@477]
> - metricsProvider.className is
> org.apache.zookeeper.metrics.impl.NullMetricsProvider
> 2022-08-28 21:36:13,854 [myid:] - INFO
>  [main:o.a.z.s.ZooKeeperServerMain@123] - Starting server
> 2022-08-28 21:36:13,861 [myid:] - INFO  [main:o.a.z.s.ServerMetrics@64] -
> ServerMetrics initialized with provider
> org.apache.zookeeper.metrics.impl.NullMetricsProvider@4d5d943d
> 2022-08-28 21:36:13,862 [myid:] - INFO
>  [main:o.a.z.s.a.DigestAuthenticationProvider@47] - ACL digest algorithm
> is: SHA1
> 2022-08-28 21:36:13,862 [myid:] - INFO
>  [main:o.a.z.s.a.DigestAuthenticationProvider@61] -
> zookeeper.DigestAuthenticationProvider.enabled = true
> 2022-08-28 21:36:13,863 [myid:] - INFO  [main:o.a.z.s.p.FileTxnSnapLog@124
> ]
> - zookeeper.snapshot.trust.empty : false
> 2022-08-28 21:36:13,869 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42] -
> 2022-08-28 21:36:13,869 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42] -
> ______                  _
> 2022-08-28 21:36:13,869 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42] -
>  |___  /                 | |
> 2022-08-28 21:36:13,869 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42] -
>   / /    ___     ___   | | __   ___    ___   _ __     ___   _ __
> 2022-08-28 21:36:13,869 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42] -
>  / /    / _ \   / _ \  | |/ /  / _ \  / _ \ | '_ \   / _ \ | '__|
> 2022-08-28 21:36:13,869 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42] -
> / /__  | (_) | | (_) | |   <  |  __/ |  __/ | |_) | |  __/ | |
> 2022-08-28 21:36:13,870 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42] -
>  /_____|  \___/   \___/  |_|\_\  \___|  \___| | .__/   \___| |_|
> 2022-08-28 21:36:13,870 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42] -
>                                             | |
> 2022-08-28 21:36:13,870 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42] -
>                                             |_|
> 2022-08-28 21:36:13,870 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42] -
> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> Server
>
> environment:zookeeper.version=3.8.0-5a02a05eddb59aee6ac762f7ea82e92a68eb9c0f,
> built on 2022-02-25 08:49 UTC
> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> Server environment:host.name=host
> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> Server environment:java.version=11.0.16
> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> Server environment:java.vendor=Ubuntu
> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> Server environment:java.home=/usr/lib/jvm/java-11-openjdk-amd64
> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> Server
>
> environment:java.class.path=/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../zookeeper-server/target/classes:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../build/classes:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../zookeeper-server/target/lib/*.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../build/lib/*.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/zookeeper-prometheus-metrics-3.8.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/zookeeper-jute-3.8.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/zookeeper-3.8.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/snappy-java-1.1.7.7.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/slf4j-api-1.7.30.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/simpleclient_servlet-0.9.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/simpleclient_hotspot-0.9.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/simpleclient_common-0.9.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/simpleclient-0.9.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-transport-native-unix-common-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-transport-native-epoll-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-transport-classes-epoll-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-transport-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-tcnative-classes-2.0.48.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-tcnative-2.0.48.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-resolver-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-handler-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-common-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-codec-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-buffer-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/metrics-core-4.1.12.1.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/logback-core-1.2.10.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/logback-classic-1.2.10.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jline-2.14.6.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-util-ajax-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-util-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-servlet-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-server-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-security-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-io-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-http-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/javax.servlet-api-3.1.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jackson-databind-2.13.1.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jackson-core-2.13.1.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jackson-annotations-2.13.1.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/commons-io-2.11.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/commons-cli-1.4.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/audience-annotations-0.12.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../zookeeper-*.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../zookeeper-server/src/main/resources/lib/*.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../conf:
> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> Server
>
> environment:java.library.path=/usr/java/packages/lib:/usr/lib/x86_64-linux-gnu/jni:/lib/x86_64-linux-gnu:/usr/lib/x86_64-linux-gnu:/usr/lib/jni:/lib:/usr/lib
> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> Server environment:java.io.tmpdir=/tmp
> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> Server environment:java.compiler=<NA>
> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> Server environment:os.name=Linux
> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> Server environment:os.arch=amd64
> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> Server environment:os.version=5.15.0-46-generic
> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> Server
>
> environment:user.dir=/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin
> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> Server environment:os.memory.free=231MB
> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> Server environment:os.memory.max=1000MB
> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
> Server environment:os.memory.total=250MB
> 2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.s.ZooKeeperServer@140]
> - zookeeper.enableEagerACLCheck = false
> 2022-08-28 21:36:13,872 [myid:] - INFO  [main:o.a.z.s.ZooKeeperServer@153]
> - zookeeper.digest.enabled = true
> 2022-08-28 21:36:13,872 [myid:] - INFO  [main:o.a.z.s.ZooKeeperServer@157]
> - zookeeper.closeSessionTxn.enabled = true
> 2022-08-28 21:36:13,872 [myid:] - INFO  [main:o.a.z.s.ZooKeeperServer@1496
> ]
> - zookeeper.flushDelay = 0 ms
> 2022-08-28 21:36:13,872 [myid:] - INFO  [main:o.a.z.s.ZooKeeperServer@1505
> ]
> - zookeeper.maxWriteQueuePollTime = 0 ms
> 2022-08-28 21:36:13,872 [myid:] - INFO  [main:o.a.z.s.ZooKeeperServer@1514
> ]
> - zookeeper.maxBatchSize=1000
> 2022-08-28 21:36:13,872 [myid:] - INFO  [main:o.a.z.s.ZooKeeperServer@264]
> - zookeeper.intBufferStartingSizeBytes = 1024
> 2022-08-28 21:36:13,872 [myid:] - INFO  [main:o.a.z.s.BlueThrottle@141] -
> Weighed connection throttling is disabled
> 2022-08-28 21:36:13,873 [myid:] - INFO  [main:o.a.z.s.ZooKeeperServer@1297
> ]
> - minSessionTimeout set to 4000 ms
> 2022-08-28 21:36:13,873 [myid:] - INFO  [main:o.a.z.s.ZooKeeperServer@1306
> ]
> - maxSessionTimeout set to 40000 ms
> 2022-08-28 21:36:13,874 [myid:] - INFO  [main:o.a.z.s.ResponseCache@45] -
> getData response cache size is initialized with value 400.
> 2022-08-28 21:36:13,874 [myid:] - INFO  [main:o.a.z.s.ResponseCache@45] -
> getChildren response cache size is initialized with value 400.
> 2022-08-28 21:36:13,874 [myid:] - INFO
>  [main:o.a.z.s.u.RequestPathMetricsCollector@109] -
> zookeeper.pathStats.slotCapacity = 60
> 2022-08-28 21:36:13,874 [myid:] - INFO
>  [main:o.a.z.s.u.RequestPathMetricsCollector@110] -
> zookeeper.pathStats.slotDuration = 15
> 2022-08-28 21:36:13,875 [myid:] - INFO
>  [main:o.a.z.s.u.RequestPathMetricsCollector@111] -
> zookeeper.pathStats.maxDepth = 6
> 2022-08-28 21:36:13,875 [myid:] - INFO
>  [main:o.a.z.s.u.RequestPathMetricsCollector@112] -
> zookeeper.pathStats.initialDelay = 5
> 2022-08-28 21:36:13,875 [myid:] - INFO
>  [main:o.a.z.s.u.RequestPathMetricsCollector@113] -
> zookeeper.pathStats.delay = 5
> 2022-08-28 21:36:13,875 [myid:] - INFO
>  [main:o.a.z.s.u.RequestPathMetricsCollector@114] -
> zookeeper.pathStats.enabled = false
> 2022-08-28 21:36:13,876 [myid:] - INFO  [main:o.a.z.s.ZooKeeperServer@1533
> ]
> - The max bytes for all large requests are set to 104857600
> 2022-08-28 21:36:13,876 [myid:] - INFO  [main:o.a.z.s.ZooKeeperServer@1547
> ]
> - The large request threshold is set to -1
> 2022-08-28 21:36:13,877 [myid:] - INFO
>  [main:o.a.z.s.AuthenticationHelper@66] - zookeeper.enforce.auth.enabled =
> false
> 2022-08-28 21:36:13,877 [myid:] - INFO
>  [main:o.a.z.s.AuthenticationHelper@67] - zookeeper.enforce.auth.schemes =
> []
> 2022-08-28 21:36:13,877 [myid:] - INFO  [main:o.a.z.s.ZooKeeperServer@365]
> - Created server with tickTime 2000 ms minSessionTimeout 4000 ms
> maxSessionTimeout 40000 ms clientPortListenBacklog -1 datadir
> /tmp/zookeeper/3.8.0/version-2 snapdir /tmp/zookeeper/3.8.0/version-2
> 2022-08-28 21:36:13,890 [myid:] - INFO  [main:o.e.j.u.l.Log@170] - Logging
> initialized @348ms to org.eclipse.jetty.util.log.Slf4jLog
> 2022-08-28 21:36:13,929 [myid:] - WARN  [main:o.e.j.s.h.ContextHandler@1656
> ]
> - o.e.j.s.ServletContextHandler@3cebbb30{/,null,STOPPED} contextPath ends
> with /*
> 2022-08-28 21:36:13,930 [myid:] - WARN  [main:o.e.j.s.h.ContextHandler@1667
> ]
> - Empty contextPath
> 2022-08-28 21:36:13,951 [myid:] - INFO  [main:o.e.j.s.Server@375] -
> jetty-9.4.43.v20210629; built: 2021-06-30T11:07:22.254Z; git:
> 526006ecfa3af7f1a27ef3a288e2bef7ea9dd7e8; jvm
> 11.0.16+8-post-Ubuntu-0ubuntu120.04
> 2022-08-28 21:36:13,967 [myid:] - INFO
>  [main:o.e.j.s.s.DefaultSessionIdManager@334] - DefaultSessionIdManager
> workerName=node0
> 2022-08-28 21:36:13,967 [myid:] - INFO
>  [main:o.e.j.s.s.DefaultSessionIdManager@339] - No SessionScavenger set,
> using defaults
> 2022-08-28 21:36:13,968 [myid:] - INFO  [main:o.e.j.s.s.HouseKeeper@132] -
> node0 Scavenging every 600000ms
> 2022-08-28 21:36:13,970 [myid:] - WARN
>  [main:o.e.j.s.ConstraintSecurityHandler@759] -
> ServletContext@o.e.j.s.ServletContextHandler@3cebbb30{/,null,STARTING} has
> uncovered http methods for path: /*
> 2022-08-28 21:36:13,975 [myid:] - INFO  [main:o.e.j.s.h.ContextHandler@915
> ]
> - Started o.e.j.s.ServletContextHandler@3cebbb30{/,null,AVAILABLE}
> 2022-08-28 21:36:13,983 [myid:] - INFO  [main:o.e.j.s.AbstractConnector@331
> ]
> - Started ServerConnector@29d89d5d{HTTP/1.1, (http/1.1)}{0.0.0.0:8080}
> 2022-08-28 21:36:13,983 [myid:] - INFO  [main:o.e.j.s.Server@415] -
> Started
> @441ms
> 2022-08-28 21:36:13,983 [myid:] - INFO
> [main:o.a.z.s.a.JettyAdminServer@196]
> - Started AdminServer on address 0.0.0.0, port 8080 and command URL
> /commands
> 2022-08-28 21:36:13,986 [myid:] - INFO  [main:o.a.z.s.ServerCnxnFactory@169
> ]
> - Using org.apache.zookeeper.server.NIOServerCnxnFactory as server
> connection factory
> 2022-08-28 21:36:13,987 [myid:] - WARN  [main:o.a.z.s.ServerCnxnFactory@309
> ]
> - maxCnxns is not configured, using default value 0.
> 2022-08-28 21:36:13,988 [myid:] - INFO
>  [main:o.a.z.s.NIOServerCnxnFactory@652] - Configuring NIO connection
> handler with 10s sessionless connection timeout, 2 selector thread(s), 24
> worker threads, and 64 kB direct buffers.
> 2022-08-28 21:36:13,988 [myid:] - INFO
>  [main:o.a.z.s.NIOServerCnxnFactory@660] - binding to port
> 0.0.0.0/0.0.0.0:2181
> 2022-08-28 21:36:13,997 [myid:] - INFO
>  [main:o.a.z.s.w.WatchManagerFactory@42] - Using
> org.apache.zookeeper.server.watch.WatchManager as watch manager
> 2022-08-28 21:36:13,997 [myid:] - INFO
>  [main:o.a.z.s.w.WatchManagerFactory@42] - Using
> org.apache.zookeeper.server.watch.WatchManager as watch manager
> 2022-08-28 21:36:13,998 [myid:] - INFO  [main:o.a.z.s.ZKDatabase@132] -
> zookeeper.snapshotSizeFactor = 0.33
> 2022-08-28 21:36:13,998 [myid:] - INFO  [main:o.a.z.s.ZKDatabase@152] -
> zookeeper.commitLogCount=500
> 2022-08-28 21:36:14,002 [myid:] - INFO  [main:o.a.z.s.p.SnapStream@61] -
> zookeeper.snapshot.compression.method = CHECKED
>
> Also here is my 3.8.0 zoo.cfg file:
>
> # The number of milliseconds of each tick
> tickTime=2000
> # The number of ticks that the initial
> # synchronization phase can take
> initLimit=10
> # The number of ticks that can pass between
> # sending a request and getting an acknowledgement
> syncLimit=5
> # the directory where the snapshot is stored.
> # do not use /tmp for storage, /tmp here is just
> # example sakes.
> dataDir=/tmp/zookeeper/3.8.0
> # the port at which the clients will connect
> clientPort=2181
> # the maximum number of client connections.
> # increase this if you need to handle more clients
> #maxClientCnxns=60
> #
> # Be sure to read the maintenance section of the
> # administrator guide before turning on autopurge.
> #
> #
> https://zookeeper.apache.org/doc/current/zookeeperAdmin.html#sc_maintenance
> #
> # The number of snapshots to retain in dataDir
> #autopurge.snapRetainCount=3
> # Purge task interval in hours
> # Set to "0" to disable auto purge feature
> #autopurge.purgeInterval=1
>
> ## Metrics Providers
> #
> # https://prometheus.io Metrics Exporter
>
> #metricsProvider.className=org.apache.zookeeper.metrics.prometheus.PrometheusMetricsProvider
> #metricsProvider.httpHost=0.0.0.0
> #metricsProvider.httpPort=7000
> #metricsProvider.exportJvmInfo=true
>
> 4lw.commands.whitelist=*
> digest.enabled=true
>
>
> metricsProvider.className=org.apache.zookeeper.metrics.impl.NullMetricsProvider
>

Re: Read performance of 3.4.6 vs 3.8.0 according to zookeeper-benchmark

Posted by Will Now <wn...@gmail.com>.

In case it is informative, here is the output from running zookeeper 3.8.0
in my latest test run with NullMetricsProvider.

~/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin$ ./zkServer.sh
start-foreground
/usr/bin/java
ZooKeeper JMX enabled by default
Using config:
/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../conf/zoo.cfg
2022-08-28 21:36:13,846 [myid:] - INFO  [main:o.a.z.s.q.QuorumPeerConfig@177]
- Reading configuration from:
/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../conf/zoo.cfg
2022-08-28 21:36:13,850 [myid:] - INFO  [main:o.a.z.s.q.QuorumPeerConfig@440]
- clientPortAddress is 0.0.0.0:2181
2022-08-28 21:36:13,851 [myid:] - INFO  [main:o.a.z.s.q.QuorumPeerConfig@444]
- secureClientPort is not set
2022-08-28 21:36:13,851 [myid:] - INFO  [main:o.a.z.s.q.QuorumPeerConfig@460]
- observerMasterPort is not set
2022-08-28 21:36:13,851 [myid:] - INFO  [main:o.a.z.s.q.QuorumPeerConfig@477]
- metricsProvider.className is
org.apache.zookeeper.metrics.impl.NullMetricsProvider
2022-08-28 21:36:13,852 [myid:] - INFO
 [main:o.a.z.s.DatadirCleanupManager@78] - autopurge.snapRetainCount set to
3
2022-08-28 21:36:13,852 [myid:] - INFO
 [main:o.a.z.s.DatadirCleanupManager@79] - autopurge.purgeInterval set to 0
2022-08-28 21:36:13,852 [myid:] - INFO
 [main:o.a.z.s.DatadirCleanupManager@101] - Purge task is not scheduled.
2022-08-28 21:36:13,852 [myid:] - WARN  [main:o.a.z.s.q.QuorumPeerMain@139]
- Either no config or no quorum defined in config, running in standalone
mode
2022-08-28 21:36:13,853 [myid:] - INFO  [main:o.a.z.j.ManagedUtil@46] -
Log4j 1.2 jmx support not found; jmx disabled.
2022-08-28 21:36:13,853 [myid:] - INFO  [main:o.a.z.s.q.QuorumPeerConfig@177]
- Reading configuration from:
/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../conf/zoo.cfg
2022-08-28 21:36:13,854 [myid:] - INFO  [main:o.a.z.s.q.QuorumPeerConfig@440]
- clientPortAddress is 0.0.0.0:2181
2022-08-28 21:36:13,854 [myid:] - INFO  [main:o.a.z.s.q.QuorumPeerConfig@444]
- secureClientPort is not set
2022-08-28 21:36:13,854 [myid:] - INFO  [main:o.a.z.s.q.QuorumPeerConfig@460]
- observerMasterPort is not set
2022-08-28 21:36:13,854 [myid:] - INFO  [main:o.a.z.s.q.QuorumPeerConfig@477]
- metricsProvider.className is
org.apache.zookeeper.metrics.impl.NullMetricsProvider
2022-08-28 21:36:13,854 [myid:] - INFO
 [main:o.a.z.s.ZooKeeperServerMain@123] - Starting server
2022-08-28 21:36:13,861 [myid:] - INFO  [main:o.a.z.s.ServerMetrics@64] -
ServerMetrics initialized with provider
org.apache.zookeeper.metrics.impl.NullMetricsProvider@4d5d943d
2022-08-28 21:36:13,862 [myid:] - INFO
 [main:o.a.z.s.a.DigestAuthenticationProvider@47] - ACL digest algorithm
is: SHA1
2022-08-28 21:36:13,862 [myid:] - INFO
 [main:o.a.z.s.a.DigestAuthenticationProvider@61] -
zookeeper.DigestAuthenticationProvider.enabled = true
2022-08-28 21:36:13,863 [myid:] - INFO  [main:o.a.z.s.p.FileTxnSnapLog@124]
- zookeeper.snapshot.trust.empty : false
2022-08-28 21:36:13,869 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42] -
2022-08-28 21:36:13,869 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42] -
______                  _
2022-08-28 21:36:13,869 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42] -
 |___  /                 | |
2022-08-28 21:36:13,869 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42] -
  / /    ___     ___   | | __   ___    ___   _ __     ___   _ __
2022-08-28 21:36:13,869 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42] -
 / /    / _ \   / _ \  | |/ /  / _ \  / _ \ | '_ \   / _ \ | '__|
2022-08-28 21:36:13,869 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42] -
/ /__  | (_) | | (_) | |   <  |  __/ |  __/ | |_) | |  __/ | |
2022-08-28 21:36:13,870 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42] -
 /_____|  \___/   \___/  |_|\_\  \___|  \___| | .__/   \___| |_|
2022-08-28 21:36:13,870 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42] -
                                            | |
2022-08-28 21:36:13,870 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42] -
                                            |_|
2022-08-28 21:36:13,870 [myid:] - INFO  [main:o.a.z.ZookeeperBanner@42] -
2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
Server
environment:zookeeper.version=3.8.0-5a02a05eddb59aee6ac762f7ea82e92a68eb9c0f,
built on 2022-02-25 08:49 UTC
2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
Server environment:host.name=host
2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
Server environment:java.version=11.0.16
2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
Server environment:java.vendor=Ubuntu
2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
Server environment:java.home=/usr/lib/jvm/java-11-openjdk-amd64
2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
Server
environment:java.class.path=/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../zookeeper-server/target/classes:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../build/classes:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../zookeeper-server/target/lib/*.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../build/lib/*.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/zookeeper-prometheus-metrics-3.8.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/zookeeper-jute-3.8.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/zookeeper-3.8.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/snappy-java-1.1.7.7.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/slf4j-api-1.7.30.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/simpleclient_servlet-0.9.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/simpleclient_hotspot-0.9.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/simpleclient_common-0.9.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/simpleclient-0.9.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-transport-native-unix-common-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-transport-native-epoll-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-transport-classes-epoll-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-transport-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-tcnative-classes-2.0.48.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-tcnative-2.0.48.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-resolver-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-handler-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-common-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-codec-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/netty-buffer-4.1.73.Final.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/metrics-core-4.1.12.1.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/logback-core-1.2.10.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/logback-classic-1.2.10.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jline-2.14.6.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-util-ajax-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-util-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-servlet-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-server-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-security-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-io-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jetty-http-9.4.43.v20210629.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/javax.servlet-api-3.1.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jackson-databind-2.13.1.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jackson-core-2.13.1.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/jackson-annotations-2.13.1.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/commons-io-2.11.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/commons-cli-1.4.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../lib/audience-annotations-0.12.0.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../zookeeper-*.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../zookeeper-server/src/main/resources/lib/*.jar:/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin/../conf:
2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
Server
environment:java.library.path=/usr/java/packages/lib:/usr/lib/x86_64-linux-gnu/jni:/lib/x86_64-linux-gnu:/usr/lib/x86_64-linux-gnu:/usr/lib/jni:/lib:/usr/lib
2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
Server environment:java.io.tmpdir=/tmp
2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
Server environment:java.compiler=<NA>
2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
Server environment:os.name=Linux
2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
Server environment:os.arch=amd64
2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
Server environment:os.version=5.15.0-46-generic
2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
Server
environment:user.dir=/home/will/servers/zookeeper/apache-zookeeper-3.8.0-bin/bin
2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
Server environment:os.memory.free=231MB
2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
Server environment:os.memory.max=1000MB
2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.Environment@98] -
Server environment:os.memory.total=250MB
2022-08-28 21:36:13,871 [myid:] - INFO  [main:o.a.z.s.ZooKeeperServer@140]
- zookeeper.enableEagerACLCheck = false
2022-08-28 21:36:13,872 [myid:] - INFO  [main:o.a.z.s.ZooKeeperServer@153]
- zookeeper.digest.enabled = true
2022-08-28 21:36:13,872 [myid:] - INFO  [main:o.a.z.s.ZooKeeperServer@157]
- zookeeper.closeSessionTxn.enabled = true
2022-08-28 21:36:13,872 [myid:] - INFO  [main:o.a.z.s.ZooKeeperServer@1496]
- zookeeper.flushDelay = 0 ms
2022-08-28 21:36:13,872 [myid:] - INFO  [main:o.a.z.s.ZooKeeperServer@1505]
- zookeeper.maxWriteQueuePollTime = 0 ms
2022-08-28 21:36:13,872 [myid:] - INFO  [main:o.a.z.s.ZooKeeperServer@1514]
- zookeeper.maxBatchSize=1000
2022-08-28 21:36:13,872 [myid:] - INFO  [main:o.a.z.s.ZooKeeperServer@264]
- zookeeper.intBufferStartingSizeBytes = 1024
2022-08-28 21:36:13,872 [myid:] - INFO  [main:o.a.z.s.BlueThrottle@141] -
Weighed connection throttling is disabled
2022-08-28 21:36:13,873 [myid:] - INFO  [main:o.a.z.s.ZooKeeperServer@1297]
- minSessionTimeout set to 4000 ms
2022-08-28 21:36:13,873 [myid:] - INFO  [main:o.a.z.s.ZooKeeperServer@1306]
- maxSessionTimeout set to 40000 ms
2022-08-28 21:36:13,874 [myid:] - INFO  [main:o.a.z.s.ResponseCache@45] -
getData response cache size is initialized with value 400.
2022-08-28 21:36:13,874 [myid:] - INFO  [main:o.a.z.s.ResponseCache@45] -
getChildren response cache size is initialized with value 400.
2022-08-28 21:36:13,874 [myid:] - INFO
 [main:o.a.z.s.u.RequestPathMetricsCollector@109] -
zookeeper.pathStats.slotCapacity = 60
2022-08-28 21:36:13,874 [myid:] - INFO
 [main:o.a.z.s.u.RequestPathMetricsCollector@110] -
zookeeper.pathStats.slotDuration = 15
2022-08-28 21:36:13,875 [myid:] - INFO
 [main:o.a.z.s.u.RequestPathMetricsCollector@111] -
zookeeper.pathStats.maxDepth = 6
2022-08-28 21:36:13,875 [myid:] - INFO
 [main:o.a.z.s.u.RequestPathMetricsCollector@112] -
zookeeper.pathStats.initialDelay = 5
2022-08-28 21:36:13,875 [myid:] - INFO
 [main:o.a.z.s.u.RequestPathMetricsCollector@113] -
zookeeper.pathStats.delay = 5
2022-08-28 21:36:13,875 [myid:] - INFO
 [main:o.a.z.s.u.RequestPathMetricsCollector@114] -
zookeeper.pathStats.enabled = false
2022-08-28 21:36:13,876 [myid:] - INFO  [main:o.a.z.s.ZooKeeperServer@1533]
- The max bytes for all large requests are set to 104857600
2022-08-28 21:36:13,876 [myid:] - INFO  [main:o.a.z.s.ZooKeeperServer@1547]
- The large request threshold is set to -1
2022-08-28 21:36:13,877 [myid:] - INFO
 [main:o.a.z.s.AuthenticationHelper@66] - zookeeper.enforce.auth.enabled =
false
2022-08-28 21:36:13,877 [myid:] - INFO
 [main:o.a.z.s.AuthenticationHelper@67] - zookeeper.enforce.auth.schemes =
[]
2022-08-28 21:36:13,877 [myid:] - INFO  [main:o.a.z.s.ZooKeeperServer@365]
- Created server with tickTime 2000 ms minSessionTimeout 4000 ms
maxSessionTimeout 40000 ms clientPortListenBacklog -1 datadir
/tmp/zookeeper/3.8.0/version-2 snapdir /tmp/zookeeper/3.8.0/version-2
2022-08-28 21:36:13,890 [myid:] - INFO  [main:o.e.j.u.l.Log@170] - Logging
initialized @348ms to org.eclipse.jetty.util.log.Slf4jLog
2022-08-28 21:36:13,929 [myid:] - WARN  [main:o.e.j.s.h.ContextHandler@1656]
- o.e.j.s.ServletContextHandler@3cebbb30{/,null,STOPPED} contextPath ends
with /*
2022-08-28 21:36:13,930 [myid:] - WARN  [main:o.e.j.s.h.ContextHandler@1667]
- Empty contextPath
2022-08-28 21:36:13,951 [myid:] - INFO  [main:o.e.j.s.Server@375] -
jetty-9.4.43.v20210629; built: 2021-06-30T11:07:22.254Z; git:
526006ecfa3af7f1a27ef3a288e2bef7ea9dd7e8; jvm
11.0.16+8-post-Ubuntu-0ubuntu120.04
2022-08-28 21:36:13,967 [myid:] - INFO
 [main:o.e.j.s.s.DefaultSessionIdManager@334] - DefaultSessionIdManager
workerName=node0
2022-08-28 21:36:13,967 [myid:] - INFO
 [main:o.e.j.s.s.DefaultSessionIdManager@339] - No SessionScavenger set,
using defaults
2022-08-28 21:36:13,968 [myid:] - INFO  [main:o.e.j.s.s.HouseKeeper@132] -
node0 Scavenging every 600000ms
2022-08-28 21:36:13,970 [myid:] - WARN
 [main:o.e.j.s.ConstraintSecurityHandler@759] -
ServletContext@o.e.j.s.ServletContextHandler@3cebbb30{/,null,STARTING} has
uncovered http methods for path: /*
2022-08-28 21:36:13,975 [myid:] - INFO  [main:o.e.j.s.h.ContextHandler@915]
- Started o.e.j.s.ServletContextHandler@3cebbb30{/,null,AVAILABLE}
2022-08-28 21:36:13,983 [myid:] - INFO  [main:o.e.j.s.AbstractConnector@331]
- Started ServerConnector@29d89d5d{HTTP/1.1, (http/1.1)}{0.0.0.0:8080}
2022-08-28 21:36:13,983 [myid:] - INFO  [main:o.e.j.s.Server@415] - Started
@441ms
2022-08-28 21:36:13,983 [myid:] - INFO  [main:o.a.z.s.a.JettyAdminServer@196]
- Started AdminServer on address 0.0.0.0, port 8080 and command URL
/commands
2022-08-28 21:36:13,986 [myid:] - INFO  [main:o.a.z.s.ServerCnxnFactory@169]
- Using org.apache.zookeeper.server.NIOServerCnxnFactory as server
connection factory
2022-08-28 21:36:13,987 [myid:] - WARN  [main:o.a.z.s.ServerCnxnFactory@309]
- maxCnxns is not configured, using default value 0.
2022-08-28 21:36:13,988 [myid:] - INFO
 [main:o.a.z.s.NIOServerCnxnFactory@652] - Configuring NIO connection
handler with 10s sessionless connection timeout, 2 selector thread(s), 24
worker threads, and 64 kB direct buffers.
2022-08-28 21:36:13,988 [myid:] - INFO
 [main:o.a.z.s.NIOServerCnxnFactory@660] - binding to port
0.0.0.0/0.0.0.0:2181
2022-08-28 21:36:13,997 [myid:] - INFO
 [main:o.a.z.s.w.WatchManagerFactory@42] - Using
org.apache.zookeeper.server.watch.WatchManager as watch manager
2022-08-28 21:36:13,997 [myid:] - INFO
 [main:o.a.z.s.w.WatchManagerFactory@42] - Using
org.apache.zookeeper.server.watch.WatchManager as watch manager
2022-08-28 21:36:13,998 [myid:] - INFO  [main:o.a.z.s.ZKDatabase@132] -
zookeeper.snapshotSizeFactor = 0.33
2022-08-28 21:36:13,998 [myid:] - INFO  [main:o.a.z.s.ZKDatabase@152] -
zookeeper.commitLogCount=500
2022-08-28 21:36:14,002 [myid:] - INFO  [main:o.a.z.s.p.SnapStream@61] -
zookeeper.snapshot.compression.method = CHECKED

Also here is my 3.8.0 zoo.cfg file:

# The number of milliseconds of each tick
tickTime=2000
# The number of ticks that the initial
# synchronization phase can take
initLimit=10
# The number of ticks that can pass between
# sending a request and getting an acknowledgement
syncLimit=5
# the directory where the snapshot is stored.
# do not use /tmp for storage, /tmp here is just
# example sakes.
dataDir=/tmp/zookeeper/3.8.0
# the port at which the clients will connect
clientPort=2181
# the maximum number of client connections.
# increase this if you need to handle more clients
#maxClientCnxns=60
#
# Be sure to read the maintenance section of the
# administrator guide before turning on autopurge.
#
#
https://zookeeper.apache.org/doc/current/zookeeperAdmin.html#sc_maintenance
#
# The number of snapshots to retain in dataDir
#autopurge.snapRetainCount=3
# Purge task interval in hours
# Set to "0" to disable auto purge feature
#autopurge.purgeInterval=1

## Metrics Providers
#
# https://prometheus.io Metrics Exporter
#metricsProvider.className=org.apache.zookeeper.metrics.prometheus.PrometheusMetricsProvider
#metricsProvider.httpHost=0.0.0.0
#metricsProvider.httpPort=7000
#metricsProvider.exportJvmInfo=true

4lw.commands.whitelist=*
digest.enabled=true

metricsProvider.className=org.apache.zookeeper.metrics.impl.NullMetricsProvider

Re: Read performance of 3.4.6 vs 3.8.0 according to zookeeper-benchmark

Posted by Will Now <wn...@gmail.com>.

In my plain vanilla configs the metrics provider seems to be the
DefaultMetricsProvider

    2022-08-28 21:18:59,359 [myid:] - INFO
 [main:o.a.z.s.q.QuorumPeerConfig@477] - metricsProvider.className is
org.apache.zookeeper.metrics.impl.DefaultMetricsProvider

I re-ran the 3.8.0 scenario using the NullMetricsProvider and still got
slow results of 16,370 READ tps.  Am I misunderstanding your suggestion?

    2022-08-28 21:26:48,981 [myid:] - INFO
 [main:o.a.z.s.q.QuorumPeerConfig@477] - metricsProvider.className is
org.apache.zookeeper.metrics.impl.NullMetricsProvider

27,052: 3.4.6
15,993:3.6.3
15,943:3.7.1
16,805: 3.8.0, digest.enabled=true:
16,682: 3.8.0: digest.enabled=false
*16,370: 3.8.0 NullMetricsProvider*




On Sun, Aug 28, 2022 at 3:45 AM shrikant kalani <sh...@gmail.com>
wrote:

> Hi Will,
>
> I remember there was a discussion in the past that starting 3.6 the
> performance is reduced because of Prometheus metrics endpoint enabled. May
> be you can try disabling metrics.
>
> Recently we compared performance between 3.6.2 and 3.8.0 and found 3.8.0
> performing way better than 3.6.2. There was improvement in both read and
> updates.
>
> Thanks
> Srikant Kalani
>
> On Sun, 28 Aug 2022 at 5:37 PM, tison <wa...@gmail.com> wrote:
>
> > Hi Will,
> >
> > Thanks for reporting this case! Could you run the benchmark on 3.7.1
> also?
> > It can help us bisect the point of change.
> >
> > Best,
> > tison.
> >
> >
> > Will Now <wn...@gmail.com> 于2022年8月28日周日 05:56写道：
> >
> > > Prior to my server upgrade I'm doing some benchmarking of zookeeper
> > server
> > > 3.4.6 and 3.8.0 using zookeeper-benchmark
> > > https://github.com/brownsys/zookeeper-benchmark
> > >
> > > Methodology: For each server version I extracted it anew from the tar
> > file
> > > onto my linux box, tweaked zoo.cfg to run a single node. On 3.8.0 I
> > enabled
> > > 4 letter words. I run it with a fresh (empty) dataDir.  Using default
> > > settings for zookeeper-benchmark.  (Contrary to best practices) I am
> > > running the server and test client on the same node :-/
> > >
> > > I perform 3 runs and show the READ average below. I am focussing just
> on
> > > READ results here; results are in reads/sec, so bigger numbers are
> > better:
> > >
> > > 27,052: 3.4.6
> > > 16,805: 3.8.0, digest.enabled=true:
> > > 16,682: 3.8.0: digest.enabled=false
> > >
> > > I saw similar results on a windows box and re-ran on linux for
> additional
> > > confirmation. I find it hard to believe that 3.8.0 is 40% slower on
> > reads!
> > >
> > > A while back I performed similar comparisons of 3.4.6 vs 3.6.x and I
> got
> > > slow results in 3.6.x initially, but disabling digest.enabled fixed it
> > and
> > > the two versions were then comparable. In 3.8.0 I am seeing poor
> results
> > > with or without digest enabled.
> > >
> > > Any thoughts?  Are there some new settings I need to tweak?  Is my
> > > methodology flawed?
> > >
> > > Thanks!
> > >
> >
>

Re: Read performance of 3.4.6 vs 3.8.0 according to zookeeper-benchmark

Posted by shrikant kalani <sh...@gmail.com>.

Hi Will,

I remember there was a discussion in the past that starting 3.6 the
performance is reduced because of Prometheus metrics endpoint enabled. May
be you can try disabling metrics.

Recently we compared performance between 3.6.2 and 3.8.0 and found 3.8.0
performing way better than 3.6.2. There was improvement in both read and
updates.

Thanks
Srikant Kalani

On Sun, 28 Aug 2022 at 5:37 PM, tison <wa...@gmail.com> wrote:

> Hi Will,
>
> Thanks for reporting this case! Could you run the benchmark on 3.7.1 also?
> It can help us bisect the point of change.
>
> Best,
> tison.
>
>
> Will Now <wn...@gmail.com> 于2022年8月28日周日 05:56写道：
>
> > Prior to my server upgrade I'm doing some benchmarking of zookeeper
> server
> > 3.4.6 and 3.8.0 using zookeeper-benchmark
> > https://github.com/brownsys/zookeeper-benchmark
> >
> > Methodology: For each server version I extracted it anew from the tar
> file
> > onto my linux box, tweaked zoo.cfg to run a single node. On 3.8.0 I
> enabled
> > 4 letter words. I run it with a fresh (empty) dataDir.  Using default
> > settings for zookeeper-benchmark.  (Contrary to best practices) I am
> > running the server and test client on the same node :-/
> >
> > I perform 3 runs and show the READ average below. I am focussing just on
> > READ results here; results are in reads/sec, so bigger numbers are
> better:
> >
> > 27,052: 3.4.6
> > 16,805: 3.8.0, digest.enabled=true:
> > 16,682: 3.8.0: digest.enabled=false
> >
> > I saw similar results on a windows box and re-ran on linux for additional
> > confirmation. I find it hard to believe that 3.8.0 is 40% slower on
> reads!
> >
> > A while back I performed similar comparisons of 3.4.6 vs 3.6.x and I got
> > slow results in 3.6.x initially, but disabling digest.enabled fixed it
> and
> > the two versions were then comparable. In 3.8.0 I am seeing poor results
> > with or without digest enabled.
> >
> > Any thoughts?  Are there some new settings I need to tweak?  Is my
> > methodology flawed?
> >
> > Thanks!
> >
>

Re: Read performance of 3.4.6 vs 3.8.0 according to zookeeper-benchmark

Posted by tison <wa...@gmail.com>.

Hi Will,

Thanks for reporting this case! Could you run the benchmark on 3.7.1 also?
It can help us bisect the point of change.

Best,
tison.


Will Now <wn...@gmail.com> 于2022年8月28日周日 05:56写道：

> Prior to my server upgrade I'm doing some benchmarking of zookeeper server
> 3.4.6 and 3.8.0 using zookeeper-benchmark
> https://github.com/brownsys/zookeeper-benchmark
>
> Methodology: For each server version I extracted it anew from the tar file
> onto my linux box, tweaked zoo.cfg to run a single node. On 3.8.0 I enabled
> 4 letter words. I run it with a fresh (empty) dataDir.  Using default
> settings for zookeeper-benchmark.  (Contrary to best practices) I am
> running the server and test client on the same node :-/
>
> I perform 3 runs and show the READ average below. I am focussing just on
> READ results here; results are in reads/sec, so bigger numbers are better:
>
> 27,052: 3.4.6
> 16,805: 3.8.0, digest.enabled=true:
> 16,682: 3.8.0: digest.enabled=false
>
> I saw similar results on a windows box and re-ran on linux for additional
> confirmation. I find it hard to believe that 3.8.0 is 40% slower on reads!
>
> A while back I performed similar comparisons of 3.4.6 vs 3.6.x and I got
> slow results in 3.6.x initially, but disabling digest.enabled fixed it and
> the two versions were then comparable. In 3.8.0 I am seeing poor results
> with or without digest enabled.
>
> Any thoughts?  Are there some new settings I need to tweak?  Is my
> methodology flawed?
>
> Thanks!
>