PutHiveQL and SelectHiveQL processors are stuck for a very long time [NiFi standalone 1.4.0]

[#1]

Hello,

We have a NiFi flow that performs several operations, out of which there are few 'milestones'.

1. Generate FlowFile

2. Get max ID from Hadoop table based on given query conditional query taken from SQL Server metastore

3. Extract results from SQL Server using select statement with injected max ID within its where clause

4. Put results to Hadoop table

I have noticed that after several executions the processors are stuck for a longer period of time and the only way to resume them is to stop the processor, stop NiFi, start NiFi and start the processor. Although it doesn't always work and even after restart processor is still stuck. Simple NiFi restart alsodoesn't always help. I asked our Hadoop admin to check how does it looks like on their side and it seems that all queries from NiFi are executed within 5s of their submission and there is nothing that hangs, while on NiFi it seems like the processor is still working for few hours.

Here's part of the log after starting PutHiveQL fresh after NiFi start and stop. There were 34 events in the queue waiting for PutHiveQL. It took around 30 minutes for first task to execute (even though the query took 3 seconds to execute in Hive). The remaining 33 in the query has been executed right after. Those were the exact same queries.

Log:

Spoiler

2020-02-24 01:02:50,613 INFO [NiFi Web Server-28] c.s.j.s.i.application.WebApplicationImpl Initiating Jersey application, version 'Jersey: 1.19 02/11/2015 03:25 AM'
2020-02-24 01:03:08,222 INFO [NiFi Web Server-30] o.a.n.c.s.StandardProcessScheduler Starting PutHiveQL[id=01681003-bc11-1fde-2d34-46c19ca843c1]
2020-02-24 01:03:08,250 INFO [StandardProcessScheduler Thread-7] o.a.n.c.s.TimerDrivenSchedulingAgent Scheduled PutHiveQL[id=01681003-bc11-1fde-2d34-46c19ca843c1] to run with 1 threads
2020-02-24 01:03:08,292 INFO [Timer-Driven Process Thread-4] o.a.nifi.dbcp.hive.HiveConnectionPool HiveConnectionPool[id=117a131a-1759-16f4-3aba-98232d474b5e] Simple Authentication
2020-02-24 01:03:08,332 INFO [Timer-Driven Process Thread-4] org.apache.hive.jdbc.Utils Supplied authorities: hadoop:10000
2020-02-24 01:03:08,332 INFO [Timer-Driven Process Thread-4] org.apache.hive.jdbc.Utils Resolved authority: hadoop:10000
2020-02-24 01:03:08,357 INFO [Timer-Driven Process Thread-4] org.apache.hive.jdbc.HiveConnection Will try to open client transport with JDBC Uri: jdbc:hive2://hadoop:10000/database_name?tez.queue.name=nifi
2020-02-24 01:03:10,842 INFO [Timer-Driven Process Thread-4] org.apache.hive.jdbc.Utils Supplied authorities: hadoop:10000
2020-02-24 01:03:10,842 INFO [Timer-Driven Process Thread-4] org.apache.hive.jdbc.Utils Resolved authority: hadoop:10000
2020-02-24 01:03:10,845 INFO [Timer-Driven Process Thread-4] org.apache.hive.jdbc.HiveConnection Will try to open client transport with JDBC Uri: jdbc:hive2://hadoop:10000/database_name?tez.queue.name=nifi
2020-02-24 01:03:12,146 INFO [Flow Service Tasks Thread-2] o.a.n.p.FlowConfigurationArchiveManager Removing old archive file /opt/nifi-1.4.0/reso_conf/flow_archive/20200204T040527-0800_flow.xml.gz to reduce storage usage. currentSize=521922168
2020-02-24 01:03:12,150 INFO [Flow Service Tasks Thread-2] o.a.nifi.controller.StandardFlowService Saved flow controller org.apache.nifi.controller.FlowController@1cd1b498 // Another save pending = false
2020-02-24 01:04:07,076 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@10664c3d checkpointed with 469 Records and 0 Swap Files in 7 milliseconds (Stop-the-world time = 2 milliseconds, Clear Edit Logs time = 2 millis), max Transaction ID 1758
2020-02-24 01:04:29,999 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2020-02-24 01:04:30,123 INFO [pool-10-thread-1] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@6dcf7c49 checkpointed with 352 Records and 0 Swap Files in 123 milliseconds (Stop-the-world time = 62 milliseconds, Clear Edit Logs time = 38 millis), max Transaction ID 242421931471
2020-02-24 01:04:30,124 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 352 records in 124 milliseconds
2020-02-24 01:06:07,083 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@10664c3d checkpointed with 469 Records and 0 Swap Files in 6 milliseconds (Stop-the-world time = 2 milliseconds, Clear Edit Logs time = 2 millis), max Transaction ID 1758
2020-02-24 01:06:30,124 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2020-02-24 01:06:30,257 INFO [pool-10-thread-1] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@6dcf7c49 checkpointed with 352 Records and 0 Swap Files in 132 milliseconds (Stop-the-world time = 65 milliseconds, Clear Edit Logs time = 42 millis), max Transaction ID 242421931471
2020-02-24 01:06:30,257 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 352 records in 132 milliseconds
2020-02-24 01:08:07,090 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@10664c3d checkpointed with 469 Records and 0 Swap Files in 6 milliseconds (Stop-the-world time = 2 milliseconds, Clear Edit Logs time = 2 millis), max Transaction ID 1758
2020-02-24 01:08:30,258 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2020-02-24 01:08:30,386 INFO [pool-10-thread-1] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@6dcf7c49 checkpointed with 352 Records and 0 Swap Files in 127 milliseconds (Stop-the-world time = 58 milliseconds, Clear Edit Logs time = 41 millis), max Transaction ID 242421931471
2020-02-24 01:08:30,386 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 352 records in 128 milliseconds
2020-02-24 01:10:07,097 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@10664c3d checkpointed with 469 Records and 0 Swap Files in 6 milliseconds (Stop-the-world time = 2 milliseconds, Clear Edit Logs time = 2 millis), max Transaction ID 1758
2020-02-24 01:10:30,386 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2020-02-24 01:10:30,513 INFO [pool-10-thread-1] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@6dcf7c49 checkpointed with 352 Records and 0 Swap Files in 126 milliseconds (Stop-the-world time = 58 milliseconds, Clear Edit Logs time = 41 millis), max Transaction ID 242421931471
2020-02-24 01:10:30,513 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 352 records in 126 milliseconds
2020-02-24 01:12:07,105 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@10664c3d checkpointed with 469 Records and 0 Swap Files in 6 milliseconds (Stop-the-world time = 3 milliseconds, Clear Edit Logs time = 2 millis), max Transaction ID 1758
2020-02-24 01:12:30,513 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2020-02-24 01:12:30,639 INFO [pool-10-thread-1] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@6dcf7c49 checkpointed with 352 Records and 0 Swap Files in 125 milliseconds (Stop-the-world time = 57 milliseconds, Clear Edit Logs time = 41 millis), max Transaction ID 242421931471
2020-02-24 01:12:30,639 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 352 records in 125 milliseconds
2020-02-24 01:14:07,112 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@10664c3d checkpointed with 469 Records and 0 Swap Files in 6 milliseconds (Stop-the-world time = 2 milliseconds, Clear Edit Logs time = 2 millis), max Transaction ID 1758
2020-02-24 01:14:30,639 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2020-02-24 01:14:30,756 INFO [pool-10-thread-1] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@6dcf7c49 checkpointed with 352 Records and 0 Swap Files in 116 milliseconds (Stop-the-world time = 55 milliseconds, Clear Edit Logs time = 38 millis), max Transaction ID 242421931471
2020-02-24 01:14:30,756 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 352 records in 116 milliseconds
2020-02-24 01:16:07,119 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@10664c3d checkpointed with 469 Records and 0 Swap Files in 6 milliseconds (Stop-the-world time = 2 milliseconds, Clear Edit Logs time = 2 millis), max Transaction ID 1758
2020-02-24 01:16:30,756 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2020-02-24 01:16:30,885 INFO [pool-10-thread-1] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@6dcf7c49 checkpointed with 352 Records and 0 Swap Files in 128 milliseconds (Stop-the-world time = 59 milliseconds, Clear Edit Logs time = 42 millis), max Transaction ID 242421931471
2020-02-24 01:16:30,885 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 352 records in 128 milliseconds
2020-02-24 01:18:07,126 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@10664c3d checkpointed with 469 Records and 0 Swap Files in 6 milliseconds (Stop-the-world time = 2 milliseconds, Clear Edit Logs time = 2 millis), max Transaction ID 1758
2020-02-24 01:18:30,885 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2020-02-24 01:18:31,000 INFO [pool-10-thread-1] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@6dcf7c49 checkpointed with 352 Records and 0 Swap Files in 115 milliseconds (Stop-the-world time = 58 milliseconds, Clear Edit Logs time = 36 millis), max Transaction ID 242421931471
2020-02-24 01:18:31,000 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 352 records in 115 milliseconds
2020-02-24 01:20:07,132 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@10664c3d checkpointed with 469 Records and 0 Swap Files in 6 milliseconds (Stop-the-world time = 2 milliseconds, Clear Edit Logs time = 2 millis), max Transaction ID 1758
2020-02-24 01:20:31,001 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2020-02-24 01:20:31,116 INFO [pool-10-thread-1] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@6dcf7c49 checkpointed with 352 Records and 0 Swap Files in 115 milliseconds (Stop-the-world time = 58 milliseconds, Clear Edit Logs time = 37 millis), max Transaction ID 242421931471
2020-02-24 01:20:31,116 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 352 records in 115 milliseconds
2020-02-24 01:22:07,139 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@10664c3d checkpointed with 469 Records and 0 Swap Files in 6 milliseconds (Stop-the-world time = 2 milliseconds, Clear Edit Logs time = 2 millis), max Transaction ID 1758
2020-02-24 01:22:31,117 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2020-02-24 01:22:31,235 INFO [pool-10-thread-1] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@6dcf7c49 checkpointed with 352 Records and 0 Swap Files in 118 milliseconds (Stop-the-world time = 61 milliseconds, Clear Edit Logs time = 36 millis), max Transaction ID 242421931471
2020-02-24 01:22:31,236 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 352 records in 118 milliseconds
2020-02-24 01:24:07,146 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@10664c3d checkpointed with 469 Records and 0 Swap Files in 6 milliseconds (Stop-the-world time = 2 milliseconds, Clear Edit Logs time = 2 millis), max Transaction ID 1758
2020-02-24 01:24:31,236 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2020-02-24 01:24:31,354 INFO [pool-10-thread-1] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@6dcf7c49 checkpointed with 352 Records and 0 Swap Files in 117 milliseconds (Stop-the-world time = 60 milliseconds, Clear Edit Logs time = 36 millis), max Transaction ID 242421931471
2020-02-24 01:24:31,354 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 352 records in 117 milliseconds
2020-02-24 01:26:07,152 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@10664c3d checkpointed with 469 Records and 0 Swap Files in 6 milliseconds (Stop-the-world time = 2 milliseconds, Clear Edit Logs time = 2 millis), max Transaction ID 1758
2020-02-24 01:26:31,354 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2020-02-24 01:26:31,472 INFO [pool-10-thread-1] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@6dcf7c49 checkpointed with 352 Records and 0 Swap Files in 117 milliseconds (Stop-the-world time = 60 milliseconds, Clear Edit Logs time = 36 millis), max Transaction ID 242421931471
2020-02-24 01:26:31,472 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 352 records in 118 milliseconds
2020-02-24 01:28:07,159 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@10664c3d checkpointed with 469 Records and 0 Swap Files in 6 milliseconds (Stop-the-world time = 2 milliseconds, Clear Edit Logs time = 2 millis), max Transaction ID 1758
2020-02-24 01:28:31,472 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2020-02-24 01:28:31,591 INFO [pool-10-thread-1] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@6dcf7c49 checkpointed with 352 Records and 0 Swap Files in 118 milliseconds (Stop-the-world time = 55 milliseconds, Clear Edit Logs time = 41 millis), max Transaction ID 242421931471
2020-02-24 01:28:31,591 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 352 records in 118 milliseconds
2020-02-24 01:30:07,167 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@10664c3d checkpointed with 469 Records and 0 Swap Files in 7 milliseconds (Stop-the-world time = 2 milliseconds, Clear Edit Logs time = 2 millis), max Transaction ID 1758
2020-02-24 01:30:31,591 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2020-02-24 01:30:31,719 INFO [pool-10-thread-1] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@6dcf7c49 checkpointed with 352 Records and 0 Swap Files in 127 milliseconds (Stop-the-world time = 58 milliseconds, Clear Edit Logs time = 42 millis), max Transaction ID 242421931471
2020-02-24 01:30:31,719 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 352 records in 127 milliseconds
2020-02-24 01:32:07,175 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@10664c3d checkpointed with 469 Records and 0 Swap Files in 7 milliseconds (Stop-the-world time = 3 milliseconds, Clear Edit Logs time = 2 millis), max Transaction ID 1758
2020-02-24 01:32:31,719 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2020-02-24 01:32:31,841 INFO [pool-10-thread-1] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@6dcf7c49 checkpointed with 352 Records and 0 Swap Files in 121 milliseconds (Stop-the-world time = 58 milliseconds, Clear Edit Logs time = 39 millis), max Transaction ID 242421931471
2020-02-24 01:32:31,841 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 352 records in 121 milliseconds
2020-02-24 01:34:07,183 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@10664c3d checkpointed with 469 Records and 0 Swap Files in 7 milliseconds (Stop-the-world time = 3 milliseconds, Clear Edit Logs time = 2 millis), max Transaction ID 1758
2020-02-24 01:34:31,841 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2020-02-24 01:34:31,960 INFO [pool-10-thread-1] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@6dcf7c49 checkpointed with 352 Records and 0 Swap Files in 118 milliseconds (Stop-the-world time = 56 milliseconds, Clear Edit Logs time = 39 millis), max Transaction ID 242421931471
2020-02-24 01:34:31,960 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 352 records in 118 milliseconds
2020-02-24 01:36:07,191 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@10664c3d checkpointed with 469 Records and 0 Swap Files in 7 milliseconds (Stop-the-world time = 3 milliseconds, Clear Edit Logs time = 2 millis), max Transaction ID 1758
2020-02-24 01:36:31,960 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2020-02-24 01:36:32,083 INFO [pool-10-thread-1] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@6dcf7c49 checkpointed with 352 Records and 0 Swap Files in 122 milliseconds (Stop-the-world time = 57 milliseconds, Clear Edit Logs time = 41 millis), max Transaction ID 242421931471
2020-02-24 01:36:32,083 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 352 records in 122 milliseconds
2020-02-24 01:38:06,925 INFO [Provenance Maintenance Thread-1] o.a.n.p.PersistentProvenanceRepository Created new Provenance Event Writers for events starting with ID 1082224466
2020-02-24 01:38:07,116 INFO [Provenance Repository Rollover Thread-1] o.a.n.p.lucene.SimpleIndexManager Index Writer for /repos_nifi/repo_prov/index-1582461095000 has been returned to Index Manager and is no longer in use. Closing Index Writer
2020-02-24 01:38:07,119 INFO [Provenance Repository Rollover Thread-1] o.a.n.p.PersistentProvenanceRepository Successfully merged 16 journal files (1 records) into single Provenance Log File /repos_nifi/repo_prov/1082224465.prov in 199 milliseconds
2020-02-24 01:38:07,120 INFO [Provenance Repository Rollover Thread-1] o.a.n.p.PersistentProvenanceRepository Successfully Rolled over Provenance Event file containing 1 records. In the past 5 minutes, 1 events have been written to the Provenance Repository, totaling 6.2 KB
2020-02-24 01:38:07,198 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@10664c3d checkpointed with 469 Records and 0 Swap Files in 6 milliseconds (Stop-the-world time = 3 milliseconds, Clear Edit Logs time = 2 millis), max Transaction ID 1758
2020-02-24 01:38:32,083 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2020-02-24 01:38:32,208 INFO [pool-10-thread-1] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@6dcf7c49 checkpointed with 352 Records and 0 Swap Files in 124 milliseconds (Stop-the-world time = 60 milliseconds, Clear Edit Logs time = 39 millis), max Transaction ID 242421931471
2020-02-24 01:38:32,209 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 352 records in 125 milliseconds
2020-02-24 01:38:46,937 INFO [Provenance Maintenance Thread-3] o.a.n.p.PersistentProvenanceRepository Created new Provenance Event Writers for events starting with ID 1082224470
2020-02-24 01:38:46,971 INFO [Provenance Repository Rollover Thread-1] o.a.n.p.lucene.SimpleIndexManager Index Writer for /repos_nifi/repo_prov/index-1582461095000 has been returned to Index Manager and is no longer in use. Closing Index Writer
2020-02-24 01:38:46,974 INFO [Provenance Repository Rollover Thread-1] o.a.n.p.PersistentProvenanceRepository Successfully merged 16 journal files (4 records) into single Provenance Log File /repos_nifi/repo_prov/1082224466.prov in 42 milliseconds
2020-02-24 01:38:46,974 INFO [Provenance Repository Rollover Thread-1] o.a.n.p.PersistentProvenanceRepository Successfully Rolled over Provenance Event file containing 4 records. In the past 5 minutes, 5 events have been written to the Provenance Repository, totaling 26.34 KB
2020-02-24 01:39:16,947 INFO [Provenance Maintenance Thread-1] o.a.n.p.PersistentProvenanceRepository Created new Provenance Event Writers for events starting with ID 1082224473
2020-02-24 01:39:16,995 INFO [Provenance Repository Rollover Thread-2] o.a.n.p.lucene.SimpleIndexManager Index Writer for /repos_nifi/repo_prov/index-1582461095000 has been returned to Index Manager and is no longer in use. Closing Index Writer
2020-02-24 01:39:16,998 INFO [Provenance Repository Rollover Thread-2] o.a.n.p.PersistentProvenanceRepository Successfully merged 16 journal files (3 records) into single Provenance Log File /repos_nifi/repo_prov/1082224470.prov in 55 milliseconds
2020-02-24 01:39:16,998 INFO [Provenance Repository Rollover Thread-2] o.a.n.p.PersistentProvenanceRepository Successfully Rolled over Provenance Event file containing 3 records. In the past 5 minutes, 8 events have been written to the Provenance Repository, totaling 43.97 KB
2020-02-24 01:39:46,962 INFO [Provenance Maintenance Thread-2] o.a.n.p.PersistentProvenanceRepository Created new Provenance Event Writers for events starting with ID 1082224476
2020-02-24 01:39:46,998 INFO [Provenance Repository Rollover Thread-1] o.a.n.p.lucene.SimpleIndexManager Index Writer for /repos_nifi/repo_prov/index-1582461095000 has been returned to Index Manager and is no longer in use. Closing Index Writer
2020-02-24 01:39:47,001 INFO [Provenance Repository Rollover Thread-1] o.a.n.p.PersistentProvenanceRepository Successfully merged 16 journal files (3 records) into single Provenance Log File /repos_nifi/repo_prov/1082224473.prov in 43 milliseconds
2020-02-24 01:39:47,001 INFO [Provenance Repository Rollover Thread-1] o.a.n.p.PersistentProvenanceRepository Successfully Rolled over Provenance Event file containing 3 records. In the past 5 minutes, 11 events have been written to the Provenance Repository, totaling 61.65 KB
2020-02-24 01:40:07,205 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@10664c3d checkpointed with 469 Records and 0 Swap Files in 6 milliseconds (Stop-the-world time = 2 milliseconds, Clear Edit Logs time = 2 millis), max Transaction ID 1758
2020-02-24 01:40:26,969 INFO [Provenance Maintenance Thread-2] o.a.n.p.PersistentProvenanceRepository Created new Provenance Event Writers for events starting with ID 1082224483
2020-02-24 01:40:27,008 INFO [Provenance Repository Rollover Thread-2] o.a.n.p.lucene.SimpleIndexManager Index Writer for /repos_nifi/repo_prov/index-1582461095000 has been returned to Index Manager and is no longer in use. Closing Index Writer
2020-02-24 01:40:27,196 INFO [Provenance Repository Rollover Thread-2] o.a.n.p.PersistentProvenanceRepository Successfully merged 16 journal files (7 records) into single Provenance Log File /repos_nifi/repo_prov/1082224476.prov in 230 milliseconds
2020-02-24 01:40:27,196 INFO [Provenance Repository Rollover Thread-2] o.a.n.p.PersistentProvenanceRepository Successfully Rolled over Provenance Event file containing 7 records. In the past 5 minutes, 18 events have been written to the Provenance Repository, totaling 96.96 KB
2020-02-24 01:40:32,209 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2020-02-24 01:40:32,328 INFO [pool-10-thread-1] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@6dcf7c49 checkpointed with 352 Records and 0 Swap Files in 118 milliseconds (Stop-the-world time = 63 milliseconds, Clear Edit Logs time = 35 millis), max Transaction ID 242421931471
2020-02-24 01:40:32,328 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 352 records in 118 milliseconds
2020-02-24 01:41:06,985 INFO [Provenance Maintenance Thread-3] o.a.n.p.PersistentProvenanceRepository Created new Provenance Event Writers for events starting with ID 1082224486
2020-02-24 01:41:07,013 INFO [Provenance Repository Rollover Thread-1] o.a.n.p.lucene.SimpleIndexManager Index Writer for /repos_nifi/repo_prov/index-1582461095000 has been returned to Index Manager and is no longer in use. Closing Index Writer
2020-02-24 01:41:07,016 INFO [Provenance Repository Rollover Thread-1] o.a.n.p.PersistentProvenanceRepository Successfully merged 16 journal files (3 records) into single Provenance Log File /repos_nifi/repo_prov/1082224483.prov in 35 milliseconds
2020-02-24 01:41:07,016 INFO [Provenance Repository Rollover Thread-1] o.a.n.p.PersistentProvenanceRepository Successfully Rolled over Provenance Event file containing 3 records. In the past 5 minutes, 21 events have been written to the Provenance Repository, totaling 115.16 KB
2020-02-24 01:41:46,992 INFO [Provenance Maintenance Thread-3] o.a.n.p.PersistentProvenanceRepository Created new Provenance Event Writers for events starting with ID 1082224489
2020-02-24 01:41:47,019 INFO [Provenance Repository Rollover Thread-2] o.a.n.p.lucene.SimpleIndexManager Index Writer for /repos_nifi/repo_prov/index-1582461095000 has been returned to Index Manager and is no longer in use. Closing Index Writer
2020-02-24 01:41:47,023 INFO [Provenance Repository Rollover Thread-2] o.a.n.p.PersistentProvenanceRepository Successfully merged 16 journal files (3 records) into single Provenance Log File /repos_nifi/repo_prov/1082224486.prov in 36 milliseconds
2020-02-24 01:41:47,024 INFO [Provenance Repository Rollover Thread-2] o.a.n.p.PersistentProvenanceRepository Successfully Rolled over Provenance Event file containing 3 records. In the past 5 minutes, 24 events have been written to the Provenance Repository, totaling 133.87 KB
2020-02-24 01:42:07,212 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@10664c3d checkpointed with 469 Records and 0 Swap Files in 6 milliseconds (Stop-the-world time = 2 milliseconds, Clear Edit Logs time = 2 millis), max Transaction ID 1758
2020-02-24 01:42:17,009 INFO [Provenance Maintenance Thread-2] o.a.n.p.PersistentProvenanceRepository Created new Provenance Event Writers for events starting with ID 1082224491
2020-02-24 01:42:17,038 INFO [Provenance Repository Rollover Thread-1] o.a.n.p.lucene.SimpleIndexManager Index Writer for /repos_nifi/repo_prov/index-1582461095000 has been returned to Index Manager and is no longer in use. Closing Index Writer
2020-02-24 01:42:17,041 INFO [Provenance Repository Rollover Thread-1] o.a.n.p.PersistentProvenanceRepository Successfully merged 16 journal files (2 records) into single Provenance Log File /repos_nifi/repo_prov/1082224489.prov in 36 milliseconds
2020-02-24 01:42:17,041 INFO [Provenance Repository Rollover Thread-1] o.a.n.p.PersistentProvenanceRepository Successfully Rolled over Provenance Event file containing 2 records. In the past 5 minutes, 26 events have been written to the Provenance Repository, totaling 144.67 KB
2020-02-24 01:42:32,328 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2020-02-24 01:42:32,441 INFO [pool-10-thread-1] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@6dcf7c49 checkpointed with 352 Records and 0 Swap Files in 112 milliseconds (Stop-the-world time = 57 milliseconds, Clear Edit Logs time = 35 millis), max Transaction ID 242421931471
2020-02-24 01:42:32,441 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 352 records in 112 milliseconds
2020-02-24 01:42:57,022 INFO [Provenance Maintenance Thread-1] o.a.n.p.PersistentProvenanceRepository Created new Provenance Event Writers for events starting with ID 1082224495
2020-02-24 01:42:57,047 INFO [Provenance Repository Rollover Thread-2] o.a.n.p.lucene.SimpleIndexManager Index Writer for /repos_nifi/repo_prov/index-1582461095000 has been returned to Index Manager and is no longer in use. Closing Index Writer
2020-02-24 01:42:57,050 INFO [Provenance Repository Rollover Thread-2] o.a.n.p.PersistentProvenanceRepository Successfully merged 16 journal files (4 records) into single Provenance Log File /repos_nifi/repo_prov/1082224491.prov in 32 milliseconds
2020-02-24 01:42:57,050 INFO [Provenance Repository Rollover Thread-2] o.a.n.p.PersistentProvenanceRepository Successfully Rolled over Provenance Event file containing 4 records. In the past 5 minutes, 30 events have been written to the Provenance Repository, totaling 166.65 KB
2020-02-24 01:43:37,031 INFO [Provenance Maintenance Thread-2] o.a.n.p.PersistentProvenanceRepository Created new Provenance Event Writers for events starting with ID 1082224499
2020-02-24 01:43:37,060 INFO [Provenance Repository Rollover Thread-1] o.a.n.p.lucene.SimpleIndexManager Index Writer for /repos_nifi/repo_prov/index-1582461095000 has been returned to Index Manager and is no longer in use. Closing Index Writer
2020-02-24 01:43:37,084 INFO [Provenance Repository Rollover Thread-1] o.a.n.p.PersistentProvenanceRepository Successfully merged 16 journal files (4 records) into single Provenance Log File /repos_nifi/repo_prov/1082224495.prov in 57 milliseconds
2020-02-24 01:43:37,085 INFO [Provenance Repository Rollover Thread-1] o.a.n.p.PersistentProvenanceRepository Successfully Rolled over Provenance Event file containing 5 records. In the past 5 minutes, 30 events have been written to the Provenance Repository, totaling 164.63 KB
2020-02-24 01:44:07,219 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@10664c3d checkpointed with 469 Records and 0 Swap Files in 6 milliseconds (Stop-the-world time = 2 milliseconds, Clear Edit Logs time = 1 millis), max Transaction ID 1758
2020-02-24 01:44:32,441 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2020-02-24 01:44:32,561 INFO [pool-10-thread-1] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@6dcf7c49 checkpointed with 352 Records and 0 Swap Files in 119 milliseconds (Stop-the-world time = 58 milliseconds, Clear Edit Logs time = 37 millis), max Transaction ID 242421931472
2020-02-24 01:44:32,561 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 352 records in 119 milliseconds
2020-02-24 01:46:07,225 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@10664c3d checkpointed with 469 Records and 0 Swap Files in 6 milliseconds (Stop-the-world time = 2 milliseconds, Clear Edit Logs time = 1 millis), max Transaction ID 1758
2020-02-24 01:46:32,561 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2020-02-24 01:46:32,682 INFO [pool-10-thread-1] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@6dcf7c49 checkpointed with 352 Records and 0 Swap Files in 120 milliseconds (Stop-the-world time = 60 milliseconds, Clear Edit Logs time = 38 millis), max Transaction ID 242421931472
2020-02-24 01:46:32,683 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 352 records in 121 milliseconds
2020-02-24 01:48:07,232 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@10664c3d checkpointed with 469 Records and 0 Swap Files in 5 milliseconds (Stop-the-world time = 2 milliseconds, Clear Edit Logs time = 2 millis), max Transaction ID 1758
2020-02-24 01:48:32,683 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2020-02-24 01:48:32,792 INFO [pool-10-thread-1] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@6dcf7c49 checkpointed with 352 Records and 0 Swap Files in 109 milliseconds (Stop-the-world time = 51 milliseconds, Clear Edit Logs time = 37 millis), max Transaction ID 242421931472
2020-02-24 01:48:32,792 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 352 records in 109 milliseconds
2020-02-24 01:50:07,238 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@10664c3d checkpointed with 469 Records and 0 Swap Files in 6 milliseconds (Stop-the-world time = 2 milliseconds, Clear Edit Logs time = 2 millis), max Transaction ID 1758
2020-02-24 01:50:32,792 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2020-02-24 01:50:32,915 INFO [pool-10-thread-1] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@6dcf7c49 checkpointed with 352 Records and 0 Swap Files in 122 milliseconds (Stop-the-world time = 57 milliseconds, Clear Edit Logs time = 38 millis), max Transaction ID 242421931472
2020-02-24 01:50:32,916 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 352 records in 123 milliseconds
2020-02-24 01:52:07,246 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@10664c3d checkpointed with 469 Records and 0 Swap Files in 6 milliseconds (Stop-the-world time = 2 milliseconds, Clear Edit Logs time = 2 millis), max Transaction ID 1758
2020-02-24 01:52:32,916 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2020-02-24 01:52:33,028 INFO [pool-10-thread-1] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@6dcf7c49 checkpointed with 352 Records and 0 Swap Files in 111 milliseconds (Stop-the-world time = 52 milliseconds, Clear Edit Logs time = 36 millis), max Transaction ID 242421931472
2020-02-24 01:52:33,028 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 352 records in 111 milliseconds
2020-02-24 01:54:07,253 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@10664c3d checkpointed with 469 Records and 0 Swap Files in 6 milliseconds (Stop-the-world time = 2 milliseconds, Clear Edit Logs time = 2 millis), max Transaction ID 1758
2020-02-24 01:54:33,028 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2020-02-24 01:54:33,145 INFO [pool-10-thread-1] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@6dcf7c49 checkpointed with 352 Records and 0 Swap Files in 116 milliseconds (Stop-the-world time = 53 milliseconds, Clear Edit Logs time = 40 millis), max Transaction ID 242421931472
2020-02-24 01:54:33,146 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 352 records in 117 milliseconds
2020-02-24 01:56:07,260 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@10664c3d checkpointed with 469 Records and 0 Swap Files in 6 milliseconds (Stop-the-world time = 2 milliseconds, Clear Edit Logs time = 2 millis), max Transaction ID 1758
2020-02-24 01:56:33,146 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2020-02-24 01:56:33,269 INFO [pool-10-thread-1] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@6dcf7c49 checkpointed with 352 Records and 0 Swap Files in 123 milliseconds (Stop-the-world time = 60 milliseconds, Clear Edit Logs time = 38 millis), max Transaction ID 242421931472
2020-02-24 01:56:33,270 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 352 records in 123 milliseconds
2020-02-24 01:58:07,267 INFO [Write-Ahead Local State Provider Maintenance] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@10664c3d checkpointed with 469 Records and 0 Swap Files in 7 milliseconds (Stop-the-world time = 2 milliseconds, Clear Edit Logs time = 2 millis), max Transaction ID 1758
2020-02-24 01:58:33,270 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Initiating checkpoint of FlowFile Repository
2020-02-24 01:58:33,389 INFO [pool-10-thread-1] org.wali.MinimalLockingWriteAheadLog org.wali.MinimalLockingWriteAheadLog@6dcf7c49 checkpointed with 352 Records and 0 Swap Files in 119 milliseconds (Stop-the-world time = 57 milliseconds, Clear Edit Logs time = 37 millis), max Transaction ID 242421931472
2020-02-24 01:58:33,389 INFO [pool-10-thread-1] o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile Repository with 352 records in 119 milliseconds

[#2]

@PPB

I am also facing the same issue with NiFi 1.8.0.

Did you get any solution for this issue?

Thanks & Regards,
R.Rohit

[#3]

Hi...i see it could be below reasons for your problem : 

1. How much data are you selecting in selecthiveql? You need to understand that nifi has its own repository, so when you run a select query, it is not only executed but the data is actually transported to the repository. So, even though the query is executed in a couple of seconds, depending on the amount of data and your network speed, it can take anywhere between minutes to hours for the data to be transported. If you restart nifi, it will hard stop the processor and it will resume from start after restart. So, that will not help you anyway.

2. Puthiveql has a batch size property that is commits. The smaller the batch the more hive has to process and commit. You should increase the batch size, since Hive is built for bulk batch insert and fetch. Optimizing the batch size would help a lot.

Try a small fetch say a couple of hundred rows and see if Nifi is still stuck for hours. It should ideally be done in a couple of minutes assuming your network speed is strong.

Hope this helps. If the comment helps you to find a solution or move forward, please accept it as a solution for other community members.

[#4]

@Rohitravi  If this has helped please comment accordingly so that @PPB can mark this as a solution for other community members.