You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@zookeeper.apache.org by "maoling (Jira)" <ji...@apache.org> on 2020/12/03 06:10:00 UTC
[jira] [Commented] (ZOOKEEPER-4019) FileChangeWatcher keep throwing
exceptions on k8s deployment
[ https://issues.apache.org/jira/browse/ZOOKEEPER-4019?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17242938#comment-17242938 ]
maoling commented on ZOOKEEPER-4019:
------------------------------------
[~ymohii]
- I dig into the source code and don't find something suspicious. We can make sure there must be something that really modifies the path where stores these keys? Since it happens every 3~5 minutes, we can observe *mtime* or *lsof |grep your-path* to find the guilty?
- Is this issue only exists in the *k8s* env, can we also reproduce it in the *Linux VM* deployment?
> 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
> Priority: Major
>
> 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)