Yassin Mohii created ZOOKEEPER-4019:
---------------------------------------
Summary: FileChangeWatcher keep throwing exceptions on k8s
deployment
Key: ZOOKEEPER-4019
URL: https://issues.apache.org/jira/browse/ZOOKEEPER-4019
Project: ZooKeeper
Issue Type: Bug
Affects Versions: 3.6.1
Reporter: Yassin Mohii
Using zookeeper 3.6.1 on k8s cluster, the deployment keep throwing this
exception every 3~5 minutes.
{code:java}
ERROR [FileChangeWatcher:FileChangeWatcher$WatcherThread@223] - Error from
callbackERROR [FileChangeWatcher:FileChangeWatcher$WatcherThread@223] - Error
from callbackjava.lang.RuntimeException:
org.apache.zookeeper.common.X509Exception$SSLContextException: Failed to create
KeyManager at
org.apache.zookeeper.common.X509Util.handleWatchEvent(X509Util.java:638)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.X509Util.lambda$newFileChangeWatcher$0(X509Util.java:562)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.FileChangeWatcher$WatcherThread.runLoop(FileChangeWatcher.java:221)
[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.FileChangeWatcher$WatcherThread.run(FileChangeWatcher.java:194)
[zookeeper-3.6.1.jar:3.6.1]Caused by:
org.apache.zookeeper.common.X509Exception$SSLContextException: Failed to create
KeyManager at
org.apache.zookeeper.common.X509Util.createSSLContextAndOptionsFromConfig(X509Util.java:350)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.X509Util.createSSLContextAndOptions(X509Util.java:328)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.X509Util.createSSLContextAndOptions(X509Util.java:282)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.X509Util.resetDefaultSSLContextAndOptions(X509Util.java:272)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.X509Util.handleWatchEvent(X509Util.java:636)
~[zookeeper-3.6.1.jar:3.6.1] ... 3 moreCaused by:
org.apache.zookeeper.common.X509Exception$KeyManagerException:
java.security.KeyStoreException: did not find a private key at
org.apache.zookeeper.common.X509Util.createKeyManager(X509Util.java:447)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.X509Util.createSSLContextAndOptionsFromConfig(X509Util.java:348)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.X509Util.createSSLContextAndOptions(X509Util.java:328)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.X509Util.createSSLContextAndOptions(X509Util.java:282)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.X509Util.resetDefaultSSLContextAndOptions(X509Util.java:272)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.X509Util.handleWatchEvent(X509Util.java:636)
~[zookeeper-3.6.1.jar:3.6.1] ... 3 moreCaused by:
java.security.KeyStoreException: did not find a private key at
org.apache.zookeeper.util.PemReader.loadPrivateKey(PemReader.java:148)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.util.PemReader.loadPrivateKey(PemReader.java:142)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.util.PemReader.loadKeyStore(PemReader.java:103)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.PEMFileLoader.loadKeyStore(PEMFileLoader.java:50)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.X509Util.loadKeyStore(X509Util.java:400)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.X509Util.createKeyManager(X509Util.java:436)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.X509Util.createSSLContextAndOptionsFromConfig(X509Util.java:348)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.X509Util.createSSLContextAndOptions(X509Util.java:328)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.X509Util.createSSLContextAndOptions(X509Util.java:282)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.X509Util.resetDefaultSSLContextAndOptions(X509Util.java:272)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.X509Util.handleWatchEvent(X509Util.java:636)
~[zookeeper-3.6.1.jar:3.6.1] ... 3 more
{code}
When enabling the debug logs it appears that it tries to reload the key
certificates and it fails on the first try then succeeds afterwards,
Worth to mention here that the certificates are not renewed this frequently
anyway.
Logs when enabling Debug
{code:java}
2020-12-02T12:32:33.846+0000 [myid:] - DEBUG
[FileChangeWatcher:FileChangeWatcher$WatcherThread@219] - Got file changed
event: ENTRY_MODIFY with context:
..2020_12_02_12_23_22.5578198682020-12-02T12:32:33.846+0000 [myid:] - DEBUG
[FileChangeWatcher:FileChangeWatcher$WatcherThread@219] - Got file changed
event: ENTRY_MODIFY with context:
..2020_12_02_12_23_22.5578198682020-12-02T12:32:33.846+0000 [myid:] - DEBUG
[FileChangeWatcher:X509Util@641] - Ignoring watch event and keeping previous
default SSL context. Event kind: ENTRY_MODIFY with context:
..2020_12_02_12_23_22.5578198682020-12-02T12:32:33.866+0000 [myid:] - DEBUG
[FileChangeWatcher:FileChangeWatcher$WatcherThread@219] - Got file changed
event: ENTRY_MODIFY with context:
certWithPrivateKey.pem2020-12-02T12:32:33.866+0000 [myid:] - DEBUG
[FileChangeWatcher:X509Util@631] - Attempting to reset default SSL context
after receiving watch event: ENTRY_MODIFY with context:
certWithPrivateKey.pem2020-12-02T12:32:33.867+0000 [myid:] - ERROR
[FileChangeWatcher:FileChangeWatcher$WatcherThread@223] - Error from
callbackjava.lang.RuntimeException:
org.apache.zookeeper.common.X509Exception$SSLContextException: Failed to create
KeyManager at
org.apache.zookeeper.common.X509Util.handleWatchEvent(X509Util.java:638)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.X509Util.lambda$newFileChangeWatcher$0(X509Util.java:562)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.FileChangeWatcher$WatcherThread.runLoop(FileChangeWatcher.java:221)
[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.FileChangeWatcher$WatcherThread.run(FileChangeWatcher.java:194)
[zookeeper-3.6.1.jar:3.6.1]Caused by:
org.apache.zookeeper.common.X509Exception$SSLContextException: Failed to create
KeyManager at
org.apache.zookeeper.common.X509Util.createSSLContextAndOptionsFromConfig(X509Util.java:350)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.X509Util.createSSLContextAndOptions(X509Util.java:328)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.X509Util.createSSLContextAndOptions(X509Util.java:282)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.X509Util.resetDefaultSSLContextAndOptions(X509Util.java:272)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.X509Util.handleWatchEvent(X509Util.java:636)
~[zookeeper-3.6.1.jar:3.6.1] ... 3 moreCaused by:
org.apache.zookeeper.common.X509Exception$KeyManagerException:
java.security.KeyStoreException: did not find a private key at
org.apache.zookeeper.common.X509Util.createKeyManager(X509Util.java:447)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.X509Util.createSSLContextAndOptionsFromConfig(X509Util.java:348)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.X509Util.createSSLContextAndOptions(X509Util.java:328)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.X509Util.createSSLContextAndOptions(X509Util.java:282)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.X509Util.resetDefaultSSLContextAndOptions(X509Util.java:272)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.X509Util.handleWatchEvent(X509Util.java:636)
~[zookeeper-3.6.1.jar:3.6.1] ... 3 moreCaused by:
java.security.KeyStoreException: did not find a private key at
org.apache.zookeeper.util.PemReader.loadPrivateKey(PemReader.java:148)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.util.PemReader.loadPrivateKey(PemReader.java:142)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.util.PemReader.loadKeyStore(PemReader.java:103)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.PEMFileLoader.loadKeyStore(PEMFileLoader.java:50)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.X509Util.loadKeyStore(X509Util.java:400)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.X509Util.createKeyManager(X509Util.java:436)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.X509Util.createSSLContextAndOptionsFromConfig(X509Util.java:348)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.X509Util.createSSLContextAndOptions(X509Util.java:328)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.X509Util.createSSLContextAndOptions(X509Util.java:282)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.X509Util.resetDefaultSSLContextAndOptions(X509Util.java:272)
~[zookeeper-3.6.1.jar:3.6.1] at
org.apache.zookeeper.common.X509Util.handleWatchEvent(X509Util.java:636)
~[zookeeper-3.6.1.jar:3.6.1] ... 3 more2020-12-02T12:32:33.868+0000 [myid:] -
DEBUG [FileChangeWatcher:FileChangeWatcher$WatcherThread@219] - Got file
changed event: ENTRY_MODIFY with context:
certWithPrivateKey.pem2020-12-02T12:32:33.868+0000 [myid:] - DEBUG
[FileChangeWatcher:X509Util@631] - Attempting to reset default SSL context
after receiving watch event: ENTRY_MODIFY with context:
certWithPrivateKey.pem2020-12-02T12:32:33.874+0000 [myid:] - DEBUG
[FileChangeWatcher:X509Util@540] - Using Java9+ optimized cipher suites for
Java version 112020-12-02T12:32:38.273+0000 [myid:] - DEBUG
[qtp877363600-30-acceptor-0@1b32cd16-ServerConnector@718607eb{HTTP/1.1,[http/1.1]}{127.0.0.1:8080}:ManagedSelector@171]
- Queued change org.eclipse.jetty.io.ManagedSelector$Accept@5aad0436 on
ManagedSelector@40021799{STARTED} id=0 keys=0 selected=0
updates=02020-12-02T12:32:38.273+0000 [myid:] - DEBUG
[qtp877363600-30-acceptor-0@1b32cd16-ServerConnector@718607eb{HTTP/1.1,[http/1.1]}{127.0.0.1:8080}:ManagedSelector@189]
- Wakeup on submit ManagedSelector@40021799{STARTED} id=0 keys=0 selected=0
updates=1
{code}
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
