Support Questions

cjervis · ‎11-15-2019

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

Shelton · ‎11-18-2019

@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

samarsimha · ‎11-17-2019

Can anyone please help ?

Shelton · ‎11-17-2019

@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 .

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

samarsimha · ‎11-17-2019

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.

Shelton · ‎11-18-2019

@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

samarsimha · ‎11-18-2019

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

samarsimha · ‎11-25-2019

It is working fine now with 3.5.6 version of zookeeper

Cloudera Community

Support Questions

Nifi Zookeeper issues with Java 11 and Nifi-1.10.0