Support Questions
Find answers, ask questions, and share your expertise
Announcements
Check out our newest addition to the community, the Cloudera Innovation Accelerator group hub.

Nifi Zookeeper issues with Java 11 and Nifi-1.10.0

Explorer

Hi,

 

I am having issues with the zookeeper (zookeeper-3.4.13) with latest nifi version of Nifi-1.10.0 , below is the stack trace. I am upgrading from nifi-1.9.0 .  let me know if latest version of Nifi needs different version of zookeeper ? or the issue is somewhere else.

 

Not : With Java 8 and nifi-1.9.0 everything works

 

Actual Logs using Java 11 

2019-11-15 03:40:09,202 INFO [main-EventThread] o.a.c.f.state.ConnectionStateManager State change: CONNECTED

2019-11-15 03:40:09,241 INFO [Curator-Framework-0] o.a.c.f.imps.CuratorFrameworkImpl backgroundOperationsLoop exiting

2019-11-15 03:40:09,355 INFO [main] o.apache.nifi.controller.FlowController It appears that no Cluster Coordinator has been Elected yet. Registering for Cluster Coordinator Role.

2019-11-15 03:40:09,356 INFO [main] o.a.n.c.l.e.CuratorLeaderElectionManager CuratorLeaderElectionManager[stopped=true] Registered new Leader Selector for role Cluster Coordinator; this node is an active participant in the election.

2019-11-15 03:40:09,360 INFO [main] o.a.c.f.imps.CuratorFrameworkImpl Starting

2019-11-15 03:40:09,361 INFO [main] org.apache.zookeeper.ClientCnxnSocket jute.maxbuffer value is 4194304 Bytes

2019-11-15 03:40:09,365 INFO [main] o.a.c.f.imps.CuratorFrameworkImpl Default schema

2019-11-15 03:40:09,371 INFO [main] o.a.n.c.l.e.CuratorLeaderElectionManager CuratorLeaderElectionManager[stopped=false] Registered new Leader Selector for role Cluster Coordinator; this node is an active participant in the election.

2019-11-15 03:40:09,372 INFO [main] o.a.n.c.l.e.CuratorLeaderElectionManager CuratorLeaderElectionManager[stopped=false] started

2019-11-15 03:40:09,372 INFO [main] o.a.n.c.c.h.AbstractHeartbeatMonitor Heartbeat Monitor started

2019-11-15 03:40:09,375 INFO [main-EventThread] o.a.c.f.state.ConnectionStateManager State change: CONNECTED

2019-11-15 03:40:09,387 INFO [Curator-ConnectionStateManager-0] o.a.n.c.l.e.CuratorLeaderElectionManager org.apache.nifi.controller.leader.election.CuratorLeaderElectionManager$ElectionListener@43eff6be Connection State changed to CONNECTED

2019-11-15 03:40:09,540 INFO [main-EventThread] o.a.c.f.state.ConnectionStateManager State change: SUSPENDED

2019-11-15 03:40:09,540 INFO [Curator-ConnectionStateManager-0] o.a.n.c.l.e.CuratorLeaderElectionManager org.apache.nifi.controller.leader.election.CuratorLeaderElectionManager$ElectionListener@43eff6be Connection State changed to SUSPENDED

2019-11-15 03:40:10,490 INFO [main-EventThread] o.a.c.f.state.ConnectionStateManager State change: RECONNECTED

2019-11-15 03:40:10,490 INFO [Curator-ConnectionStateManager-0] o.a.n.c.l.e.CuratorLeaderElectionManager org.apache.nifi.controller.leader.election.CuratorLeaderElectionManager$ElectionListener@43eff6be Connection State changed to RECONNECTED

2019-11-15 03:40:10,634 INFO [main-EventThread] o.a.c.f.state.ConnectionStateManager State change: SUSPENDED

2019-11-15 03:40:10,636 INFO [Curator-ConnectionStateManager-0] o.a.n.c.l.e.CuratorLeaderElectionManager org.apache.nifi.controller.leader.election.CuratorLeaderElectionManager$ElectionListener@43eff6be Connection State changed to SUSPENDED

2019-11-15 03:40:10,835 INFO [main-EventThread] o.a.c.f.state.ConnectionStateManager State change: RECONNECTED

2019-11-15 03:40:10,841 INFO [Curator-ConnectionStateManager-0] o.a.n.c.l.e.CuratorLeaderElectionManager org.apache.nifi.controller.leader.election.CuratorLeaderElectionManager$ElectionListener@43eff6be Connection State changed to RECONNECTED

2019-11-15 03:40:10,952 INFO [main-EventThread] o.a.c.f.state.ConnectionStateManager State change: SUSPENDED

2019-11-15 03:40:10,959 INFO [Curator-ConnectionStateManager-0] o.a.n.c.l.e.CuratorLeaderElectionManager org.apache.nifi.controller.leader.election.CuratorLeaderElectionManager$ElectionListener@43eff6be Connection State changed to SUSPENDED

2019-11-15 03:40:11,017 ERROR [main-EventThread] o.a.c.f.imps.CuratorFrameworkImpl Background operation retry gave up

org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss

at org.apache.zookeeper.KeeperException.create(KeeperException.java:102)

at org.apache.curator.framework.imps.CuratorFrameworkImpl.checkBackgroundRetry(CuratorFrameworkImpl.java:862)

at org.apache.curator.framework.imps.CuratorFrameworkImpl.processBackgroundOperation(CuratorFrameworkImpl.java:647)

at org.apache.curator.framework.imps.WatcherRemovalFacade.processBackgroundOperation(WatcherRemovalFacade.java:152)

at org.apache.curator.framework.imps.FindAndDeleteProtectedNodeInBackground$2.processResult(FindAndDeleteProtectedNodeInBackground.java:104)

at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:630)

at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:510)

2019-11-15 03:40:11,450 INFO [main-EventThread] o.a.c.f.state.ConnectionStateManager State change: RECONNECTED

2019-11-15 03:40:11,455 INFO [Curator-ConnectionStateManager-0] o.a.n.c.l.e.CuratorLeaderElectionManager org.apache.nifi.controller.leader.election.CuratorLeaderElectionManager$ElectionListener@43eff6be Connection State changed to RECONNECTED

2019-11-15 03:40:11,551 INFO [main-EventThread] o.a.c.f.state.ConnectionStateManager State change: SUSPENDED

2019-11-15 03:40:11,552 INFO [Curator-ConnectionStateManager-0] o.a.n.c.l.e.CuratorLeaderElectionManager org.apache.nifi.controller.leader.election.CuratorLeaderElectionManager$ElectionListener@43eff6be Connection State changed to SUSPENDED

2019-11-15 03:40:11,552 ERROR [main-EventThread] o.a.c.f.imps.CuratorFrameworkImpl Background operation retry gave up

 

Comparision of Java 8 with Nifi-1.9.0 and Java11 Nifi-1.10.0 logs below 

 

===================== JAVA 8 working ================================================

2019-11-15 18:07:44,302 INFO [main] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@196ca821 finished recovering records. Performing Checkpoint to ensure proper state of Partitions before updates
2019-11-15 18:07:44,303 INFO [main] org.wali.MinimalLockingWriteAheadLog Successfully recovered 1800 records in 18 milliseconds
2019-11-15 18:07:44,330 INFO [main] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@196ca821 checkpointed with 1800 Records and 0 Swap Files in 26 milliseconds (Stop-the-world time = 4 milliseconds, Clear Edit Logs time = 3 millis), max Transaction ID 137772318
2019-11-15 18:07:45,253 INFO [main] o.a.n.c.c.node.NodeClusterCoordinator Resetting cluster node statuses from {} to {rn-ssenpcit-lapp205.rno.apple.com:8086=NodeConnectionStatus[nodeId=rn-ssenpcit-lapp205.rno.apple.com:8086, state=DISCONNECTED, Disconnect Code=Has Not Yet Connected to Cluster, Disconnect Reason=Has Not Yet Connected to Cluster, updateId=1], rn-ssenpcit-lapp206.rno.apple.com:8086=NodeConnectionStatus[nodeId=rn-ssenpcit-lapp206.rno.apple.com:8086, state=DISCONNECTED, Disconnect Code=Has Not Yet Connected to Cluster, Disconnect Reason=Has Not Yet Connected to Cluster, updateId=0]}
2019-11-15 18:07:45,363 INFO [main] o.a.n.r.v.FileBasedVariableRegistry Loaded 97 properties from system properties and environment variables
2019-11-15 18:07:45,364 INFO [main] o.a.n.r.v.FileBasedVariableRegistry Loaded a total of 97 properties. Including precedence overrides effective accessible registry key size is 97
2019-11-15 18:07:45,520 INFO [main] o.a.n.c.r.WriteAheadFlowFileRepository Initialized FlowFile Repository using 256 partitions
2019-11-15 18:07:46,240 INFO [main] o.a.n.p.store.WriteAheadStorePartition After recovering ./provenance_repository, next Event ID to be generated will be 148085136
2019-11-15 18:07:47,399 INFO [pool-23-thread-1] o.a.n.p.index.lucene.LuceneEventIndex Determined that Max Event ID indexed for Partition default is approximately 148084987 based on index ./provenance_repository/index-1573685499416
2019-11-15 18:07:47,403 INFO [pool-23-thread-1] o.a.n.p.store.WriteAheadStorePartition The last Provenance Event indexed for partition default is 148074987, but the last event written to partition has ID 148085135. Re-indexing up to the last 10148 events to ensure that the Event Index is accurate and up-to-date
2019-11-15 18:07:49,963 INFO [pool-23-thread-1] o.a.n.p.store.WriteAheadStorePartition Finished re-indexing 10149 events across 1 files for ./provenance_repository in 2.559 seconds
2019-11-15 18:07:49,973 INFO [main] o.a.n.c.repository.FileSystemRepository Maximum Threshold for Container default set to 35101377658 bytes; if volume exceeds this size, archived data will be deleted until it no longer exceeds this size
2019-11-15 18:07:49,975 INFO [main] o.a.n.c.repository.FileSystemRepository Initializing FileSystemRepository with 'Always Sync' set to false
2019-11-15 18:07:50,935 INFO [main] o.apache.nifi.controller.FlowController Checking if there is already a Cluster Coordinator Elected...
2019-11-15 18:07:51,015 INFO [main] o.a.c.f.imps.CuratorFrameworkImpl Starting
2019-11-15 18:07:51,340 INFO [main-EventThread] o.a.c.f.state.ConnectionStateManager State change: CONNECTED
2019-11-15 18:07:51,362 INFO [Curator-Framework-0] o.a.c.f.imps.CuratorFrameworkImpl backgroundOperationsLoop exiting
2019-11-15 18:07:51,370 INFO [main] o.apache.nifi.controller.FlowController The Election for Cluster Coordinator has already begun (Leader is rn-ssenpcit-lapp206.rno.apple.com:11443). Will not register to be elected for this role until after connecting to the cluster and inheriting the cluster's flow.
2019-11-15 18:07:51,372 INFO [main] o.a.n.c.l.e.CuratorLeaderElectionManager CuratorLeaderElectionManager[stopped=true] Registered new Leader Selector for role Cluster Coordinator; this node is a silent observer in the election.
2019-11-15 18:07:51,373 INFO [main] o.a.c.f.imps.CuratorFrameworkImpl Starting
2019-11-15 18:07:51,376 INFO [main] o.a.n.c.l.e.CuratorLeaderElectionManager CuratorLeaderElectionManager[stopped=false] Registered new Leader Selector for role Cluster Coordinator; this node is a silent observer in the election.
2019-11-15 18:07:51,379 INFO [main] o.a.n.c.l.e.CuratorLeaderElectionManager CuratorLeaderElectionManager[stopped=false] started
2019-11-15 18:07:51,379 INFO [main] o.a.n.c.c.h.AbstractHeartbeatMonitor Heartbeat Monitor started
2019-11-15 18:07:51,385 INFO [main-EventThread] o.a.c.f.state.ConnectionStateManager State change: CONNECTED
2019-11-15 18:07:55,430 INFO [main] o.e.jetty.server.handler.ContextHandler Started o.e.j.w.WebAppContext@6ca9f1d0{nifi-api,/nifi-api,file:///ngs/app/ssewiret/nifi/work/jetty/nifi-web-api-1.9.0.war/webapp/,AVAILABLE}{./work/nar/framework/nifi-framework-nar-1.9.0.nar-unpacked/NAR-INF/bundled-dependencies/nifi-web-api-1.9.0.war}
2019-11-15 18:07:55,831 INFO [main] o.e.j.a.AnnotationConfiguration Scanning elapsed time=135ms
2019-11-15 18:07:55,862 INFO [main] o.e.j.s.h.C._nifi_content_viewer No Spring WebApplicationInitializer types detected on classpath
2019-11-15 18:07:56,194 INFO [main] o.e.jetty.server.handler.ContextHandler Started o.e.j.w.WebAppContext@4a467f08{nifi-content-viewer,/nifi-content-viewer,file:///ngs/app/ssewiret/nifi/work/jetty/nifi-web-content-viewer-1.9.0.war/webapp/,AVAILABLE}{./work/nar/framework/nifi-framework-nar-1.9.0.nar-unpacked/NAR-INF/bundled-dependencies/nifi-web-content-viewer-1.9.0.war}
2019-11-15 18:07:56,218 INFO [main] o.e.j.a.AnnotationConfiguration Scanning elapsed time=9ms
2019-11-15 18:07:56,219 WARN [main] o.e.j.webapp.StandardDescriptorProcessor Duplicate mapping from / to default


======================== JAVA 11 NOT WORKING ============================================

2019-11-15 20:02:32,893 ERROR [main] org.apache.nifi.encrypt.StringEncryptor ********************************************************************************
2019-11-15 20:02:32,996 INFO [main] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@56c856c0 finished recovering records. Performing Checkpoint to ensure proper state of Partitions before updates
2019-11-15 20:02:32,996 INFO [main] org.wali.MinimalLockingWriteAheadLog Successfully recovered 1800 records in 31 milliseconds
2019-11-15 20:02:33,015 INFO [main] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@56c856c0 checkpointed with 1800 Records and 0 Swap Files in 19 milliseconds (Stop-the-world time = 3 milliseconds, Clear Edit Logs time = 2 millis), max Transaction ID 137772323
2019-11-15 20:02:33,517 INFO [main] o.a.n.c.c.node.NodeClusterCoordinator Resetting cluster node statuses from {} to {rn-ssenpcit-lapp205.rno.apple.com:8086=NodeConnectionStatus[nodeId=rn-ssenpcit-lapp205.rno.apple.com:8086, state=DISCONNECTED, Disconnect Code=Has Not Yet Connected to Cluster, Disconnect Reason=Has Not Yet Connected to Cluster, updateId=1], rn-ssenpcit-lapp206.rno.apple.com:8086=NodeConnectionStatus[nodeId=rn-ssenpcit-lapp206.rno.apple.com:8086, state=DISCONNECTED, Disconnect Code=Has Not Yet Connected to Cluster, Disconnect Reason=Has Not Yet Connected to Cluster, updateId=0]}
2019-11-15 20:02:33,569 INFO [main] o.a.n.r.v.FileBasedVariableRegistry Loaded 95 properties from system properties and environment variables
2019-11-15 20:02:33,569 INFO [main] o.a.n.r.v.FileBasedVariableRegistry Loaded a total of 95 properties. Including precedence overrides effective accessible registry key size is 95
2019-11-15 20:02:33,629 INFO [main] o.a.n.c.r.WriteAheadFlowFileRepository Initialized FlowFile Repository using 256 partitions
2019-11-15 20:02:33,768 INFO [main] o.a.n.p.store.WriteAheadStorePartition After recovering ./provenance_repository, next Event ID to be generated will be 148085136
2019-11-15 20:02:33,835 WARN [main] o.a.n.p.index.lucene.LuceneEventIndex Lucene Index ./provenance_repository/index-1573685499416 could not be opened. Assuming that index is defunct and will re-index events belonging to this index.
2019-11-15 20:02:33,835 INFO [main] o.a.n.p.index.lucene.LuceneEventIndex Determined that Lucene Index Directory ./provenance_repository/index-1573685499416 is defunct. Will destroy and rebuild index
2019-11-15 20:02:33,839 INFO [main] o.a.n.p.index.lucene.LuceneEventIndex Will avoid re-indexing Provenance Events because the newest index is defunct, so it will be re-indexed in the background
2019-11-15 20:02:33,839 INFO [main] o.a.n.p.WriteAheadProvenanceRepository Provenance Event Index indicates that no events should be re-indexed upon startup. Will not wait for re-indexing to occur.
2019-11-15 20:02:33,840 INFO [main] o.a.n.c.repository.FileSystemRepository Maximum Threshold for Container default set to 35101377658 bytes; if volume exceeds this size, archived data will be deleted until it no longer exceeds this size
2019-11-15 20:02:33,842 INFO [main] o.a.n.c.repository.FileSystemRepository Initializing FileSystemRepository with 'Always Sync' set to false
2019-11-15 20:02:34,199 INFO [main] o.apache.nifi.controller.FlowController Checking if there is already a Cluster Coordinator Elected...
2019-11-15 20:02:34,328 INFO [main] org.apache.curator.utils.Compatibility Using emulated InjectSessionExpiration
2019-11-15 20:02:34,456 INFO [main] o.a.c.f.imps.CuratorFrameworkImpl Starting
2019-11-15 20:02:34,505 INFO [main] org.apache.zookeeper.common.X509Util Setting -D jdk.tls.rejectClientInitiatedRenegotiation=true to disable client-initiated TLS renegotiation
2019-11-15 20:02:34,547 INFO [main] org.apache.zookeeper.ClientCnxnSocket jute.maxbuffer value is 4194304 Bytes
2019-11-15 20:02:34,743 INFO [main] o.a.c.f.imps.CuratorFrameworkImpl Default schema
2019-11-15 20:02:34,983 INFO [main-EventThread] o.a.c.f.state.ConnectionStateManager State change: CONNECTED
2019-11-15 20:02:35,083 INFO [Curator-Framework-0] o.a.c.f.imps.CuratorFrameworkImpl backgroundOperationsLoop exiting
2019-11-15 20:02:35,219 INFO [main] o.apache.nifi.controller.FlowController It appears that no Cluster Coordinator has been Elected yet. Registering for Cluster Coordinator Role.
2019-11-15 20:02:35,220 INFO [main] o.a.n.c.l.e.CuratorLeaderElectionManager CuratorLeaderElectionManager[stopped=true] Registered new Leader Selector for role Cluster Coordinator; this node is an active participant in the election.
2019-11-15 20:02:35,223 INFO [main] o.a.c.f.imps.CuratorFrameworkImpl Starting
2019-11-15 20:02:35,236 INFO [main] org.apache.zookeeper.ClientCnxnSocket jute.maxbuffer value is 4194304 Bytes
2019-11-15 20:02:35,250 INFO [main] o.a.c.f.imps.CuratorFrameworkImpl Default schema
2019-11-15 20:02:35,257 INFO [main] o.a.n.c.l.e.CuratorLeaderElectionManager CuratorLeaderElectionManager[stopped=false] Registered new Leader Selector for role Cluster Coordinator; this node is an active participant in the election.
2019-11-15 20:02:35,257 INFO [main] o.a.n.c.l.e.CuratorLeaderElectionManager CuratorLeaderElectionManager[stopped=false] started
2019-11-15 20:02:35,257 INFO [main] o.a.n.c.c.h.AbstractHeartbeatMonitor Heartbeat Monitor started
2019-11-15 20:02:35,283 INFO [main-EventThread] o.a.c.f.state.ConnectionStateManager State change: CONNECTED
2019-11-15 20:02:35,290 INFO [Curator-ConnectionStateManager-0] o.a.n.c.l.e.CuratorLeaderElectionManager org.apache.nifi.controller.leader.election.CuratorLeaderElectionManager$ElectionListener@4d490d2c Connection State changed to CONNECTED
2019-11-15 20:02:35,565 INFO [main-EventThread] o.a.c.f.state.ConnectionStateManager State change: SUSPENDED
2019-11-15 20:02:35,568 INFO [Curator-ConnectionStateManager-0] o.a.n.c.l.e.CuratorLeaderElectionManager org.apache.nifi.controller.leader.election.CuratorLeaderElectionManager$ElectionListener@4d490d2c Connection State changed to SUSPENDED
2019-11-15 20:02:36,567 INFO [main-EventThread] o.a.c.f.state.ConnectionStateManager State change: RECONNECTED
2019-11-15 20:02:36,567 INFO [Curator-ConnectionStateManager-0] o.a.n.c.l.e.CuratorLeaderElectionManager org.apache.nifi.controller.leader.election.CuratorLeaderElectionManager$ElectionListener@4d490d2c Connection State changed to RECONNECTED
2019-11-15 20:02:36,680 INFO [main-EventThread] o.a.c.f.state.ConnectionStateManager State change: SUSPENDED
2019-11-15 20:02:36,691 INFO [Curator-ConnectionStateManager-0] o.a.n.c.l.e.CuratorLeaderElectionManager org.apache.nifi.controller.leader.election.CuratorLeaderElectionManager$ElectionListener@4d490d2c Connection State changed to SUSPENDED
2019-11-15 20:02:36,729 INFO [main-EventThread] o.a.c.f.state.ConnectionStateManager State change: RECONNECTED
2019-11-15 20:02:36,730 INFO [Curator-ConnectionStateManager-0] o.a.n.c.l.e.CuratorLeaderElectionManager org.apache.nifi.controller.leader.election.CuratorLeaderElectionManager$ElectionListener@4d490d2c Connection State changed to RECONNECTED
2019-11-15 20:02:36,859 INFO [main-EventThread] o.a.c.f.state.ConnectionStateManager State change: SUSPENDED

 

1 ACCEPTED SOLUTION

Mentor

@samarsimha 

Oh well and good, are you downloading Nifi 1.10.0 from https://nifi.apache.org/download.html  released just last week November 4th, 2019  according to the documentation you  MUST upgrade to zookeeper version 3.5.5  which is the recommended version.

I am sure if you align  zookeeper version to the documentation.

 

Task 6624 is automatic but the 6578 must be done manually 

[NIFI-6624] - Automatically migrate old embedded zookeeper.properties files to the new format

[NIFI-6578] - Upgrade zookeeper to 3.5.5

 

Hope that helps

 

 

View solution in original post

6 REPLIES 6

Explorer

Can anyone please help ? 

Mentor

@samarsimha 

 

The simplest answer I can give you if compatibility!  HDF/HDP/HCP are packaged applications that have undergone rigorous unitary tests are supposed to "work as"  that explains why you cannot upgrade ONLY a component and upgrade minor or Major released go through a battery of test and QA to ensure all the components work properly.

In your case Java 7 and 8 are to date the recommended versions the latter being the most preferred.  From the matrix link https://supportmatrix.hortonworks.com/   I filtered out the latest version of HDF and No HDP/HDF product has been certified against Java 11 as of now, that could change in the near future but it won't definitely be with your current version of Nifi  .
Nifi_java11.PNG

 

So the above could explain your dilemma. Do you have a special use case as to why you want to use Java 11? I am not sure whether Cloudera offers a workaround but if you bought support from Cloudera then you can open a ticket.

 

Happy hadooping

 

 

Explorer

Upgrading to Java 11 is a mandate across our ORG. I was able to compile ( On MAC with Java 11) and seems to be working fine. however see above issue when installing Nifi-1.10.0 with external zookeeper.

 

Mentor

@samarsimha 

Oh well and good, are you downloading Nifi 1.10.0 from https://nifi.apache.org/download.html  released just last week November 4th, 2019  according to the documentation you  MUST upgrade to zookeeper version 3.5.5  which is the recommended version.

I am sure if you align  zookeeper version to the documentation.

 

Task 6624 is automatic but the 6578 must be done manually 

[NIFI-6624] - Automatically migrate old embedded zookeeper.properties files to the new format

[NIFI-6578] - Upgrade zookeeper to 3.5.5

 

Hope that helps

 

 

Explorer

Thanks @Shelton , will give it a try and update here later.

Explorer

It is working fine now with 3.5.6 version of zookeeper