Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

ZK::Exceptions::ConnectionLoss error with Zookeeper 3.9 #124

Open
brendar opened this issue Oct 3, 2023 · 2 comments
Open

ZK::Exceptions::ConnectionLoss error with Zookeeper 3.9 #124

brendar opened this issue Oct 3, 2023 · 2 comments

Comments

@brendar
Copy link

brendar commented Oct 3, 2023

I'm seeing a ZK::Exceptions::ConnectionLoss error immediately after connecting when trying to use zk version 1.10.0 and zookeeper version 1.5.5 with Zookeeper 3.9.0. The issue does not occur with Zookeeper 3.8.

$ podman run --rm -d -p 21818:2181 --name zookeeper_3_8 zookeeper:3.8

$ podman run --rm -d -p 21819:2181 --name zookeeper_3_9 zookeeper:3.9

$ irb
irb(main):001> RUBY_VERSION
=> "3.2.2"
irb(main):002> require "zk"
=> true
irb(main):003> require "zk/version"
=> true
irb(main):004> ZK::VERSION
=> "1.10.0"
irb(main):005> require "zookeeper/version"
=> true
irb(main):006> Zookeeper::VERSION
=> "1.5.5"

irb(main):007> client_3_8 = ZK.new("localhost:21818")
=> #<ZK::Client::Threaded:79940 zk_session_id=0x100024968220000 ...>
irb(main):008> client_3_8.exists?("/foo")
=> false

irb(main):009> client_3_9 = ZK.new("localhost:21819")
=> #<ZK::Client::Threaded:107880 zk_session_id=0x10002497ef50000 ...>
irb(main):010> client_3_9.exists?("/foo")
/Users/brendan/.gem/ruby/3.2.2/gems/zk-1.10.0/lib/zk/client/base.rb:1083:in `check_rc': inputs: {:path=>"/foo", :ignore=>:no_node} (ZK::Exceptions::ConnectionLoss)
	from /Users/brendan/.gem/ruby/3.2.2/gems/zk-1.10.0/lib/zk/client/base.rb:1072:in `call_and_check_rc'
	from /Users/brendan/.gem/ruby/3.2.2/gems/zk-1.10.0/lib/zk/client/threaded.rb:584:in `call_and_check_rc'
	from /Users/brendan/.gem/ruby/3.2.2/gems/zk-1.10.0/lib/zk/client/base.rb:623:in `block in stat'
	from /Users/brendan/.gem/ruby/3.2.2/gems/zk-1.10.0/lib/zk/event_handler.rb:292:in `setup_watcher!'
	from /Users/brendan/.gem/ruby/3.2.2/gems/zk-1.10.0/lib/zk/client/base.rb:1115:in `setup_watcher!'
	from /Users/brendan/.gem/ruby/3.2.2/gems/zk-1.10.0/lib/zk/client/base.rb:622:in `stat'
	from /Users/brendan/.gem/ruby/3.2.2/gems/zk-1.10.0/lib/zk/client/base.rb:648:in `exists?'
	from (irb):10:in `<main>'
	from /Users/brendan/.gem/ruby/3.2.2/gems/irb-1.8.1/exe/irb:9:in `<top (required)>'
	from /Users/brendan/.gem/ruby/3.2.2/bin/irb:25:in `load'
	from /Users/brendan/.gem/ruby/3.2.2/bin/irb:25:in `<main>'
Zookeeper 3.9.0 logs: podman logs zookeeper_3_9 
ZooKeeper JMX enabled by default
Using config: /conf/zoo.cfg
2023-10-03 17:39:58,725 [myid:] - INFO  [main:o.a.z.s.q.QuorumPeerConfig@177] - Reading configuration from: /conf/zoo.cfg
2023-10-03 17:39:58,728 [myid:] - INFO  [main:o.a.z.s.q.QuorumPeerConfig@431] - clientPort is not set
2023-10-03 17:39:58,728 [myid:] - INFO  [main:o.a.z.s.q.QuorumPeerConfig@444] - secureClientPort is not set
2023-10-03 17:39:58,728 [myid:] - INFO  [main:o.a.z.s.q.QuorumPeerConfig@460] - observerMasterPort is not set
2023-10-03 17:39:58,728 [myid:] - INFO  [main:o.a.z.s.q.QuorumPeerConfig@477] - metricsProvider.className is org.apache.zookeeper.metrics.impl.DefaultMetricsProvider
2023-10-03 17:39:58,732 [myid:] - ERROR [main:o.a.z.s.q.QuorumPeerConfig@702] - Invalid configuration, only one server specified (ignoring)
2023-10-03 17:39:58,732 [myid:1] - INFO  [main:o.a.z.s.DatadirCleanupManager@78] - autopurge.snapRetainCount set to 3
2023-10-03 17:39:58,733 [myid:1] - INFO  [main:o.a.z.s.DatadirCleanupManager@79] - autopurge.purgeInterval set to 0
2023-10-03 17:39:58,733 [myid:1] - INFO  [main:o.a.z.s.DatadirCleanupManager@101] - Purge task is not scheduled.
2023-10-03 17:39:58,733 [myid:1] - WARN  [main:o.a.z.s.q.QuorumPeerMain@139] - Either no config or no quorum defined in config, running in standalone mode
2023-10-03 17:39:58,734 [myid:1] - INFO  [main:o.a.z.j.ManagedUtil@46] - Log4j 1.2 jmx support not found; jmx disabled.
2023-10-03 17:39:58,734 [myid:1] - INFO  [main:o.a.z.s.q.QuorumPeerConfig@177] - Reading configuration from: /conf/zoo.cfg
2023-10-03 17:39:58,735 [myid:1] - INFO  [main:o.a.z.s.q.QuorumPeerConfig@431] - clientPort is not set
2023-10-03 17:39:58,735 [myid:1] - INFO  [main:o.a.z.s.q.QuorumPeerConfig@444] - secureClientPort is not set
2023-10-03 17:39:58,735 [myid:1] - INFO  [main:o.a.z.s.q.QuorumPeerConfig@460] - observerMasterPort is not set
2023-10-03 17:39:58,735 [myid:1] - INFO  [main:o.a.z.s.q.QuorumPeerConfig@477] - metricsProvider.className is org.apache.zookeeper.metrics.impl.DefaultMetricsProvider
2023-10-03 17:39:58,735 [myid:1] - ERROR [main:o.a.z.s.q.QuorumPeerConfig@702] - Invalid configuration, only one server specified (ignoring)
2023-10-03 17:39:58,736 [myid:1] - INFO  [main:o.a.z.s.ZooKeeperServerMain@123] - Starting server
2023-10-03 17:39:58,741 [myid:1] - INFO  [main:o.a.z.s.ServerMetrics@64] - ServerMetrics initialized with provider org.apache.zookeeper.metrics.impl.DefaultMetricsProvider@55141def
2023-10-03 17:39:58,742 [myid:1] - INFO  [main:o.a.z.s.a.DigestAuthenticationProvider@51] - ACL digest algorithm is: SHA1
2023-10-03 17:39:58,743 [myid:1] - INFO  [main:o.a.z.s.a.DigestAuthenticationProvider@65] - zookeeper.DigestAuthenticationProvider.enabled = true
2023-10-03 17:39:58,744 [myid:1] - INFO  [main:o.a.z.s.p.FileTxnSnapLog@124] - zookeeper.snapshot.trust.empty : false
2023-10-03 17:39:58,749 [myid:1] - INFO  [main:o.a.z.ZookeeperBanner@42] -
2023-10-03 17:39:58,749 [myid:1] - INFO  [main:o.a.z.ZookeeperBanner@42] -   ______                  _
2023-10-03 17:39:58,749 [myid:1] - INFO  [main:o.a.z.ZookeeperBanner@42] -  |___  /                 | |
2023-10-03 17:39:58,749 [myid:1] - INFO  [main:o.a.z.ZookeeperBanner@42] -     / /    ___     ___   | | __   ___    ___   _ __     ___   _ __
2023-10-03 17:39:58,749 [myid:1] - INFO  [main:o.a.z.ZookeeperBanner@42] -    / /    / _ \   / _ \  | |/ /  / _ \  / _ \ | '_ \   / _ \ | '__|
2023-10-03 17:39:58,749 [myid:1] - INFO  [main:o.a.z.ZookeeperBanner@42] -   / /__  | (_) | | (_) | |   <  |  __/ |  __/ | |_) | |  __/ | |
2023-10-03 17:39:58,749 [myid:1] - INFO  [main:o.a.z.ZookeeperBanner@42] -  /_____|  \___/   \___/  |_|\_\  \___|  \___| | .__/   \___| |_|
2023-10-03 17:39:58,750 [myid:1] - INFO  [main:o.a.z.ZookeeperBanner@42] -                                               | |
2023-10-03 17:39:58,750 [myid:1] - INFO  [main:o.a.z.ZookeeperBanner@42] -                                               |_|
2023-10-03 17:39:58,751 [myid:1] - INFO  [main:o.a.z.ZookeeperBanner@42] -
2023-10-03 17:39:58,751 [myid:1] - INFO  [main:o.a.z.Environment@98] - Server environment:zookeeper.version=3.9.0-1674a5e97f43bc38e9bf56b04f83a7ae34d68249, built on 2023-07-19 09:09 UTC
2023-10-03 17:39:58,751 [myid:1] - INFO  [main:o.a.z.Environment@98] - Server environment:host.name=e29393b32ac6
2023-10-03 17:39:58,751 [myid:1] - INFO  [main:o.a.z.Environment@98] - Server environment:java.version=11.0.20.1
2023-10-03 17:39:58,752 [myid:1] - INFO  [main:o.a.z.Environment@98] - Server environment:java.vendor=Eclipse Adoptium
2023-10-03 17:39:58,752 [myid:1] - INFO  [main:o.a.z.Environment@98] - Server environment:java.home=/opt/java/openjdk
2023-10-03 17:39:58,752 [myid:1] - INFO  [main:o.a.z.Environment@98] - Server environment:java.class.path=/apache-zookeeper-3.9.0-bin/bin/../zookeeper-metrics-providers/zookeeper-prometheus-metrics/target/classes:/apache-zookeeper-3.9.0-bin/bin/../zookeeper-server/target/classes:/apache-zookeeper-3.9.0-bin/bin/../build/classes:/apache-zookeeper-3.9.0-bin/bin/../zookeeper-metrics-providers/zookeeper-prometheus-metrics/target/lib/*.jar:/apache-zookeeper-3.9.0-bin/bin/../zookeeper-server/target/lib/*.jar:/apache-zookeeper-3.9.0-bin/bin/../build/lib/*.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/zookeeper-prometheus-metrics-3.9.0.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/zookeeper-jute-3.9.0.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/zookeeper-3.9.0.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/snappy-java-1.1.10.1.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/slf4j-api-1.7.30.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/simpleclient_servlet-0.9.0.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/simpleclient_hotspot-0.9.0.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/simpleclient_common-0.9.0.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/simpleclient-0.9.0.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/netty-transport-native-unix-common-4.1.94.Final.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/netty-transport-native-epoll-4.1.94.Final-linux-x86_64.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/netty-transport-classes-epoll-4.1.94.Final.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/netty-transport-4.1.94.Final.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/netty-tcnative-classes-2.0.61.Final.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/netty-tcnative-boringssl-static-2.0.61.Final-windows-x86_64.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/netty-tcnative-boringssl-static-2.0.61.Final-osx-x86_64.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/netty-tcnative-boringssl-static-2.0.61.Final-osx-aarch_64.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/netty-tcnative-boringssl-static-2.0.61.Final-linux-x86_64.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/netty-tcnative-boringssl-static-2.0.61.Final-linux-aarch_64.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/netty-tcnative-boringssl-static-2.0.61.Final.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/netty-resolver-4.1.94.Final.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/netty-handler-4.1.94.Final.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/netty-common-4.1.94.Final.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/netty-codec-4.1.94.Final.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/netty-buffer-4.1.94.Final.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/metrics-core-4.1.12.1.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/logback-core-1.2.10.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/logback-classic-1.2.10.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/jline-2.14.6.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/jetty-util-ajax-9.4.51.v20230217.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/jetty-util-9.4.51.v20230217.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/jetty-servlet-9.4.51.v20230217.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/jetty-server-9.4.51.v20230217.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/jetty-security-9.4.51.v20230217.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/jetty-io-9.4.51.v20230217.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/jetty-http-9.4.51.v20230217.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/javax.servlet-api-3.1.0.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/jackson-databind-2.15.2.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/jackson-core-2.15.2.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/jackson-annotations-2.15.2.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/commons-io-2.11.0.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/commons-cli-1.5.0.jar:/apache-zookeeper-3.9.0-bin/bin/../lib/audience-annotations-0.12.0.jar:/apache-zookeeper-3.9.0-bin/bin/../zookeeper-*.jar:/apache-zookeeper-3.9.0-bin/bin/../zookeeper-server/src/main/resources/lib/*.jar:/conf:
2023-10-03 17:39:58,752 [myid:1] - INFO  [main:o.a.z.Environment@98] - Server environment:java.library.path=/usr/java/packages/lib:/lib:/usr/lib:/usr/lib64:/lib64
2023-10-03 17:39:58,752 [myid:1] - INFO  [main:o.a.z.Environment@98] - Server environment:java.io.tmpdir=/tmp
2023-10-03 17:39:58,752 [myid:1] - INFO  [main:o.a.z.Environment@98] - Server environment:java.compiler=<NA>
2023-10-03 17:39:58,752 [myid:1] - INFO  [main:o.a.z.Environment@98] - Server environment:os.name=Linux
2023-10-03 17:39:58,752 [myid:1] - INFO  [main:o.a.z.Environment@98] - Server environment:os.arch=aarch64
2023-10-03 17:39:58,752 [myid:1] - INFO  [main:o.a.z.Environment@98] - Server environment:os.version=6.4.15-200.fc38.aarch64
2023-10-03 17:39:58,752 [myid:1] - INFO  [main:o.a.z.Environment@98] - Server environment:user.name=zookeeper
2023-10-03 17:39:58,752 [myid:1] - INFO  [main:o.a.z.Environment@98] - Server environment:user.home=/home/zookeeper
2023-10-03 17:39:58,752 [myid:1] - INFO  [main:o.a.z.Environment@98] - Server environment:user.dir=/apache-zookeeper-3.9.0-bin
2023-10-03 17:39:58,752 [myid:1] - INFO  [main:o.a.z.Environment@98] - Server environment:os.memory.free=117MB
2023-10-03 17:39:58,752 [myid:1] - INFO  [main:o.a.z.Environment@98] - Server environment:os.memory.max=1000MB
2023-10-03 17:39:58,752 [myid:1] - INFO  [main:o.a.z.Environment@98] - Server environment:os.memory.total=126MB
2023-10-03 17:39:58,752 [myid:1] - INFO  [main:o.a.z.s.ZooKeeperServer@149] - zookeeper.enableEagerACLCheck = false
2023-10-03 17:39:58,753 [myid:1] - INFO  [main:o.a.z.s.ZooKeeperServer@162] - zookeeper.digest.enabled = true
2023-10-03 17:39:58,753 [myid:1] - INFO  [main:o.a.z.s.ZooKeeperServer@166] - zookeeper.closeSessionTxn.enabled = true
2023-10-03 17:39:58,753 [myid:1] - INFO  [main:o.a.z.s.ZooKeeperServer@2251] - zookeeper.serializeLastProcessedZxid.enabled = true
2023-10-03 17:39:58,753 [myid:1] - INFO  [main:o.a.z.s.ZooKeeperServer@1594] - zookeeper.flushDelay = 0 ms
2023-10-03 17:39:58,753 [myid:1] - INFO  [main:o.a.z.s.ZooKeeperServer@1603] - zookeeper.maxWriteQueuePollTime = 0 ms
2023-10-03 17:39:58,753 [myid:1] - INFO  [main:o.a.z.s.ZooKeeperServer@1612] - zookeeper.maxBatchSize=1000
2023-10-03 17:39:58,753 [myid:1] - INFO  [main:o.a.z.s.ZooKeeperServer@287] - zookeeper.intBufferStartingSizeBytes = 1024
2023-10-03 17:39:58,753 [myid:1] - INFO  [main:o.a.z.s.BlueThrottle@141] - Weighed connection throttling is disabled
2023-10-03 17:39:58,754 [myid:1] - INFO  [main:o.a.z.s.AuthenticationHelper@66] - zookeeper.enforce.auth.enabled = false
2023-10-03 17:39:58,754 [myid:1] - INFO  [main:o.a.z.s.AuthenticationHelper@67] - zookeeper.enforce.auth.schemes = []
2023-10-03 17:39:58,754 [myid:1] - INFO  [main:o.a.z.s.ZooKeeperServer@1406] - minSessionTimeout set to 4000 ms
2023-10-03 17:39:58,754 [myid:1] - INFO  [main:o.a.z.s.ZooKeeperServer@1415] - maxSessionTimeout set to 40000 ms
2023-10-03 17:39:58,755 [myid:1] - INFO  [main:o.a.z.s.ResponseCache@45] - getData response cache size is initialized with value 400.
2023-10-03 17:39:58,755 [myid:1] - INFO  [main:o.a.z.s.ResponseCache@45] - getChildren response cache size is initialized with value 400.
2023-10-03 17:39:58,755 [myid:1] - INFO  [main:o.a.z.s.u.RequestPathMetricsCollector@109] - zookeeper.pathStats.slotCapacity = 60
2023-10-03 17:39:58,755 [myid:1] - INFO  [main:o.a.z.s.u.RequestPathMetricsCollector@110] - zookeeper.pathStats.slotDuration = 15
2023-10-03 17:39:58,755 [myid:1] - INFO  [main:o.a.z.s.u.RequestPathMetricsCollector@111] - zookeeper.pathStats.maxDepth = 6
2023-10-03 17:39:58,755 [myid:1] - INFO  [main:o.a.z.s.u.RequestPathMetricsCollector@112] - zookeeper.pathStats.initialDelay = 5
2023-10-03 17:39:58,755 [myid:1] - INFO  [main:o.a.z.s.u.RequestPathMetricsCollector@113] - zookeeper.pathStats.delay = 5
2023-10-03 17:39:58,755 [myid:1] - INFO  [main:o.a.z.s.u.RequestPathMetricsCollector@114] - zookeeper.pathStats.enabled = false
2023-10-03 17:39:58,756 [myid:1] - INFO  [main:o.a.z.s.ZooKeeperServer@1631] - The max bytes for all large requests are set to 104857600
2023-10-03 17:39:58,757 [myid:1] - INFO  [main:o.a.z.s.ZooKeeperServer@1645] - The large request threshold is set to -1
2023-10-03 17:39:58,757 [myid:1] - INFO  [main:o.a.z.s.ZooKeeperServer@385] - Created server with tickTime 2000 ms minSessionTimeout 4000 ms maxSessionTimeout 40000 ms clientPortListenBacklog -1 datadir /datalog/version-2 snapdir /data/version-2
2023-10-03 17:39:58,774 [myid:1] - INFO  [main:o.e.j.u.l.Log@170] - Logging initialized @321ms to org.eclipse.jetty.util.log.Slf4jLog
2023-10-03 17:39:58,809 [myid:1] - WARN  [main:o.e.j.s.h.ContextHandler@1662] - o.e.j.s.ServletContextHandler@4c1909a3{/,null,STOPPED} contextPath ends with /*
2023-10-03 17:39:58,810 [myid:1] - WARN  [main:o.e.j.s.h.ContextHandler@1673] - Empty contextPath
2023-10-03 17:39:58,822 [myid:1] - INFO  [main:o.e.j.s.Server@375] - jetty-9.4.51.v20230217; built: 2023-02-17T08:19:37.309Z; git: b45c405e4544384de066f814ed42ae3dceacdd49; jvm 11.0.20.1+1
2023-10-03 17:39:58,840 [myid:1] - INFO  [main:o.e.j.s.s.DefaultSessionIdManager@334] - DefaultSessionIdManager workerName=node0
2023-10-03 17:39:58,840 [myid:1] - INFO  [main:o.e.j.s.s.DefaultSessionIdManager@339] - No SessionScavenger set, using defaults
2023-10-03 17:39:58,840 [myid:1] - INFO  [main:o.e.j.s.s.HouseKeeper@132] - node0 Scavenging every 660000ms
2023-10-03 17:39:58,842 [myid:1] - WARN  [main:o.e.j.s.ConstraintSecurityHandler@759] - [email protected]@4c1909a3{/,null,STARTING} has uncovered http methods for path: /*
2023-10-03 17:39:58,848 [myid:1] - INFO  [main:o.e.j.s.h.ContextHandler@921] - Started o.e.j.s.ServletContextHandler@4c1909a3{/,null,AVAILABLE}
2023-10-03 17:39:58,856 [myid:1] - INFO  [main:o.e.j.s.AbstractConnector@333] - Started ServerConnector@24fcf36f{HTTP/1.1, (http/1.1)}{0.0.0.0:8080}
2023-10-03 17:39:58,857 [myid:1] - INFO  [main:o.e.j.s.Server@415] - Started @405ms
2023-10-03 17:39:58,857 [myid:1] - INFO  [main:o.a.z.s.a.JettyAdminServer@201] - Started AdminServer on address 0.0.0.0, port 8080 and command URL /commands
2023-10-03 17:39:58,859 [myid:1] - INFO  [main:o.a.z.s.ServerCnxnFactory@169] - Using org.apache.zookeeper.server.NIOServerCnxnFactory as server connection factory
2023-10-03 17:39:58,859 [myid:1] - WARN  [main:o.a.z.s.ServerCnxnFactory@309] - maxCnxns is not configured, using default value 0.
2023-10-03 17:39:58,860 [myid:1] - INFO  [main:o.a.z.s.NIOServerCnxnFactory@652] - Configuring NIO connection handler with 10s sessionless connection timeout, 1 selector thread(s), 8 worker threads, and 64 kB direct buffers.
2023-10-03 17:39:58,861 [myid:1] - INFO  [main:o.a.z.s.NIOServerCnxnFactory@660] - binding to port /0.0.0.0:2181
2023-10-03 17:39:58,868 [myid:1] - INFO  [main:o.a.z.s.w.WatchManagerFactory@42] - Using org.apache.zookeeper.server.watch.WatchManager as watch manager
2023-10-03 17:39:58,868 [myid:1] - INFO  [main:o.a.z.s.w.WatchManagerFactory@42] - Using org.apache.zookeeper.server.watch.WatchManager as watch manager
2023-10-03 17:39:58,869 [myid:1] - INFO  [main:o.a.z.s.ZKDatabase@135] - zookeeper.snapshotSizeFactor = 0.33
2023-10-03 17:39:58,869 [myid:1] - INFO  [main:o.a.z.s.ZKDatabase@155] - zookeeper.commitLogCount=500
2023-10-03 17:39:58,871 [myid:1] - INFO  [main:o.a.z.s.p.SnapStream@61] - zookeeper.snapshot.compression.method = CHECKED
2023-10-03 17:39:58,871 [myid:1] - INFO  [main:o.a.z.s.p.FileTxnSnapLog@480] - Snapshotting: 0x0 to /data/version-2/snapshot.0
2023-10-03 17:39:58,873 [myid:1] - INFO  [main:o.a.z.s.ZKDatabase@292] - Snapshot loaded in 4 ms, highest zxid is 0x0, digest is 1371985504
2023-10-03 17:39:58,873 [myid:1] - INFO  [main:o.a.z.s.p.FileTxnSnapLog@480] - Snapshotting: 0x0 to /data/version-2/snapshot.0
2023-10-03 17:39:58,874 [myid:1] - INFO  [main:o.a.z.s.ZooKeeperServer@589] - Snapshot taken in 1 ms
2023-10-03 17:39:58,879 [myid:] - INFO  [ProcessThread(sid:0 cport:2181)::o.a.z.s.PrepRequestProcessor@138] - PrepRequestProcessor (sid:0) started, reconfigEnabled=false
2023-10-03 17:39:58,880 [myid:1] - INFO  [main:o.a.z.s.RequestThrottler@75] - zookeeper.request_throttler.shutdownTimeout = 10000 ms
2023-10-03 17:39:58,889 [myid:1] - INFO  [main:o.a.z.s.ContainerManager@83] - Using checkIntervalMs=60000 maxPerMinute=10000 maxNeverUsedIntervalMs=0
2023-10-03 17:39:58,890 [myid:1] - INFO  [main:o.a.z.a.ZKAuditProvider@42] - ZooKeeper audit is disabled.
2023-10-03 17:40:42,509 [myid:] - WARN  [NIOWorkerThread-1:o.a.z.s.ZooKeeperServer@1505] - Connection request from old client /192.168.127.1:30539; will be dropped if server is in r-o mode
2023-10-03 17:40:42,514 [myid:] - INFO  [SyncThread:0:o.a.z.s.p.FileTxnLog@284] - Creating new log file: log.1
2023-10-03 17:40:46,853 [myid:] - INFO  [NIOWorkerThread-5:o.a.z.s.NIOServerCnxn@339] - Unable to read additional data from client, it probably closed the socket: address = /192.168.127.1:30539, session = 0x10002497ef50000
2023-10-03 17:40:46,859 [myid:] - WARN  [NIOWorkerThread-6:o.a.z.s.ZooKeeperServer@1505] - Connection request from old client /192.168.127.1:30540; will be dropped if server is in r-o mode
2023-10-03 17:40:53,543 [myid:] - INFO  [NIOWorkerThread-2:o.a.z.s.NIOServerCnxn@339] - Unable to read additional data from client, it probably closed the socket: address = /192.168.127.1:30540, session = 0x10002497ef50000
2023-10-03 17:41:00,219 [myid:] - WARN  [NIOWorkerThread-3:o.a.z.s.ZooKeeperServer@1505] - Connection request from old client /192.168.127.1:30541; will be dropped if server is in r-o mode
2023-10-03 17:41:06,894 [myid:] - INFO  [NIOWorkerThread-7:o.a.z.s.NIOServerCnxn@339] - Unable to read additional data from client, it probably closed the socket: address = /192.168.127.1:30541, session = 0x10002497ef50000
2023-10-03 17:41:06,901 [myid:] - WARN  [NIOWorkerThread-8:o.a.z.s.ZooKeeperServer@1505] - Connection request from old client /192.168.127.1:30543; will be dropped if server is in r-o mode
2023-10-03 17:41:07,530 [myid:] - INFO  [NIOWorkerThread-3:o.a.z.s.NIOServerCnxn@339] - Unable to read additional data from client, it probably closed the socket: address = /192.168.127.1:30543, session = 0x10002497ef50000

The above commands were executed on a mac, but I'm seeing the same issue on a linux CI host.

Is it possible this is a C client compatibility issue? zookeeper appears to be using a 3.4.x client, but the release announcement for 3.9.0 says

ZooKeeper clients from 3.5.x onwards are fully compatible with 3.9.x servers.
@markdascher markdascher mentioned this issue Oct 13, 2023
Open
@brandonvin
Copy link

brandonvin commented Nov 10, 2023 •
edited
Loading

Seeing similar issues using zookeeper gem version 1.5.5, and ZooKeeper cluster version 3.9.1. Was able to work around this by rolling back the ZooKeeper cluster to 3.8.3.

  • Operations on paths return a result indicating the node doesn't exist, though the node does exist in ZooKeeper with children
  • Some operations time out after 30 seconds
$ echo srvr | nc zookeeper 2181
Zookeeper version: 3.9.1-1398af177833412e9ead6b9bb737dc9fd7418a45, built on 2023-10-04 09:54 UTC

In an irb session:

irb(main):001:0> require 'zookeeper'
=> true

irb(main):002:0> zk = Zookeeper.new("zookeeper:2181")
=>
#<Zookeeper::Client:0x0000560db4237018
...

irb(main):003:0> zk.stat(:path => "/")
=> {:req_id=>0, :rc=>-4, :stat=>#<Zookeeper::Stat:0x0000560db479fe60 @exists=false>}

irb(main):004:0> zk.get_children(:path => "/")
=> {:req_id=>1, :rc=>-2, :children=>nil, :stat=>#<Zookeeper::Stat:0x0000560db474b630 @exists=false>}

irb(main):005:0> zk.get_children(:path => "/")
/var/lib/gems/3.0.0/gems/zookeeper-1.5.5/lib/zookeeper/continuation.rb:117:in `block in value': response for meth: :get_children, args: [2, "/", nil, nil], not received within 30 seconds (Zookeeper::Exceptions::ContinuationTimeoutError)
        from /usr/lib/ruby/3.0.0/monitor.rb:202:in `synchronize'
        from /usr/lib/ruby/3.0.0/monitor.rb:202:in `mon_synchronize'
        from /var/lib/gems/3.0.0/gems/zookeeper-1.5.5/lib/zookeeper/continuation.rb:107:in `value'
        from /var/lib/gems/3.0.0/gems/zookeeper-1.5.5/ext/c_zookeeper.rb:233:in `submit_and_block'
        from /var/lib/gems/3.0.0/gems/zookeeper-1.5.5/ext/c_zookeeper.rb:42:in `get_children'
        from /usr/lib/ruby/3.0.0/forwardable.rb:238:in `get_children'
        from /var/lib/gems/3.0.0/gems/zookeeper-1.5.5/lib/zookeeper/client_methods.rb:69:in `get_children'
        from (irb):5:in `<main>'
        from /usr/lib/ruby/gems/3.0.0/gems/irb-1.3.5/exe/irb:11:in `<top (required)>'
        from /usr/bin/irb:23:in `load'
        from /usr/bin/irb:23:in `<main>'

@agelwarg
Copy link

agelwarg commented Sep 3, 2024

Does anyone know if this project dead? Doesn't seem to be any movement on this or any other issues.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@agelwarg @brendar @brandonvin