Issue connecting to zookeeper over ssl

[itskannanraj]

I have tested the below snippet with python3.4, python3.5, python3.6, python3.7.
The code is running on python 3.4 and an other versions Connection dropped: socket connection error: The operation did not complete (read) (_ssl.c:2309).

Kazoo: 2.6.1
Zookeeper: 3.5.5

Python 3.4.10 (default, Mar 29 2019, 18:50:06)
[GCC 7.3.0] on linux
Type "help", "copyright", "credits" or "license" for more information.

>>> import logging
>>> from kazoo.client import KazooClient
>>> from kazoo.retry import KazooRetry
>>> client = KazooClient(connection_retry=KazooRetry(max_tries=3),hosts='127.0.0.1:2281',read_only=True,timeout=3,use_ssl=True,verify_certs=True,keyfile='key.pem',certfile='cert.pem',ca='ca.pem')
>>> client.start()
>>>

Python 3.5.9 (default, Nov 24 2019, 01:35:13)
[GCC 7.4.0] on linux
Type "help", "copyright", "credits" or "license" for more information.

>>> import logging
>>> from kazoo.client import KazooClient
>>> from kazoo.retry import KazooRetry
>>> client = KazooClient(connection_retry=KazooRetry(max_tries=3),hosts='127.0.0.1:2281',read_only=True,timeout=3,use_ssl=True,verify_certs=True,keyfile='key.pem',certfile='cert.pem',ca='ca.pem')
>>> client.start()
Connection dropped: socket connection error: The operation did not complete (read) (_ssl.c:2096)
Connection dropped: socket connection error: The operation did not complete (read) (_ssl.c:2096)
Connection dropped: socket connection error: The operation did not complete (read) (_ssl.c:2096)
Connection dropped: socket connection error: The operation did not complete (read) (_ssl.c:2096)
Failed connecting to Zookeeper within the connection retry policy.
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/local/lib/python3.5/dist-packages/kazoo/client.py", line 582, in start
    raise self.handler.timeout_exception("Connection time-out")
kazoo.handlers.threading.KazooTimeoutError: Connection time-out

Python 3.6.9 (default, Nov 7 2019, 10:44:02)
[GCC 8.3.0] on linux
Type "help", "copyright", "credits" or "license" for more information.

>>> import logging
>>> from kazoo.client import KazooClient
>>> from kazoo.retry import KazooRetry
>>> client = KazooClient(connection_retry=KazooRetry(max_tries=3),hosts='127.0.0.1:2281',read_only=True,timeout=3,use_ssl=True,verify_certs=True,keyfile='key.pem',certfile='cert.pem',ca='ca.pem')
>>> client.start()
Connection dropped: socket connection error: The operation did not complete (read) (_ssl.c:2309)
Connection dropped: socket connection error: The operation did not complete (read) (_ssl.c:2309)
Connection dropped: socket connection error: The operation did not complete (read) (_ssl.c:2309)
Connection dropped: socket connection error: The operation did not complete (read) (_ssl.c:2309)
Failed connecting to Zookeeper within the connection retry policy.
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/local/lib/python3.6/dist-packages/kazoo/client.py", line 582, in start
    raise self.handler.timeout_exception("Connection time-out")
kazoo.handlers.threading.KazooTimeoutError: Connection time-out

Python 3.7.3 (default, Feb 11 2020, 12:38:04)
[GCC 7.4.0] on linux
Type "help", "copyright", "credits" or "license" for more information.

>>> import logging
>>> from kazoo.client import KazooClient
>>> from kazoo.retry import KazooRetry
>>> client = KazooClient(connection_retry=KazooRetry(max_tries=3),hosts='127.0.0.12281',read_only=True,timeout=3,use_ssl=True,verify_certs=True,keyfile='key.pem',certfile='cert.pem',ca='ca.pem')
>>> client.start()
Connection dropped: socket connection error: The operation did not complete (read) (_ssl.c:2488)
Connection dropped: socket connection error: The operation did not complete (read) (_ssl.c:2488)
Connection dropped: socket connection error: The operation did not complete (read) (_ssl.c:2488)
Connection dropped: socket connection error: The operation did not complete (read) (_ssl.c:2488)
Failed connecting to Zookeeper within the connection retry policy.
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/local/lib/python3.7/site-packages/kazoo/client.py", line 582, in start
    raise self.handler.timeout_exception("Connection time-out")
kazoo.handlers.threading.KazooTimeoutError: Connection time-out

logs from zookeeper with python 3.5, 3.6 and 3.7

2020-02-17 15:04:41,086 [myid:123] - INFO  [epollEventLoopGroup-7-2:NettyServerCnxnFactory@336] - SSL handler added for channel: [id: 0xcfa5ae35, L:/127.0.0.1:2281 - R:/127.0.0.1:38842]
2020-02-17 15:04:41,121 [myid:123] - INFO  [epollEventLoopGroup-7-2:X509AuthenticationProvider@172] - Authenticated Id '1.2.840.113549.1.9.1=#161363796265726f707340616b616d61692e636f6d,' for Scheme 'x509'
2020-02-17 15:04:41,125 [myid:123] - INFO  [epollEventLoopGroup-7-3:NettyServerCnxnFactory@336] - SSL handler added for channel: [id: 0x15fd232c, L:/127.0.0.1:2281 - R:/127.0.0.1:38846]
2020-02-17 15:04:41,161 [myid:123] - INFO  [epollEventLoopGroup-7-3:X509AuthenticationProvider@172] - Authenticated Id '1.2.840.113549.1.9.1=#161363796265726f707340616b616d61692e636f6d,' for Scheme 'x509'
2020-02-17 15:04:42,166 [myid:123] - INFO  [epollEventLoopGroup-7-4:NettyServerCnxnFactory@336] - SSL handler added for channel: [id: 0x5146c4e6, L:/127.0.0.1:2281 - R:/127.0.0.1:38848]
2020-02-17 15:04:42,189 [myid:123] - INFO  [epollEventLoopGroup-7-4:X509AuthenticationProvider@172] - Authenticated Id '1.2.840.113549.1.9.1=#161363796265726f707340616b616d61692e636f6d' for Scheme 'x509'
2020-02-17 15:04:43,195 [myid:123] - INFO  [epollEventLoopGroup-7-1:NettyServerCnxnFactory@336] - SSL handler added for channel: [id: 0xb2a7da48, L:/127.0.0.1:2281 - R:/127.0.0.1:38852]
2020-02-17 15:04:43,218 [myid:123] - INFO  [epollEventLoopGroup-7-1:X509AuthenticationProvider@172] - Authenticated Id '1.2.840.113549.1.9.1=#161363796265726f707340616b616d61692e636f6d' for Scheme 'x509'
2020-02-17 15:04:46,228 [myid:123] - INFO  [SessionTracker:ZooKeeperServer@398] - Expiring session 0x7b000ec6a328037c, timeout of 4000ms exceeded
2020-02-17 15:04:46,228 [myid:123] - INFO  [SessionTracker:QuorumZooKeeperServer@157] - Submitting global closeSession request for session 0x7b000ec6a328037c
2020-02-17 15:04:46,228 [myid:123] - INFO  [SessionTracker:ZooKeeperServer@398] - Expiring session 0x7b000ec6a328037b, timeout of 4000ms exceeded
2020-02-17 15:04:46,229 [myid:123] - INFO  [SessionTracker:QuorumZooKeeperServer@157] - Submitting global closeSession request for session 0x7b000ec6a328037b
2020-02-17 15:04:48,229 [myid:123] - INFO  [SessionTracker:ZooKeeperServer@398] - Expiring session 0x7b000ec6a328037e, timeout of 4000ms exceeded
2020-02-17 15:04:48,229 [myid:123] - INFO  [SessionTracker:QuorumZooKeeperServer@157] - Submitting global closeSession request for session 0x7b000ec6a328037e
2020-02-17 15:04:48,229 [myid:123] - INFO  [SessionTracker:ZooKeeperServer@398] - Expiring session 0x7b000ec6a328037d, timeout of 4000ms exceeded
2020-02-17 15:04:48,229 [myid:123] - INFO  [SessionTracker:QuorumZooKeeperServer@157] - Submitting global closeSession request for session 0x7b000ec6a328037d

Reproduce:
run the code with any of the python version 3.5.9, 3.6.9 and 3.7.3

>>> import logging
>>> from kazoo.client import KazooClient
>>> from kazoo.retry import KazooRetry
>>> client = KazooClient(connection_retry=KazooRetry(max_tries=3),hosts='127.0.0.1:2281',read_only=True,timeout=3,use_ssl=True,verify_certs=True,keyfile='key.pem',certfile='cert.pem',ca='ca.pem')
>>> client.start()

[StephenSorriaux]

Hi,

Thanks for the issue, I will try to reproduce it. Can you re-run one of your snippet with your logging level set to logging.DEBUG?

[itskannanraj]

I ran code with logging.DEGUG in Python 3.6.9

import logging
from kazoo.client import KazooClient
from kazoo.retry import KazooRetry

logger = '[%(asctime)s] %(levelname)-5s %(message)s'
logging.basicConfig(format=logger,
                    level=logging.DEBUG,
                    datefmt='%d-%m-%Y %H:%M:%S')

client = KazooClient(connection_retry=KazooRetry(max_tries=3),
                     hosts='127.0.0.1:2281',
                     read_only=True,
                     timeout=3,
                     use_ssl=True,
                     verify_certs=True,
                     keyfile='key.pem',
                     certfile='cert.pem',
                     ca='ca.pem')
client.start()

[18-02-2020 10:52:32] INFO  Connecting to 127.0.0.1:2281, use_ssl: True
[18-02-2020 10:52:32] DEBUG Sending request(xid=None): Connect(protocol_version=0, last_zxid_seen=0, time_out=3000, session_id=0, passwd=b'\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00', read_only=True)
[18-02-2020 10:52:32] WARNING Connection dropped: socket connection error: The operation did not complete (read) (_ssl.c:2309)
[18-02-2020 10:52:32] INFO  Connecting to 127.0.0.1:2281, use_ssl: True
[18-02-2020 10:52:32] DEBUG Sending request(xid=None): Connect(protocol_version=0, last_zxid_seen=0, time_out=3000, session_id=0, passwd=b'\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00', read_only=True)
[18-02-2020 10:52:32] WARNING Connection dropped: socket connection error: The operation did not complete (read) (_ssl.c:2309)
[18-02-2020 10:52:32] INFO  Connecting to 127.0.0.1:2281, use_ssl: True
[18-02-2020 10:52:32] DEBUG Sending request(xid=None): Connect(protocol_version=0, last_zxid_seen=0, time_out=3000, session_id=0, passwd=b'\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00', read_only=True)
[18-02-2020 10:52:32] WARNING Connection dropped: socket connection error: The operation did not complete (read) (_ssl.c:2309)
[18-02-2020 10:52:33] INFO  Connecting to 127.0.0.1:2281, use_ssl: True
[18-02-2020 10:52:33] DEBUG Sending request(xid=None): Connect(protocol_version=0, last_zxid_seen=0, time_out=3000, session_id=0, passwd=b'\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00', read_only=True)
[18-02-2020 10:52:33] WARNING Connection dropped: socket connection error: The operation did not complete (read) (_ssl.c:2309)
[18-02-2020 10:52:33] WARNING Failed connecting to Zookeeper within the connection retry policy.
[18-02-2020 10:52:33] INFO  Zookeeper session lost, state: CLOSED
Traceback (most recent call last):
  File "snippet.py", line 19, in <module>
    client.start()
  File "/usr/local/lib/python3.6/dist-packages/kazoo/client.py", line 582, in start
    raise self.handler.timeout_exception("Connection time-out")
kazoo.handlers.threading.KazooTimeoutError: Connection time-out

[StephenSorriaux]

Hello,

I am not reproducing it using python 3.6 or python 3.7 with the following configuration:

• 1 ZK server in version 3.5.5
• a self signed CA (ca.cert) used to generate a cert for ZK and a client cert (client.cert)
• snippet

from kazoo.client import KazooClient
zk = KazooClient(
    hosts=hosts,
    ca='ca.cert',
    keyfile='client.key',
    certfile='client.cert',
    use_ssl=True
)
zk.start()

Can you provide more configuration from your ZK server and your TLS configuration? Is it only 1 ZK server or a cluster with more nodes?

[StephenSorriaux]

Gentle ping @itskannanraj