[
https://issues.apache.org/jira/browse/NIFI-6110?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16787976#comment-16787976
]
ASF subversion and git services commented on NIFI-6110:
-------------------------------------------------------
Commit 58a25cfa5a9b9e4af9a5e9b7e5c3be9a676d8e87 in nifi's branch
refs/heads/master from Mark Payne
[ https://gitbox.apache.org/repos/asf?p=nifi.git;h=58a25cf ]
NIFI-6110: Updated StandardProcessSession such that if we fail to update the
FlowFile Repository, we do not decrement claimant counts for any FlowFiles that
were removed. Doing so can cause an issue where a FlowFile is removed, then the
FlowFileRepo update fails, resulting in the flowfile being rolled back, but
after its claimant count is decremented. It will then be processed again, which
can result in the same thing, and we'll end up decrementing the claimant count
repeatedly. Also updated LengthDelimitedJournal so that if the overflow
directory already exists, it does not fail when trying to create the directory
and instead just moves on. Updated unit tests to test both of these new fixes
and updated DummyRecordSerde to be thread-safe because the
TestLengthDelimitedJournal now needs it to be thread safe due to the new unit
test that was added.
This closes #3358.
Signed-off-by: Bryan Bende <[email protected]>
> FlowFile Repository can fail to update
> --------------------------------------
>
> Key: NIFI-6110
> URL: https://issues.apache.org/jira/browse/NIFI-6110
> Project: Apache NiFi
> Issue Type: Bug
> Components: Core Framework
> Reporter: Mark Payne
> Assignee: Mark Payne
> Priority: Blocker
> Fix For: 1.10.0
>
> Time Spent: 0.5h
> Remaining Estimate: 0h
>
> The following errors were reported on the mailing list:
>
> 2019-03-06 14:33:20,305 ERROR [Timer-Driven Process Thread-47]
> o.a.n.c.r.StandardProcessSession Failed to commit session
> org.apache.nifi.processor.exception.ProcessException: FlowFile Repository
> failed to update. Will roll back.
> 2019-03-06 14:33:20,306 ERROR [Timer-Driven Process Thread-47]
> o.a.n.processors.standard.ConvertRecord
> ConvertRecord[id=32781c92-fab3-34de-b1ff-6138f8788701] Failed to commit
> session StandardProcessSession[id=244416156] due to
> org.apache.nifi.processor.exception.ProcessException: FlowFile Repository
> failed to update; rolling back:
> org.apache.nifi.processor.exception.ProcessException: FlowFile Repository
> failed to update
> org.apache.nifi.processor.exception.ProcessException: FlowFile Repository
> failed to update
> at
> org.apache.nifi.controller.repository.StandardProcessSession.commit(StandardProcessSession.java:413)
> at
> org.apache.nifi.controller.repository.StandardProcessSession.commit(StandardProcessSession.java:343)
> at
> org.apache.nifi.controller.tasks.ConnectableTask.invoke(ConnectableTask.java:256)
> at
> org.apache.nifi.controller.scheduling.TimerDrivenSchedulingAgent$1.run(TimerDrivenSchedulingAgent.java:117)
> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
> at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> at java.lang.Thread.run(Thread.java:748)
> Caused by: java.nio.file.FileAlreadyExistsException:
> /flowfile_repo/nifi-1.9.0/journals/overflow-874061
> at sun.nio.fs.UnixException.translateToIOException(UnixException.java:88)
> at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:102)
> at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:107)
> at
> sun.nio.fs.UnixFileSystemProvider.createDirectory(UnixFileSystemProvider.java:384)
> at java.nio.file.Files.createDirectory(Files.java:674)
> at
> org.apache.nifi.wali.LengthDelimitedJournal.update(LengthDelimitedJournal.java:249)
> at
> org.apache.nifi.wali.SequentialAccessWriteAheadLog.update(SequentialAccessWriteAheadLog.java:123)
> at
> org.apache.nifi.controller.repository.WriteAheadFlowFileRepository.updateRepository(WriteAheadFlowFileRepository.java:309)
> at
> org.apache.nifi.controller.repository.WriteAheadFlowFileRepository.updateRepository(WriteAheadFlowFileRepository.java:259)
> at
> org.apache.nifi.controller.repository.StandardProcessSession.commit(StandardProcessSession.java:407)
> ... 10 common frames omitted
> 2019-03-06 14:33:20,337 ERROR [Timer-Driven Process Thread-53]
> o.a.n.c.r.StandardProcessSession Failed to commit session
> org.apache.nifi.processor.exception.ProcessException: FlowFile Repository
> failed to update. Will roll back.
> 2019-03-06 14:33:20,337 ERROR [Timer-Driven Process Thread-53]
> o.a.n.processors.standard.ConvertRecord
> ConvertRecord[id=32781c92-fab3-34de-b1ff-6138f8788701] Failed to commit
> session StandardProcessSession[id=244415981] due to
> org.apache.nifi.processor.exception.ProcessException: FlowFile Repository
> failed to update; rolling back:
> org.apache.nifi.processor.exception.ProcessException: FlowFile Repository
> failed to update
> org.apache.nifi.processor.exception.ProcessException: FlowFile Repository
> failed to update
> at
> org.apache.nifi.controller.repository.StandardProcessSession.commit(StandardProcessSession.java:413)
> at
> org.apache.nifi.controller.repository.StandardProcessSession.commit(StandardProcessSession.java:343)
> at
> org.apache.nifi.controller.tasks.ConnectableTask.invoke(ConnectableTask.java:256)
> at
> org.apache.nifi.controller.scheduling.TimerDrivenSchedulingAgent$1.run(TimerDrivenSchedulingAgent.java:117)
> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
> at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> at java.lang.Thread.run(Thread.java:748)
> Caused by: java.io.IOException: Stream Closed
> at java.io.FileOutputStream.writeBytes(Native Method)
> at java.io.FileOutputStream.write(FileOutputStream.java:326)
> at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
> at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
> at
> org.apache.nifi.wali.LengthDelimitedJournal.update(LengthDelimitedJournal.java:308)
> at
> org.apache.nifi.wali.SequentialAccessWriteAheadLog.update(SequentialAccessWriteAheadLog.java:123)
> at
> org.apache.nifi.controller.repository.WriteAheadFlowFileRepository.updateRepository(WriteAheadFlowFileRepository.java:309)
> at
> org.apache.nifi.controller.repository.WriteAheadFlowFileRepository.updateRepository(WriteAheadFlowFileRepository.java:259)
> at
> org.apache.nifi.controller.repository.StandardProcessSession.commit(StandardProcessSession.java:407)...
> 10 common frames omitted
> .......MANY errors
>
> After 26 rolls of the logfiles the checkpoint arrives
> 2019-03-06 14:34:53,671 INFO [pool-13-thread-1]
> o.a.n.c.r.WriteAheadFlowFileRepository Successfully checkpointed FlowFile
> Repository with 22744 records in 339 milliseconds
>
> And then a new repository file fails
> 2019-03-06 14:34:54,287 ERROR [Timer-Driven Process Thread-93]
> o.a.n.processors.standard.ConvertRecord
> ConvertRecord[id=32781c92-fab3-34de-b1ff-6138f8788701] Failed to commit
> session StandardProcessSession[id=246475219] due to
> org.apache.nifi.processor.exception.ProcessException: FlowFile Repository
> failed to update; rolling back:
> org.apache.nifi.processor.exception.ProcessException: FlowFile Repository
> failed to update
> org.apache.nifi.processor.exception.ProcessException: FlowFile Repository
> failed to update
> at
> org.apache.nifi.controller.repository.StandardProcessSession.commit(StandardProcessSession.java:413)
> at
> org.apache.nifi.controller.repository.StandardProcessSession.commit(StandardProcessSession.java:343)
> at
> org.apache.nifi.controller.tasks.ConnectableTask.invoke(ConnectableTask.java:256)
> at
> org.apache.nifi.controller.scheduling.TimerDrivenSchedulingAgent$1.run(TimerDrivenSchedulingAgent.java:117)
> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
> at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> at java.lang.Thread.run(Thread.java:748)Caused by:
> java.nio.file.FileAlreadyExistsException:
> /flowfile_repo/nifi-1.9.0/journals/overflow-876686
>
>
> The following also start showing up after a while.
> 2019-03-06 14:33:22,363 ERROR [Timer-Driven Process Thread-19]
> o.a.n.c.r.c.StandardResourceClaimManager Decremented claimant count for
> StandardResourceClaim[id=[1551879190172-8371|tel:1551879190172-8371],
> container=default, section=179] to -3333
> 2019-03-06 14:33:22,363 WARN [Timer-Driven Process Thread-53]
> o.a.n.c.r.c.StandardResourceClaimManager Decrementing claimant count for
> StandardResourceClaim[id=[1551879161479-8345|tel:1551879161479-8345],
> container=default, section=153] but claimant count is not known. Returning -1
> 2019-03-06 14:33:22,363 WARN [Timer-Driven Process Thread-47]
> o.a.n.c.r.c.StandardResourceClaimManager Decrementing claimant count for
> StandardResourceClaim[id=[1551879161479-8346|tel:1551879161479-8346],
> container=default, section=154] but claimant count is not known. Returning -1
> 2019-03-06 14:33:22,363 WARN [Timer-Driven Process Thread-47]
> o.a.n.c.r.c.StandardResourceClaimManager Decrementing claimant count for
> StandardResourceClaim[id=[1551879161479-8345|tel:1551879161479-8345],
> container=default, section=153] but claimant count is not known. Returning
> -12019-03-06 14:33:22,363 ERROR [Timer-Driven Process Thread-94]
> o.a.n.c.r.c.StandardResourceClaimManager Decremented claimant count for
> StandardResourceClaim[id=[1551879190172-8371|tel:1551879190172-8371],
> container=default, section=179] to -3334
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
