You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@nifi.apache.org by bmichaud <be...@optum.com> on 2016/11/08 19:09:58 UTC

Partition closed in MergeContent bins

I am using NiFi 1.0.0. I have a MergeContent merging to 6 bins using a
correlation attribute that will have at most 6 values. 
<http://apache-nifi-developer-list.39713.n7.nabble.com/file/n13851/MergeContent.png> 

It is directly preceded by a custom processor that is set for 12 concurrent
tasks. I am getting this error repeatedly in some of my installations,
especially when under high load (about 2 million messages every 5 minutes).
Restarting only solves the problem temporarily. 

Here is the error: 

2016-11-08 13:15:08,451 WARN [Timer-Driven Process Thread-3]
o.a.n.processors.standard.MergeContent
MergeContent[id=12054904-d034-49fa-e6b6-b4e99d0d488a] Processor
Administratively Yielded for 1 sec due to processing failure
2016-11-08 13:15:08,451 WARN [Timer-Driven Process Thread-3]
o.a.n.c.t.ContinuallyRunProcessorTask Administratively Yielding
MergeContent[id=12054904-d034-49fa-e6b6-b4e99d0d488a] due to uncaught
Exception: java.lang.IllegalStateException: Partition is closed
2016-11-08 13:15:08,452 WARN [Timer-Driven Process Thread-3]
o.a.n.c.t.ContinuallyRunProcessorTask
java.lang.IllegalStateException: Partition is closed
        at
org.wali.MinimalLockingWriteAheadLog$Partition.update(MinimalLockingWriteAheadLog.java:906)
~[nifi-write-ahead-log-1.0.0.jar:1.0.0]
        at
org.wali.MinimalLockingWriteAheadLog.update(MinimalLockingWriteAheadLog.java:230)
~[nifi-write-ahead-log-1.0.0.jar:1.0.0]
        at
org.apache.nifi.controller.repository.WriteAheadFlowFileRepository.swapFlowFilesOut(WriteAheadFlowFileRepository.java:323)
~[nifi-framework-core-1.0.0.jar:1.0.0]
        at
org.apache.nifi.controller.FileSystemSwapManager.swapOut(FileSystemSwapManager.java:129)
~[nifi-framework-core-1.0.0.jar:1.0.0]
        at
org.apache.nifi.controller.StandardFlowFileQueue.writeSwapFilesIfNecessary(StandardFlowFileQueue.java:579)
~[nifi-framework-core-1.0.0.jar:1.0.0]
        at
org.apache.nifi.controller.StandardFlowFileQueue.put(StandardFlowFileQueue.java:282)
~[nifi-framework-core-1.0.0.jar:1.0.0]
        at
org.apache.nifi.controller.repository.StandardProcessSession.rollback(StandardProcessSession.java:949)
~[nifi-framework-core-1.0.0.jar:1.0.0]
        at
org.apache.nifi.controller.repository.StandardProcessSession.rollback(StandardProcessSession.java:876)
~[nifi-framework-core-1.0.0.jar:1.0.0]
        at
org.apache.nifi.controller.repository.StandardProcessSession.rollback(StandardProcessSession.java:871)
~[nifi-framework-core-1.0.0.jar:1.0.0]
        at
org.apache.nifi.processor.util.bin.BinFiles.processBins(BinFiles.java:247)
~[nifi-processor-utils-1.0.0.jar:1.0.0]
        at
org.apache.nifi.processor.util.bin.BinFiles.onTrigger(BinFiles.java:190)
~[nifi-processor-utils-1.0.0.jar:1.0.0]
        at
org.apache.nifi.controller.StandardProcessorNode.onTrigger(StandardProcessorNode.java:1064)
~[nifi-framework-core-1.0.0.jar:1.0.0]
        at
org.apache.nifi.controller.tasks.ContinuallyRunProcessorTask.call(ContinuallyRunProcessorTask.java:136)
[nifi-framework-core-1.0.0.jar:1.0.0]
        at
org.apache.nifi.controller.tasks.ContinuallyRunProcessorTask.call(ContinuallyRunProcessorTask.java:47)
[nifi-framework-core-1.0.0.jar:1.0.0]
        at
org.apache.nifi.controller.scheduling.TimerDrivenSchedulingAgent$1.run(TimerDrivenSchedulingAgent.java:132)
[nifi-framework-core-1.0.0.jar:1.0.0]
        at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[na:1.8.0_65]
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
[na:1.8.0_65]
        at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
[na:1.8.0_65]
        at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
[na:1.8.0_65]
        at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
[na:1.8.0_65]
        at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[na:1.8.0_65]
        at java.lang.Thread.run(Thread.java:745) [na:1.8.0_65]




--
View this message in context: http://apache-nifi-developer-list.39713.n7.nabble.com/Partition-closed-in-MergeContent-bins-tp13851.html
Sent from the Apache NiFi Developer List mailing list archive at Nabble.com.

Re: Partition closed in MergeContent bins

Posted by bmichaud <be...@optum.com>.
Mark Payne wrote
> Hello,
> 
> So I am a little bit confused by this error. The only case where this
> should ever occur
> is when NiFi is shutdown. This is the only case when the Partition would
> be closed.
> 
> Is it possible that you're seeing some other error while running, and then
> this error only
> when shutting down?
> 
> Thanks
> -Mark

That is the only error I see, but I will take a look at the entire log next
time it happens, which should be any time now. One variation is as follows:
16-10-31 14:13:27,574 ERROR [StandardProcessScheduler Thread-2]
org.apache.nifi.util.ReflectionUtils Failed while invoking annotated method
'public final void org.apache.nifi.processor.util.bin.BinFiles.resetState()'
with arguments '[]'.
java.lang.reflect.InvocationTargetException: null
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
~[na:1.8.0_65]
        at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
~[na:1.8.0_65]
        at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
~[na:1.8.0_65]
        at java.lang.reflect.Method.invoke(Method.java:497) ~[na:1.8.0_65]
        at
org.apache.nifi.util.ReflectionUtils.invokeMethodsWithAnnotations(ReflectionUtils.java:137)
[nifi-framework-core-1.0.0.jar:1.0.0]
        at
org.apache.nifi.util.ReflectionUtils.invokeMethodsWithAnnotations(ReflectionUtils.java:125)
[nifi-framework-core-1.0.0.jar:1.0.0]
        at
org.apache.nifi.util.ReflectionUtils.quietlyInvokeMethodsWithAnnotations(ReflectionUtils.java:233)
[nifi-framework-core-1.0.0.jar:1.0.0]
        at
org.apache.nifi.util.ReflectionUtils.quietlyInvokeMethodsWithAnnotation(ReflectionUtils.java:85)
[nifi-framework-core-1.0.0.jar:1.0.0]
        at
org.apache.nifi.controller.StandardProcessorNode$2.run(StandardProcessorNode.java:1338)
[nifi-framework-core-1.0.0.jar:1.0.0]
        at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[na:1.8.0_65]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[na:1.8.0_65]
        at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
[na:1.8.0_65]
        at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
[na:1.8.0_65]
        at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
[na:1.8.0_65]
        at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[na:1.8.0_65]
        at java.lang.Thread.run(Thread.java:745) [na:1.8.0_65]
Caused by: java.lang.IllegalStateException: Partition is closed
        at
org.wali.MinimalLockingWriteAheadLog$Partition.update(MinimalLockingWriteAheadLog.java:906)
~[nifi-write-ahead-log-1.0.0.jar:1.0.0]
        at
org.wali.MinimalLockingWriteAheadLog.update(MinimalLockingWriteAheadLog.java:230)
~[nifi-write-ahead-log-1.0.0.jar:1.0.0]
        at
org.apache.nifi.controller.repository.WriteAheadFlowFileRepository.swapFlowFilesOut(WriteAheadFlowFileRepository.java:323)
~[nifi-framework-core-1.0.0.jar:1.0.0]
        at
org.apache.nifi.controller.FileSystemSwapManager.swapOut(FileSystemSwapManager.java:129)
~[nifi-framework-core-1.0.0.jar:1.0.0]
        at
org.apache.nifi.controller.StandardFlowFileQueue.writeSwapFilesIfNecessary(StandardFlowFileQueue.java:579)
~[nifi-framework-core-1.0.0.jar:1.0.0]
        at
org.apache.nifi.controller.StandardFlowFileQueue.put(StandardFlowFileQueue.java:282)
~[nifi-framework-core-1.0.0.jar:1.0.0]
        at
org.apache.nifi.controller.repository.StandardProcessSession.rollback(StandardProcessSession.java:949)
~[nifi-framework-core-1.0.0.jar:1.0.0]
        at
org.apache.nifi.controller.repository.StandardProcessSession.rollback(StandardProcessSession.java:876)
~[nifi-framework-core-1.0.0.jar:1.0.0]
        at
org.apache.nifi.controller.repository.StandardProcessSession.rollback(StandardProcessSession.java:871)
~[nifi-framework-core-1.0.0.jar:1.0.0]
        at
org.apache.nifi.processor.util.bin.BinManager.purge(BinManager.java:64)
~[nifi-processor-utils-1.0.0.jar:1.0.0]
        at
org.apache.nifi.processor.util.bin.BinFiles.resetState(BinFiles.java:108)
~[nifi-processor-utils-1.0.0.jar:1.0.0]




--
View this message in context: http://apache-nifi-developer-list.39713.n7.nabble.com/Partition-closed-in-MergeContent-bins-tp13851p13854.html
Sent from the Apache NiFi Developer List mailing list archive at Nabble.com.

Re: Partition closed in MergeContent bins

Posted by bmichaud <be...@optum.com>.
Alright. The next time it happens, I will let you know. I have another issue
I am dealing with at the moment, so please be patient. I think I need a new
topic for the other one, because it is related to clustering.


Joe Witt wrote
> Hello
> 
> So let's work on finding out why nifi is shutting down.  Can you show
> the output of the logs/nifi-bootstrap.log?
> 
> Thanks
> Joe
> 
> On Tue, Nov 15, 2016 at 7:51 AM, bmichaud &lt;

> ben_michaud@

> &gt; wrote:
>> I have been unable to determine the reason NiFi is shutting down when
>> this
>> occurs. There is nothing in the logs that indicates what the reason is.
>> It
>> is also clear that a shut down is already occurring when the above
>> message
>> is logged, so I guess this is not the cause after all.
>>
>>
>>
>> --
>> View this message in context:
>> http://apache-nifi-developer-list.39713.n7.nabble.com/Partition-closed-in-MergeContent-bins-tp13851p13885.html
>> Sent from the Apache NiFi Developer List mailing list archive at
>> Nabble.com.





--
View this message in context: http://apache-nifi-developer-list.39713.n7.nabble.com/Partition-closed-in-MergeContent-bins-tp13851p13887.html
Sent from the Apache NiFi Developer List mailing list archive at Nabble.com.

Re: Partition closed in MergeContent bins

Posted by Joe Witt <jo...@gmail.com>.
Hello

So let's work on finding out why nifi is shutting down.  Can you show
the output of the logs/nifi-bootstrap.log?

Thanks
Joe

On Tue, Nov 15, 2016 at 7:51 AM, bmichaud <be...@optum.com> wrote:
> I have been unable to determine the reason NiFi is shutting down when this
> occurs. There is nothing in the logs that indicates what the reason is. It
> is also clear that a shut down is already occurring when the above message
> is logged, so I guess this is not the cause after all.
>
>
>
> --
> View this message in context: http://apache-nifi-developer-list.39713.n7.nabble.com/Partition-closed-in-MergeContent-bins-tp13851p13885.html
> Sent from the Apache NiFi Developer List mailing list archive at Nabble.com.

Re: Partition closed in MergeContent bins

Posted by bmichaud <be...@optum.com>.
I have been unable to determine the reason NiFi is shutting down when this
occurs. There is nothing in the logs that indicates what the reason is. It
is also clear that a shut down is already occurring when the above message
is logged, so I guess this is not the cause after all.



--
View this message in context: http://apache-nifi-developer-list.39713.n7.nabble.com/Partition-closed-in-MergeContent-bins-tp13851p13885.html
Sent from the Apache NiFi Developer List mailing list archive at Nabble.com.

Re: Partition closed in MergeContent bins

Posted by Mark Payne <ma...@hotmail.com>.
Hello,

So I am a little bit confused by this error. The only case where this should ever occur
is when NiFi is shutdown. This is the only case when the Partition would be closed.

Is it possible that you're seeing some other error while running, and then this error only
when shutting down?

Thanks
-Mark



> On Nov 8, 2016, at 2:09 PM, bmichaud <be...@optum.com> wrote:
> 
> I am using NiFi 1.0.0. I have a MergeContent merging to 6 bins using a
> correlation attribute that will have at most 6 values. 
> <http://apache-nifi-developer-list.39713.n7.nabble.com/file/n13851/MergeContent.png> 
> 
> It is directly preceded by a custom processor that is set for 12 concurrent
> tasks. I am getting this error repeatedly in some of my installations,
> especially when under high load (about 2 million messages every 5 minutes).
> Restarting only solves the problem temporarily. 
> 
> Here is the error: 
> 
> 2016-11-08 13:15:08,451 WARN [Timer-Driven Process Thread-3]
> o.a.n.processors.standard.MergeContent
> MergeContent[id=12054904-d034-49fa-e6b6-b4e99d0d488a] Processor
> Administratively Yielded for 1 sec due to processing failure
> 2016-11-08 13:15:08,451 WARN [Timer-Driven Process Thread-3]
> o.a.n.c.t.ContinuallyRunProcessorTask Administratively Yielding
> MergeContent[id=12054904-d034-49fa-e6b6-b4e99d0d488a] due to uncaught
> Exception: java.lang.IllegalStateException: Partition is closed
> 2016-11-08 13:15:08,452 WARN [Timer-Driven Process Thread-3]
> o.a.n.c.t.ContinuallyRunProcessorTask
> java.lang.IllegalStateException: Partition is closed
>        at
> org.wali.MinimalLockingWriteAheadLog$Partition.update(MinimalLockingWriteAheadLog.java:906)
> ~[nifi-write-ahead-log-1.0.0.jar:1.0.0]
>        at
> org.wali.MinimalLockingWriteAheadLog.update(MinimalLockingWriteAheadLog.java:230)
> ~[nifi-write-ahead-log-1.0.0.jar:1.0.0]
>        at
> org.apache.nifi.controller.repository.WriteAheadFlowFileRepository.swapFlowFilesOut(WriteAheadFlowFileRepository.java:323)
> ~[nifi-framework-core-1.0.0.jar:1.0.0]
>        at
> org.apache.nifi.controller.FileSystemSwapManager.swapOut(FileSystemSwapManager.java:129)
> ~[nifi-framework-core-1.0.0.jar:1.0.0]
>        at
> org.apache.nifi.controller.StandardFlowFileQueue.writeSwapFilesIfNecessary(StandardFlowFileQueue.java:579)
> ~[nifi-framework-core-1.0.0.jar:1.0.0]
>        at
> org.apache.nifi.controller.StandardFlowFileQueue.put(StandardFlowFileQueue.java:282)
> ~[nifi-framework-core-1.0.0.jar:1.0.0]
>        at
> org.apache.nifi.controller.repository.StandardProcessSession.rollback(StandardProcessSession.java:949)
> ~[nifi-framework-core-1.0.0.jar:1.0.0]
>        at
> org.apache.nifi.controller.repository.StandardProcessSession.rollback(StandardProcessSession.java:876)
> ~[nifi-framework-core-1.0.0.jar:1.0.0]
>        at
> org.apache.nifi.controller.repository.StandardProcessSession.rollback(StandardProcessSession.java:871)
> ~[nifi-framework-core-1.0.0.jar:1.0.0]
>        at
> org.apache.nifi.processor.util.bin.BinFiles.processBins(BinFiles.java:247)
> ~[nifi-processor-utils-1.0.0.jar:1.0.0]
>        at
> org.apache.nifi.processor.util.bin.BinFiles.onTrigger(BinFiles.java:190)
> ~[nifi-processor-utils-1.0.0.jar:1.0.0]
>        at
> org.apache.nifi.controller.StandardProcessorNode.onTrigger(StandardProcessorNode.java:1064)
> ~[nifi-framework-core-1.0.0.jar:1.0.0]
>        at
> org.apache.nifi.controller.tasks.ContinuallyRunProcessorTask.call(ContinuallyRunProcessorTask.java:136)
> [nifi-framework-core-1.0.0.jar:1.0.0]
>        at
> org.apache.nifi.controller.tasks.ContinuallyRunProcessorTask.call(ContinuallyRunProcessorTask.java:47)
> [nifi-framework-core-1.0.0.jar:1.0.0]
>        at
> org.apache.nifi.controller.scheduling.TimerDrivenSchedulingAgent$1.run(TimerDrivenSchedulingAgent.java:132)
> [nifi-framework-core-1.0.0.jar:1.0.0]
>        at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
> [na:1.8.0_65]
>        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
> [na:1.8.0_65]
>        at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
> [na:1.8.0_65]
>        at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
> [na:1.8.0_65]
>        at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> [na:1.8.0_65]
>        at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> [na:1.8.0_65]
>        at java.lang.Thread.run(Thread.java:745) [na:1.8.0_65]
> 
> 
> 
> 
> --
> View this message in context: http://apache-nifi-developer-list.39713.n7.nabble.com/Partition-closed-in-MergeContent-bins-tp13851.html
> Sent from the Apache NiFi Developer List mailing list archive at Nabble.com.