You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@nifi.apache.org by Neil Derraugh <ne...@intellifylearning.com> on 2017/09/13 14:01:40 UTC

QueryRecord not closing stream before committing session

Seeing this warning and the subsequent error in a dataflow we recently
authored.  Bryan, looks like the same thing you were asking details of
on Hortonworks
Community Connection
<https://community.hortonworks.com/questions/118295/nifi-filttering-records-from-avro-file-error.html>
.

This is a QueryRecord processor consuming a schema in the Schema Registry
using a CSVReader and CSVRecordSetWriter.  Cache Schema and Include Zero
Record FlowFiles are set to false.

2017-09-13 09:54:42,628 WARN [Timer-Driven Process Thread-7]
o.a.n.c.r.StandardProcessSession StandardProcessSession[id=36915342]
closing
ErrorHandlingInputStream[FlowFile=StandardFlowFileRecord[uuid=8ad17b27-2d2d-49e7-9e79-e280deb8776a,claim=StandardContentClaim
[resourceClaim=StandardResourceClaim[id=1505264918993-2878,
container=default, section=830], offset=0,
length=308314548],offset=283108779,name=150526493445632157215839162_8ad17b27-2d2d-49e7-9e79-e280deb8776a,size=10485503]]
for
StandardFlowFileRecord[uuid=8ad17b27-2d2d-49e7-9e79-e280deb8776a,claim=StandardContentClaim
[resourceClaim=StandardResourceClaim[id=1505264918993-2878,
container=default, section=830], offset=0,
length=308314548],offset=283108779,name=150526493445632157215839162_8ad17b27-2d2d-49e7-9e79-e280deb8776a,size=10485503]
because the session was committed without the stream being closed.

2017-09-13 09:54:42,628 ERROR [Timer-Driven Process Thread-7]
o.a.nifi.processors.standard.QueryRecord
QueryRecord[id=57303d34-015e-1000-0000-0000032f37b4]
QueryRecord[id=57303d34-015e-1000-0000-0000032f37b4] failed to process
session due to java.lang.IllegalStateException:
StandardFlowFileRecord[uuid=8ad17b27-2d2d-49e7-9e79-e280deb8776a,claim=StandardContentClaim
[resourceClaim=StandardResourceClaim[id=1505264918993-2878,
container=default, section=830], offset=0,
length=308314548],offset=283108779,name=150526493445632157215839162_8ad17b27-2d2d-49e7-9e79-e280deb8776a,size=10485503]
already in use for an active callback or an InputStream created by
ProcessSession.read(FlowFile) has not been closed: {}
java.lang.IllegalStateException:
StandardFlowFileRecord[uuid=8ad17b27-2d2d-49e7-9e79-e280deb8776a,claim=StandardContentClaim
[resourceClaim=StandardResourceClaim[id=1505264918993-2878,
container=default, section=830], offset=0,
length=308314548],offset=283108779,name=150526493445632157215839162_8ad17b27-2d2d-49e7-9e79-e280deb8776a,size=10485503]
already in use for an active callback or an InputStream created by
ProcessSession.read(FlowFile) has not been closed
at
org.apache.nifi.controller.repository.StandardProcessSession.validateRecordState(StandardProcessSession.java:3018)
at
org.apache.nifi.controller.repository.StandardProcessSession.validateRecordState(StandardProcessSession.java:3013)
at
org.apache.nifi.controller.repository.StandardProcessSession.transfer(StandardProcessSession.java:1815)
at
org.apache.nifi.processors.standard.QueryRecord.onTrigger(QueryRecord.java:355)
at
org.apache.nifi.processor.AbstractProcessor.onTrigger(AbstractProcessor.java:27)
at
org.apache.nifi.controller.StandardProcessorNode.onTrigger(StandardProcessorNode.java:1120)
at
org.apache.nifi.controller.tasks.ContinuallyRunProcessorTask.call(ContinuallyRunProcessorTask.java:147)
at
org.apache.nifi.controller.tasks.ContinuallyRunProcessorTask.call(ContinuallyRunProcessorTask.java:47)
at
org.apache.nifi.controller.scheduling.TimerDrivenSchedulingAgent$1.run(TimerDrivenSchedulingAgent.java:132)
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:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:748)

Re: QueryRecord not closing stream before committing session

Posted by Neil Derraugh <ne...@intellifylearning.com>.
Yeah, 1.3.0 in a three node cluster.

Our query looks like SELECT * FROM FLOWFILE WHERE id IN ('${id_list}').

On Wed, Sep 13, 2017 at 10:07 AM, Bryan Bende <bb...@gmail.com> wrote:

> Neil,
>
> Thanks for providing the full error.
>
> Just to confirm, you encountered this running the 1.3.0 release?
>
> Thanks,
>
> Bryan
>
> On Wed, Sep 13, 2017 at 10:01 AM, Neil Derraugh
> <ne...@intellifylearning.com> wrote:
> > Seeing this warning and the subsequent error in a dataflow we recently
> > authored.  Bryan, looks like the same thing you were asking details of on
> > Hortonworks Community Connection.
> >
> > This is a QueryRecord processor consuming a schema in the Schema Registry
> > using a CSVReader and CSVRecordSetWriter.  Cache Schema and Include Zero
> > Record FlowFiles are set to false.
> >
> > 2017-09-13 09:54:42,628 WARN [Timer-Driven Process Thread-7]
> > o.a.n.c.r.StandardProcessSession StandardProcessSession[id=36915342]
> closing
> > ErrorHandlingInputStream[FlowFile=StandardFlowFileRecord[uuid=
> 8ad17b27-2d2d-49e7-9e79-e280deb8776a,claim=StandardContentClaim
> > [resourceClaim=StandardResourceClaim[id=1505264918993-2878,
> > container=default, section=830], offset=0,
> > length=308314548],offset=283108779,name=150526493445632157215839162_
> 8ad17b27-2d2d-49e7-9e79-e280deb8776a,size=10485503]]
> > for
> > StandardFlowFileRecord[uuid=8ad17b27-2d2d-49e7-9e79-e280deb8776a,claim=
> StandardContentClaim
> > [resourceClaim=StandardResourceClaim[id=1505264918993-2878,
> > container=default, section=830], offset=0,
> > length=308314548],offset=283108779,name=150526493445632157215839162_
> 8ad17b27-2d2d-49e7-9e79-e280deb8776a,size=10485503]
> > because the session was committed without the stream being closed.
> >
> > 2017-09-13 09:54:42,628 ERROR [Timer-Driven Process Thread-7]
> > o.a.nifi.processors.standard.QueryRecord
> > QueryRecord[id=57303d34-015e-1000-0000-0000032f37b4]
> > QueryRecord[id=57303d34-015e-1000-0000-0000032f37b4] failed to process
> > session due to java.lang.IllegalStateException:
> > StandardFlowFileRecord[uuid=8ad17b27-2d2d-49e7-9e79-e280deb8776a,claim=
> StandardContentClaim
> > [resourceClaim=StandardResourceClaim[id=1505264918993-2878,
> > container=default, section=830], offset=0,
> > length=308314548],offset=283108779,name=150526493445632157215839162_
> 8ad17b27-2d2d-49e7-9e79-e280deb8776a,size=10485503]
> > already in use for an active callback or an InputStream created by
> > ProcessSession.read(FlowFile) has not been closed: {}
> > java.lang.IllegalStateException:
> > StandardFlowFileRecord[uuid=8ad17b27-2d2d-49e7-9e79-e280deb8776a,claim=
> StandardContentClaim
> > [resourceClaim=StandardResourceClaim[id=1505264918993-2878,
> > container=default, section=830], offset=0,
> > length=308314548],offset=283108779,name=150526493445632157215839162_
> 8ad17b27-2d2d-49e7-9e79-e280deb8776a,size=10485503]
> > already in use for an active callback or an InputStream created by
> > ProcessSession.read(FlowFile) has not been closed
> > at
> > org.apache.nifi.controller.repository.StandardProcessSession.
> validateRecordState(StandardProcessSession.java:3018)
> > at
> > org.apache.nifi.controller.repository.StandardProcessSession.
> validateRecordState(StandardProcessSession.java:3013)
> > at
> > org.apache.nifi.controller.repository.StandardProcessSession.transfer(
> StandardProcessSession.java:1815)
> > at
> > org.apache.nifi.processors.standard.QueryRecord.
> onTrigger(QueryRecord.java:355)
> > at
> > org.apache.nifi.processor.AbstractProcessor.onTrigger(
> AbstractProcessor.java:27)
> > at
> > org.apache.nifi.controller.StandardProcessorNode.onTrigger(
> StandardProcessorNode.java:1120)
> > at
> > org.apache.nifi.controller.tasks.ContinuallyRunProcessorTask.call(
> ContinuallyRunProcessorTask.java:147)
> > at
> > org.apache.nifi.controller.tasks.ContinuallyRunProcessorTask.call(
> ContinuallyRunProcessorTask.java:47)
> > at
> > org.apache.nifi.controller.scheduling.TimerDrivenSchedulingAgent$1.run(
> TimerDrivenSchedulingAgent.java:132)
> > 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:1142)
> > at
> > java.util.concurrent.ThreadPoolExecutor$Worker.run(
> ThreadPoolExecutor.java:617)
> > at java.lang.Thread.run(Thread.java:748)
>

Re: QueryRecord not closing stream before committing session

Posted by Bryan Bende <bb...@gmail.com>.
Neil,

Thanks for providing the full error.

Just to confirm, you encountered this running the 1.3.0 release?

Thanks,

Bryan

On Wed, Sep 13, 2017 at 10:01 AM, Neil Derraugh
<ne...@intellifylearning.com> wrote:
> Seeing this warning and the subsequent error in a dataflow we recently
> authored.  Bryan, looks like the same thing you were asking details of on
> Hortonworks Community Connection.
>
> This is a QueryRecord processor consuming a schema in the Schema Registry
> using a CSVReader and CSVRecordSetWriter.  Cache Schema and Include Zero
> Record FlowFiles are set to false.
>
> 2017-09-13 09:54:42,628 WARN [Timer-Driven Process Thread-7]
> o.a.n.c.r.StandardProcessSession StandardProcessSession[id=36915342] closing
> ErrorHandlingInputStream[FlowFile=StandardFlowFileRecord[uuid=8ad17b27-2d2d-49e7-9e79-e280deb8776a,claim=StandardContentClaim
> [resourceClaim=StandardResourceClaim[id=1505264918993-2878,
> container=default, section=830], offset=0,
> length=308314548],offset=283108779,name=150526493445632157215839162_8ad17b27-2d2d-49e7-9e79-e280deb8776a,size=10485503]]
> for
> StandardFlowFileRecord[uuid=8ad17b27-2d2d-49e7-9e79-e280deb8776a,claim=StandardContentClaim
> [resourceClaim=StandardResourceClaim[id=1505264918993-2878,
> container=default, section=830], offset=0,
> length=308314548],offset=283108779,name=150526493445632157215839162_8ad17b27-2d2d-49e7-9e79-e280deb8776a,size=10485503]
> because the session was committed without the stream being closed.
>
> 2017-09-13 09:54:42,628 ERROR [Timer-Driven Process Thread-7]
> o.a.nifi.processors.standard.QueryRecord
> QueryRecord[id=57303d34-015e-1000-0000-0000032f37b4]
> QueryRecord[id=57303d34-015e-1000-0000-0000032f37b4] failed to process
> session due to java.lang.IllegalStateException:
> StandardFlowFileRecord[uuid=8ad17b27-2d2d-49e7-9e79-e280deb8776a,claim=StandardContentClaim
> [resourceClaim=StandardResourceClaim[id=1505264918993-2878,
> container=default, section=830], offset=0,
> length=308314548],offset=283108779,name=150526493445632157215839162_8ad17b27-2d2d-49e7-9e79-e280deb8776a,size=10485503]
> already in use for an active callback or an InputStream created by
> ProcessSession.read(FlowFile) has not been closed: {}
> java.lang.IllegalStateException:
> StandardFlowFileRecord[uuid=8ad17b27-2d2d-49e7-9e79-e280deb8776a,claim=StandardContentClaim
> [resourceClaim=StandardResourceClaim[id=1505264918993-2878,
> container=default, section=830], offset=0,
> length=308314548],offset=283108779,name=150526493445632157215839162_8ad17b27-2d2d-49e7-9e79-e280deb8776a,size=10485503]
> already in use for an active callback or an InputStream created by
> ProcessSession.read(FlowFile) has not been closed
> at
> org.apache.nifi.controller.repository.StandardProcessSession.validateRecordState(StandardProcessSession.java:3018)
> at
> org.apache.nifi.controller.repository.StandardProcessSession.validateRecordState(StandardProcessSession.java:3013)
> at
> org.apache.nifi.controller.repository.StandardProcessSession.transfer(StandardProcessSession.java:1815)
> at
> org.apache.nifi.processors.standard.QueryRecord.onTrigger(QueryRecord.java:355)
> at
> org.apache.nifi.processor.AbstractProcessor.onTrigger(AbstractProcessor.java:27)
> at
> org.apache.nifi.controller.StandardProcessorNode.onTrigger(StandardProcessorNode.java:1120)
> at
> org.apache.nifi.controller.tasks.ContinuallyRunProcessorTask.call(ContinuallyRunProcessorTask.java:147)
> at
> org.apache.nifi.controller.tasks.ContinuallyRunProcessorTask.call(ContinuallyRunProcessorTask.java:47)
> at
> org.apache.nifi.controller.scheduling.TimerDrivenSchedulingAgent$1.run(TimerDrivenSchedulingAgent.java:132)
> 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:1142)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:748)

Re: QueryRecord not closing stream before committing session

Posted by Neil Derraugh <ne...@intellifylearning.com>.
Yes.  Here are the logs for everything in between two instances of "Unable
to query".  But it looks like we had an error in our Avro schema.  Thanks
for the help !

2017-09-12 18:10:57,924 ERROR [Timer-Driven Process Thread-8]
o.a.nifi.processors.standard.QueryRecord
QueryRecord[id=57303d34-015e-1000-0000-0000032f37b4] Unable to query
StandardFlowFileRecord[uuid=17a8eddf-1774-43f8-b1ec-e1c2aed7a096,claim=StandardContentClaim
[resourceClaim=StandardResourceClaim[id=1505254238726-2167,
container=default, section=119], offset=0,
length=308314548],offset=0,name=21476397035749,size=10485600] due to
org.apache.nifi.processor.exception.ProcessExceptio
n: Failed to read next record in stream for
StandardFlowFileRecord[uuid=17a8eddf-1774-43f8-b1ec-e1c2aed7a096,claim=StandardContentClaim
[resourceClaim=StandardResourceClaim[id=1505254238726-2167,
container=default, section=119], offset=0,
length=308314548],offset=0,name=21476397035749,size=10485600]: {}
org.apache.nifi.processor.exception.ProcessException: Failed to read next
record in stream for
StandardFlowFileRecord[uuid=17a8eddf-1774-43f8-b1ec-e1c2aed7a096,claim=StandardContentClaim
[resourceClaim=StandardResourceClaim[id=1505254238726-2167,
container=default, section=119], offset=0,
length=308314548],offset=0,name=21476397035749,size=10485600]
at
org.apache.nifi.queryrecord.FlowFileEnumerator.moveNext(FlowFileEnumerator.java:65)
at Baz$1$1.moveNext(Unknown Source)
at
org.apache.calcite.linq4j.Linq4j$EnumeratorIterator.<init>(Linq4j.java:664)
at org.apache.calcite.linq4j.Linq4j.enumeratorIterator(Linq4j.java:98)
at
org.apache.calcite.linq4j.AbstractEnumerable.iterator(AbstractEnumerable.java:33)
at org.apache.calcite.avatica.MetaImpl.createCursor(MetaImpl.java:89)
at
org.apache.calcite.avatica.AvaticaResultSet.execute(AvaticaResultSet.java:196)
at
org.apache.calcite.jdbc.CalciteResultSet.execute(CalciteResultSet.java:67)
at
org.apache.calcite.jdbc.CalciteResultSet.execute(CalciteResultSet.java:44)
at
org.apache.calcite.avatica.AvaticaConnection$1.execute(AvaticaConnection.java:607)
at
org.apache.calcite.jdbc.CalciteMetaImpl.prepareAndExecute(CalciteMetaImpl.java:600)
at
org.apache.calcite.avatica.AvaticaConnection.prepareAndExecuteInternal(AvaticaConnection.java:615)
at
org.apache.calcite.avatica.AvaticaStatement.executeInternal(AvaticaStatement.java:148)
at
org.apache.calcite.avatica.AvaticaStatement.executeQuery(AvaticaStatement.java:218)
at
org.apache.nifi.processors.standard.QueryRecord.query(QueryRecord.java:490)
at
org.apache.nifi.processors.standard.QueryRecord.onTrigger(QueryRecord.java:286)
at
org.apache.nifi.processor.AbstractProcessor.onTrigger(AbstractProcessor.java:27)
at
org.apache.nifi.controller.StandardProcessorNode.onTrigger(StandardProcessorNode.java:1120)
at
org.apache.nifi.controller.tasks.ContinuallyRunProcessorTask.call(ContinuallyRunProcessorTask.java:147)
at
org.apache.nifi.controller.tasks.ContinuallyRunProcessorTask.call(ContinuallyRunProcessorTask.java:47)
at
org.apache.nifi.controller.scheduling.TimerDrivenSchedulingAgent$1.run(TimerDrivenSchedulingAgent.java:132)
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:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:748)
Caused by:
org.apache.nifi.serialization.record.util.IllegalTypeConversionException:
Cannot convert value [1.0] of type class java.lang.String to Boolean for
field self_enrolled
at
org.apache.nifi.serialization.record.util.DataTypeUtils.toBoolean(DataTypeUtils.java:613)
at
org.apache.nifi.serialization.record.util.DataTypeUtils.convertType(DataTypeUtils.java:112)
at org.apache.nifi.csv.CSVRecordReader.convert(CSVRecordReader.java:123)
at org.apache.nifi.csv.CSVRecordReader.nextRecord(CSVRecordReader.java:95)
at
org.apache.nifi.queryrecord.FlowFileEnumerator.moveNext(FlowFileEnumerator.java:62)
... 27 common frames omitted
2017-09-12 18:10:57,924 ERROR [Timer-Driven Process Thread-8]
o.a.nifi.processors.standard.QueryRecord
QueryRecord[id=57303d34-015e-1000-0000-0000032f37b4]
QueryRecord[id=57303d34-015e-1000-0000-0000032f37b4] failed to process due
to java.lang.IllegalStateException:
StandardFlowFileRecord[uuid=17a8eddf-1774-43f8-b1ec-e1c2aed7a096,claim=StandardContentClaim
[resourceClaim=StandardResourceClaim[id=1505254238726-2167,
container=default, section=119], offset=0, length=308314548],offset=
0,name=21476397035749,size=10485600] already in use for an active callback
or an InputStream created by ProcessSession.read(FlowFile) has not been
closed; rolling back session: {}
java.lang.IllegalStateException:
StandardFlowFileRecord[uuid=17a8eddf-1774-43f8-b1ec-e1c2aed7a096,claim=StandardContentClaim
[resourceClaim=StandardResourceClaim[id=1505254238726-2167,
container=default, section=119], offset=0,
length=308314548],offset=0,name=21476397035749,size=10485600] already in
use for an active callback or an InputStream created by
ProcessSession.read(FlowFile) has not been closed
at
org.apache.nifi.controller.repository.StandardProcessSession.validateRecordState(StandardProcessSession.java:3018)
at
org.apache.nifi.controller.repository.StandardProcessSession.validateRecordState(StandardProcessSession.java:3013)
at
org.apache.nifi.controller.repository.StandardProcessSession.transfer(StandardProcessSession.java:1815)
at
org.apache.nifi.processors.standard.QueryRecord.onTrigger(QueryRecord.java:355)
at
org.apache.nifi.processor.AbstractProcessor.onTrigger(AbstractProcessor.java:27)
at
org.apache.nifi.controller.StandardProcessorNode.onTrigger(StandardProcessorNode.java:1120)
at
org.apache.nifi.controller.tasks.ContinuallyRunProcessorTask.call(ContinuallyRunProcessorTask.java:147)
at
org.apache.nifi.controller.tasks.ContinuallyRunProcessorTask.call(ContinuallyRunProcessorTask.java:47)
at
org.apache.nifi.controller.scheduling.TimerDrivenSchedulingAgent$1.run(TimerDrivenSchedulingAgent.java:132)
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:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:748)
2017-09-12 18:10:57,924 WARN [Timer-Driven Process Thread-8]
o.a.n.c.r.StandardProcessSession StandardProcessSession[id=10914669]
closing
ErrorHandlingInputStream[FlowFile=StandardFlowFileRecord[uuid=17a8eddf-1774-43f8-b1ec-e1c2aed7a096,claim=StandardContentClaim
[resourceClaim=StandardResourceClaim[id=1505254238726-2167,
container=default, section=119], offset=0,
length=308314548],offset=0,name=21476397035749,size=10485600]] for
StandardFlowFileRecord[uuid=17a8eddf-1774-43f8-b1ec-e
1c2aed7a096,claim=StandardContentClaim
[resourceClaim=StandardResourceClaim[id=1505254238726-2167,
container=default, section=119], offset=0,
length=308314548],offset=0,name=21476397035749,size=10485600] because the
session was committed without the stream being closed.
2017-09-12 18:10:57,924 ERROR [Timer-Driven Process Thread-8]
o.a.nifi.processors.standard.QueryRecord
QueryRecord[id=57303d34-015e-1000-0000-0000032f37b4]
QueryRecord[id=57303d34-015e-1000-0000-0000032f37b4] failed to process
session due to java.lang.IllegalStateException:
StandardFlowFileRecord[uuid=17a8eddf-1774-43f8-b1ec-e1c2aed7a096,claim=StandardContentClaim
[resourceClaim=StandardResourceClaim[id=1505254238726-2167,
container=default, section=119], offset=0, length=308314548]
,offset=0,name=21476397035749,size=10485600] already in use for an active
callback or an InputStream created by ProcessSession.read(FlowFile) has not
been closed: {}
java.lang.IllegalStateException:
StandardFlowFileRecord[uuid=17a8eddf-1774-43f8-b1ec-e1c2aed7a096,claim=StandardContentClaim
[resourceClaim=StandardResourceClaim[id=1505254238726-2167,
container=default, section=119], offset=0,
length=308314548],offset=0,name=21476397035749,size=10485600] already in
use for an active callback or an InputStream created by
ProcessSession.read(FlowFile) has not been closed
at
org.apache.nifi.controller.repository.StandardProcessSession.validateRecordState(StandardProcessSession.java:3018)
at
org.apache.nifi.controller.repository.StandardProcessSession.validateRecordState(StandardProcessSession.java:3013)
at
org.apache.nifi.controller.repository.StandardProcessSession.transfer(StandardProcessSession.java:1815)
at
org.apache.nifi.processors.standard.QueryRecord.onTrigger(QueryRecord.java:355)
at
org.apache.nifi.processor.AbstractProcessor.onTrigger(AbstractProcessor.java:27)
at
org.apache.nifi.controller.StandardProcessorNode.onTrigger(StandardProcessorNode.java:1120)
at
org.apache.nifi.controller.tasks.ContinuallyRunProcessorTask.call(ContinuallyRunProcessorTask.java:147)
at
org.apache.nifi.controller.tasks.ContinuallyRunProcessorTask.call(ContinuallyRunProcessorTask.java:47)
at
org.apache.nifi.controller.scheduling.TimerDrivenSchedulingAgent$1.run(TimerDrivenSchedulingAgent.java:132)
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:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:748)
2017-09-12 18:10:57,924 WARN [Timer-Driven Process Thread-8]
o.a.nifi.processors.standard.QueryRecord
QueryRecord[id=57303d34-015e-1000-0000-0000032f37b4] Processor
Administratively Yielded for 1 sec due to processing failure
2017-09-12 18:10:57,924 WARN [Timer-Driven Process Thread-8]
o.a.n.c.t.ContinuallyRunProcessorTask Administratively Yielding
QueryRecord[id=57303d34-015e-1000-0000-0000032f37b4] due to uncaught
Exception: java.lang.IllegalStateException:
StandardFlowFileRecord[uuid=17a8eddf-1774-43f8-b1ec-e1c2aed7a096,claim=StandardContentClaim
[resourceClaim=StandardResourceClaim[id=1505254238726-2167,
container=default, section=119], offset=0,
length=308314548],offset=0,name=21476397035749,size=10
485600] already in use for an active callback or an InputStream created by
ProcessSession.read(FlowFile) has not been closed
2017-09-12 18:10:57,924 WARN [Timer-Driven Process Thread-8]
o.a.n.c.t.ContinuallyRunProcessorTask
java.lang.IllegalStateException:
StandardFlowFileRecord[uuid=17a8eddf-1774-43f8-b1ec-e1c2aed7a096,claim=StandardContentClaim
[resourceClaim=StandardResourceClaim[id=1505254238726-2167,
container=default, section=119], offset=0,
length=308314548],offset=0,name=21476397035749,size=10485600] already in
use for an active callback or an InputStream created by
ProcessSession.read(FlowFile) has not been closed
at
org.apache.nifi.controller.repository.StandardProcessSession.validateRecordState(StandardProcessSession.java:3018)
at
org.apache.nifi.controller.repository.StandardProcessSession.validateRecordState(StandardProcessSession.java:3013)
at
org.apache.nifi.controller.repository.StandardProcessSession.transfer(StandardProcessSession.java:1815)
at
org.apache.nifi.processors.standard.QueryRecord.onTrigger(QueryRecord.java:355)
at
org.apache.nifi.processor.AbstractProcessor.onTrigger(AbstractProcessor.java:27)
at
org.apache.nifi.controller.StandardProcessorNode.onTrigger(StandardProcessorNode.java:1120)
at
org.apache.nifi.controller.tasks.ContinuallyRunProcessorTask.call(ContinuallyRunProcessorTask.java:147)
at
org.apache.nifi.controller.tasks.ContinuallyRunProcessorTask.call(ContinuallyRunProcessorTask.java:47)
at
org.apache.nifi.controller.scheduling.TimerDrivenSchedulingAgent$1.run(TimerDrivenSchedulingAgent.java:132)
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:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:748)

On Wed, Sep 13, 2017 at 10:15 AM, Mark Payne <ma...@hotmail.com> wrote:

> Neil,
>
> Do you have any other errors in your log? Specifically, if you search for
> "Unable to query" do you find anything?
> This appears to be a problem with the failure handling logic, but it would
> only get into this state if another failure occurred.
> That other failure should be logged starting with "Unable to query".
>
> Thanks
> -Mark
>
>
> On Sep 13, 2017, at 10:01 AM, Neil Derraugh <neil.derraugh@
> intellifylearning.com> wrote:
>
> Seeing this warning and the subsequent error in a dataflow we recently
> authored.  Bryan, looks like the same thing you were asking details of on Hortonworks
> Community Connection
> <https://community.hortonworks.com/questions/118295/nifi-filttering-records-from-avro-file-error.html>
> .
>
> This is a QueryRecord processor consuming a schema in the Schema Registry
> using a CSVReader and CSVRecordSetWriter.  Cache Schema and Include Zero
> Record FlowFiles are set to false.
>
> 2017-09-13 09:54:42,628 WARN [Timer-Driven Process Thread-7] o.a.n.c.r.StandardProcessSession
> StandardProcessSession[id=36915342] closing ErrorHandlingInputStream[
> FlowFile=StandardFlowFileRecord[uuid=8ad17b27-2d2d-49e7-9e79-
> e280deb8776a,claim=StandardContentClaim [resourceClaim=
> StandardResourceClaim[id=1505264918993-2878, container=default,
> section=830], offset=0, length=308314548],offset=283108779,name=
> 150526493445632157215839162_8ad17b27-2d2d-49e7-9e79-e280deb8776a,size=10485503]]
> for StandardFlowFileRecord[uuid=8ad17b27-2d2d-49e7-9e79-
> e280deb8776a,claim=StandardContentClaim [resourceClaim=
> StandardResourceClaim[id=1505264918993-2878, container=default,
> section=830], offset=0, length=308314548],offset=283108779,name=
> 150526493445632157215839162_8ad17b27-2d2d-49e7-9e79-e280deb8776a,size=10485503]
> because the session was committed without the stream being closed.
>
> 2017-09-13 09:54:42,628 ERROR [Timer-Driven Process Thread-7]
> o.a.nifi.processors.standard.QueryRecord QueryRecord[id=57303d34-015e-1000-0000-0000032f37b4]
> QueryRecord[id=57303d34-015e-1000-0000-0000032f37b4] failed to process
> session due to java.lang.IllegalStateException:
> StandardFlowFileRecord[uuid=8ad17b27-2d2d-49e7-9e79-e280deb8776a,claim=StandardContentClaim
> [resourceClaim=StandardResourceClaim[id=1505264918993-2878,
> container=default, section=830], offset=0, length=308314548],offset=
> 283108779,name=150526493445632157215839162_8ad17b27-2d2d-49e7-9e79-e280deb8776a,size=10485503]
> already in use for an active callback or an InputStream created by
> ProcessSession.read(FlowFile) has not been closed: {}
> java.lang.IllegalStateException: StandardFlowFileRecord[uuid=
> 8ad17b27-2d2d-49e7-9e79-e280deb8776a,claim=StandardContentClaim
> [resourceClaim=StandardResourceClaim[id=1505264918993-2878,
> container=default, section=830], offset=0, length=308314548],offset=
> 283108779,name=150526493445632157215839162_8ad17b27-2d2d-49e7-9e79-e280deb8776a,size=10485503]
> already in use for an active callback or an InputStream created by
> ProcessSession.read(FlowFile) has not been closed
> at org.apache.nifi.controller.repository.StandardProcessSession.
> validateRecordState(StandardProcessSession.java:3018)
> at org.apache.nifi.controller.repository.StandardProcessSession.
> validateRecordState(StandardProcessSession.java:3013)
> at org.apache.nifi.controller.repository.StandardProcessSession.transfer(
> StandardProcessSession.java:1815)
> at org.apache.nifi.processors.standard.QueryRecord.
> onTrigger(QueryRecord.java:355)
> at org.apache.nifi.processor.AbstractProcessor.onTrigger(
> AbstractProcessor.java:27)
> at org.apache.nifi.controller.StandardProcessorNode.onTrigger(
> StandardProcessorNode.java:1120)
> at org.apache.nifi.controller.tasks.ContinuallyRunProcessorTask.call(
> ContinuallyRunProcessorTask.java:147)
> at org.apache.nifi.controller.tasks.ContinuallyRunProcessorTask.call(
> ContinuallyRunProcessorTask.java:47)
> at org.apache.nifi.controller.scheduling.TimerDrivenSchedulingAgent$1.run(
> TimerDrivenSchedulingAgent.java:132)
> 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:1142)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(
> ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:748)
>
>
>

Re: QueryRecord not closing stream before committing session

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

Do you have any other errors in your log? Specifically, if you search for "Unable to query" do you find anything?
This appears to be a problem with the failure handling logic, but it would only get into this state if another failure occurred.
That other failure should be logged starting with "Unable to query".

Thanks
-Mark


On Sep 13, 2017, at 10:01 AM, Neil Derraugh <ne...@intellifylearning.com>> wrote:

Seeing this warning and the subsequent error in a dataflow we recently authored.  Bryan, looks like the same thing you were asking details of on Hortonworks Community Connection<https://community.hortonworks.com/questions/118295/nifi-filttering-records-from-avro-file-error.html>.

This is a QueryRecord processor consuming a schema in the Schema Registry using a CSVReader and CSVRecordSetWriter.  Cache Schema and Include Zero Record FlowFiles are set to false.

2017-09-13 09:54:42,628 WARN [Timer-Driven Process Thread-7] o.a.n.c.r.StandardProcessSession StandardProcessSession[id=36915342] closing ErrorHandlingInputStream[FlowFile=StandardFlowFileRecord[uuid=8ad17b27-2d2d-49e7-9e79-e280deb8776a,claim=StandardContentClaim [resourceClaim=StandardResourceClaim[id=1505264918993-2878, container=default, section=830], offset=0, length=308314548],offset=283108779,name=150526493445632157215839162_8ad17b27-2d2d-49e7-9e79-e280deb8776a,size=10485503]] for StandardFlowFileRecord[uuid=8ad17b27-2d2d-49e7-9e79-e280deb8776a,claim=StandardContentClaim [resourceClaim=StandardResourceClaim[id=1505264918993-2878, container=default, section=830], offset=0, length=308314548],offset=283108779,name=150526493445632157215839162_8ad17b27-2d2d-49e7-9e79-e280deb8776a,size=10485503] because the session was committed without the stream being closed.

2017-09-13 09:54:42,628 ERROR [Timer-Driven Process Thread-7] o.a.nifi.processors.standard.QueryRecord QueryRecord[id=57303d34-015e-1000-0000-0000032f37b4] QueryRecord[id=57303d34-015e-1000-0000-0000032f37b4] failed to process session due to java.lang.IllegalStateException: StandardFlowFileRecord[uuid=8ad17b27-2d2d-49e7-9e79-e280deb8776a,claim=StandardContentClaim [resourceClaim=StandardResourceClaim[id=1505264918993-2878, container=default, section=830], offset=0, length=308314548],offset=283108779,name=150526493445632157215839162_8ad17b27-2d2d-49e7-9e79-e280deb8776a,size=10485503] already in use for an active callback or an InputStream created by ProcessSession.read(FlowFile) has not been closed: {}
java.lang.IllegalStateException: StandardFlowFileRecord[uuid=8ad17b27-2d2d-49e7-9e79-e280deb8776a,claim=StandardContentClaim [resourceClaim=StandardResourceClaim[id=1505264918993-2878, container=default, section=830], offset=0, length=308314548],offset=283108779,name=150526493445632157215839162_8ad17b27-2d2d-49e7-9e79-e280deb8776a,size=10485503] already in use for an active callback or an InputStream created by ProcessSession.read(FlowFile) has not been closed
at org.apache.nifi.controller.repository.StandardProcessSession.validateRecordState(StandardProcessSession.java:3018)
at org.apache.nifi.controller.repository.StandardProcessSession.validateRecordState(StandardProcessSession.java:3013)
at org.apache.nifi.controller.repository.StandardProcessSession.transfer(StandardProcessSession.java:1815)
at org.apache.nifi.processors.standard.QueryRecord.onTrigger(QueryRecord.java:355)
at org.apache.nifi.processor.AbstractProcessor.onTrigger(AbstractProcessor.java:27)
at org.apache.nifi.controller.StandardProcessorNode.onTrigger(StandardProcessorNode.java:1120)
at org.apache.nifi.controller.tasks.ContinuallyRunProcessorTask.call(ContinuallyRunProcessorTask.java:147)
at org.apache.nifi.controller.tasks.ContinuallyRunProcessorTask.call(ContinuallyRunProcessorTask.java:47)
at org.apache.nifi.controller.scheduling.TimerDrivenSchedulingAgent$1.run(TimerDrivenSchedulingAgent.java:132)
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:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:748)