Mailing-List: contact users-help@nifi.apache.org; run by ezmlm
Precedence: bulk
Reply-To: users@nifi.apache.org
From: Mark Payne <markap14@hotmail.com>
To: "users@nifi.apache.org" <users@nifi.apache.org>
Subject: Re: QueryRecord not closing stream before committing session
Thread-Topic: QueryRecord not closing stream before committing session
Thread-Index: AQHTLJjxuOmsWR9bN0637MzT1zI4yqKy3DCA
Date: Wed, 13 Sep 2017 14:15:08 +0000
Message-ID: <BN3PR15MB08043BF8442F953DA701F897CE6E0@BN3PR15MB0804.namprd15.prod.outlook.com>
References: <CACB-nJE0xMxqdW7rOBStWP+MVot=HFwooDHmw5jr5y-YfAay3Q@mail.gmail.com>
In-Reply-To: <CACB-nJE0xMxqdW7rOBStWP+MVot=HFwooDHmw5jr5y-YfAay3Q@mail.gmail.com>
Accept-Language: en-US
Content-Language: en-US
x-ms-exchange-messagesentrepresentingtype: 1
x-tmn: [a6af/SEu8gqsTlhEYWl7wbdNFSMQo7YrAd7QHjFeXfo=]
x-ms-publictraffictype: Email
x-microsoft-exchange-diagnostics: 1;CO1NAM03HT199;6:ZjfJhIK5efiEKLBNpRHQ9ni9JZR/5HPVgFy20P0lQX8mR2QCzlwHjPjNUlWjMAjtJm1GnPspJn6Ctxcekc9yDk9Lxm+yVDSnRRww5ojSFoZ7mP4gZITbUJk2vUReHuh1H53+67L5m7zDaYyvpzFGEZcSpxUeW6ziw33QoGfaBjTs6UBt4vIXc7uvY1RbbzCuURJS7icCBM8jb6s8K+efnNJQuAvhEdRwE7m5tF1SIgUIHzJOJwJK36Yc3Yz2F3UJ9LZKtbHQqD+F5PGJSxLXyI/KbAaHtUwP8y+dZnxHFwi3MdM/U2vT7GaJXE1DkBAEbQuI9n1+xEIIxkenbu5PZg==;5:4QhpyYNDr4rWbEviNhaxTNfpaGPferaELISKCL1OGjwS6lzDoZfUMc2SS8rVnlQ/KdJMPMmJB/eY38M+AIHlkDOklfS80te1YEW9LhBLORalek9e9N8nQwCb5OufcnoDwsZ5KwBgsTcfGFortbrA9w==;24:Kefe/8Nlj7heb8u59YIwGSuxNirvHUq9bovEoTVlmqwBXmm1d8EwNsyicjnlWhYrSgYIBB4QIvXWtCQ2jB6i57fRKxrRxdtCXXd+gh2iBp0=;7:/Q1GbwMJVOYdWwlTCz/Z3mxLpuQebK/Cd3M0VwHMOdqh7jhDTk2R6jpKLt0XJCftmrGNcVkNU6L4yL0KRSXqHnAh0umRD/WRZOOMhvMESfpE9M7+AYokhuInZzrpDV3U1f/Lyc4WazgOfChuqk8euHPO4mjBOVpoDU4sBcfnSc40Fa37KZ39cV/qTm8DBeQineuIMggL2Zyymx22QVJbsLzRv3KPzHhGHR0CUe8mXCc=
x-incomingheadercount: 46
x-eopattributedmessage: 0
x-ms-office365-filtering-correlation-id: 238be44a-3bc0-46cd-31dd-08d4fab1d684
x-microsoft-antispam: UriScan:;BCL:0;PCL:0;RULEID:(300000500095)(300135000095)(300000501095)(300135300095)(22001)(300000502095)(300135100095)(300000503095)(300135400095)(201702061074)(5061506573)(5061507331)(1603103135)(2017031320274)(2017031324274)(2017031323274)(2017031322404)(1603101448)(1601125374)(1701031045)(300000504095)(300135200095)(300000505095)(300135600095)(300000506095)(300135500095);SRVR:CO1NAM03HT199;
x-ms-traffictypediagnostic: CO1NAM03HT199:
authentication-results: outbound.protection.outlook.com; spf=skipped
 (originating message); dkim=none (message not signed) header.d=none;
 dmarc=none action=none header.from=hotmail.com;
x-exchange-antispam-report-test: UriScan:;
x-exchange-antispam-report-cfa-test: BCL:0;PCL:0;RULEID:(100000700101)(100105000095)(100000701101)(100105300095)(100000702101)(100105100095)(444000031);SRVR:CO1NAM03HT199;BCL:0;PCL:0;RULEID:(100000800101)(100110000095)(100000801101)(100110300095)(100000802101)(100110100095)(100000803101)(100110400095)(100000804101)(100110200095)(100000805101)(100110500095);SRVR:CO1NAM03HT199;
x-forefront-prvs: 042957ACD7
x-forefront-antispam-report: SFV:NSPM;SFS:(7070007)(98901004);DIR:OUT;SFP:1901;SCL:1;SRVR:CO1NAM03HT199;H:BN3PR15MB0804.namprd15.prod.outlook.com;FPR:;SPF:None;LANG:;
spamdiagnosticoutput: 1:99
spamdiagnosticmetadata: NSPM
Content-Type: multipart/alternative;
	boundary="_000_BN3PR15MB08043BF8442F953DA701F897CE6E0BN3PR15MB0804namp_"
MIME-Version: 1.0
X-OriginatorOrg: hotmail.com
X-MS-Exchange-CrossTenant-originalarrivaltime: 13 Sep 2017 14:15:08.9819
 (UTC)
X-MS-Exchange-CrossTenant-fromentityheader: Internet
X-MS-Exchange-CrossTenant-id: 84df9e7f-e9f6-40af-b435-aaaaaaaaaaaa
X-MS-Exchange-Transport-CrossTenantHeadersStamped: CO1NAM03HT199
archived-at: Wed, 13 Sep 2017 14:15:23 -0000

--_000_BN3PR15MB08043BF8442F953DA701F897CE6E0BN3PR15MB0804namp_
Content-Type: text/plain; charset="us-ascii"
Content-Transfer-Encoding: quoted-printable

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@intellifylearnin=
g.com<mailto:neil.derraugh@intellifylearning.com>> wrote:

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

This is a QueryRecord processor consuming a schema in the Schema Registry u=
sing a CSVReader and CSVRecordSetWriter.  Cache Schema and Include Zero Rec=
ord FlowFiles are set to false.

2017-09-13 09:54:42,628 WARN [Timer-Driven Process Thread-7] o.a.n.c.r.Stan=
dardProcessSession StandardProcessSession[id=3D36915342] closing ErrorHandl=
ingInputStream[FlowFile=3DStandardFlowFileRecord[uuid=3D8ad17b27-2d2d-49e7-=
9e79-e280deb8776a,claim=3DStandardContentClaim [resourceClaim=3DStandardRes=
ourceClaim[id=3D1505264918993-2878, container=3Ddefault, section=3D830], of=
fset=3D0, length=3D308314548],offset=3D283108779,name=3D1505264934456321572=
15839162_8ad17b27-2d2d-49e7-9e79-e280deb8776a,size=3D10485503]] for Standar=
dFlowFileRecord[uuid=3D8ad17b27-2d2d-49e7-9e79-e280deb8776a,claim=3DStandar=
dContentClaim [resourceClaim=3DStandardResourceClaim[id=3D1505264918993-287=
8, container=3Ddefault, section=3D830], offset=3D0, length=3D308314548],off=
set=3D283108779,name=3D150526493445632157215839162_8ad17b27-2d2d-49e7-9e79-=
e280deb8776a,size=3D10485503] 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.proc=
essors.standard.QueryRecord QueryRecord[id=3D57303d34-015e-1000-0000-000003=
2f37b4] QueryRecord[id=3D57303d34-015e-1000-0000-0000032f37b4] failed to pr=
ocess session due to java.lang.IllegalStateException: StandardFlowFileRecor=
d[uuid=3D8ad17b27-2d2d-49e7-9e79-e280deb8776a,claim=3DStandardContentClaim =
[resourceClaim=3DStandardResourceClaim[id=3D1505264918993-2878, container=
=3Ddefault, section=3D830], offset=3D0, length=3D308314548],offset=3D283108=
779,name=3D150526493445632157215839162_8ad17b27-2d2d-49e7-9e79-e280deb8776a=
,size=3D10485503] already in use for an active callback or an InputStream c=
reated by ProcessSession.read(FlowFile) has not been closed: {}
java.lang.IllegalStateException: StandardFlowFileRecord[uuid=3D8ad17b27-2d2=
d-49e7-9e79-e280deb8776a,claim=3DStandardContentClaim [resourceClaim=3DStan=
dardResourceClaim[id=3D1505264918993-2878, container=3Ddefault, section=3D8=
30], offset=3D0, length=3D308314548],offset=3D283108779,name=3D150526493445=
632157215839162_8ad17b27-2d2d-49e7-9e79-e280deb8776a,size=3D10485503] alrea=
dy in use for an active callback or an InputStream created by ProcessSessio=
n.read(FlowFile) has not been closed
at org.apache.nifi.controller.repository.StandardProcessSession.validateRec=
ordState(StandardProcessSession.java:3018)
at org.apache.nifi.controller.repository.StandardProcessSession.validateRec=
ordState(StandardProcessSession.java:3013)
at org.apache.nifi.controller.repository.StandardProcessSession.transfer(St=
andardProcessSession.java:1815)
at org.apache.nifi.processors.standard.QueryRecord.onTrigger(QueryRecord.ja=
va:355)
at org.apache.nifi.processor.AbstractProcessor.onTrigger(AbstractProcessor.=
java:27)
at org.apache.nifi.controller.StandardProcessorNode.onTrigger(StandardProce=
ssorNode.java:1120)
at org.apache.nifi.controller.tasks.ContinuallyRunProcessorTask.call(Contin=
uallyRunProcessorTask.java:147)
at org.apache.nifi.controller.tasks.ContinuallyRunProcessorTask.call(Contin=
uallyRunProcessorTask.java:47)
at org.apache.nifi.controller.scheduling.TimerDrivenSchedulingAgent$1.run(T=
imerDrivenSchedulingAgent.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.acc=
ess$301(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run=
(ScheduledThreadPoolExecutor.java:294)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.jav=
a:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.ja=
va:617)
at java.lang.Thread.run(Thread.java:748)


--_000_BN3PR15MB08043BF8442F953DA701F897CE6E0BN3PR15MB0804namp_
Content-Type: text/html; charset="us-ascii"
Content-ID: <1E98592BA1A37248A809370F25B25B8A@namprd15.prod.outlook.com>
Content-Transfer-Encoding: quoted-printable

<html>
<head>
<meta http-equiv=3D"Content-Type" content=3D"text/html; charset=3Dus-ascii"=
>
</head>
<body style=3D"word-wrap: break-word; -webkit-nbsp-mode: space; -webkit-lin=
e-break: after-white-space;" class=3D"">
<div class=3D"">Neil,</div>
<div class=3D""><br class=3D"">
</div>
<div class=3D"">Do you have any other errors in your log? Specifically, if =
you search for &quot;Unable to query&quot; do you find anything?</div>
<div class=3D"">This appears to be a problem with the failure handling logi=
c, but it would only get into this state if another failure occurred.</div>
<div class=3D"">That other failure should be logged starting with &quot;Una=
ble to query&quot;.</div>
<div class=3D""><br class=3D"">
</div>
<div class=3D"">Thanks</div>
<div class=3D"">-Mark</div>
<div class=3D""><br class=3D"">
</div>
<br class=3D"">
<div>
<blockquote type=3D"cite" class=3D"">
<div class=3D"">On Sep 13, 2017, at 10:01 AM, Neil Derraugh &lt;<a href=3D"=
mailto:neil.derraugh@intellifylearning.com" class=3D"">neil.derraugh@intell=
ifylearning.com</a>&gt; wrote:</div>
<br class=3D"Apple-interchange-newline">
<div class=3D"">
<div dir=3D"ltr" class=3D"">
<div class=3D"">Seeing this warning and the subsequent error in a dataflow =
we recently authored.&nbsp; Bryan, looks like the same thing you were askin=
g details of on
<a href=3D"https://community.hortonworks.com/questions/118295/nifi-filtteri=
ng-records-from-avro-file-error.html" class=3D"">
Hortonworks Community Connection</a>.</div>
<div class=3D""><br class=3D"">
</div>
<div class=3D"">This is a QueryRecord processor consuming a schema in the S=
chema Registry using a CSVReader and CSVRecordSetWriter.&nbsp; Cache Schema=
 and Include Zero Record FlowFiles are&nbsp;set to false.</div>
<div class=3D""><br class=3D"">
</div>
<div class=3D"">2017-09-13 09:54:42,628 WARN [Timer-Driven Process Thread-7=
] o.a.n.c.r.StandardProcessSession StandardProcessSession[id=3D36915342] cl=
osing ErrorHandlingInputStream[FlowFile=3DStandardFlowFileRecord[uuid=3D8ad=
17b27-2d2d-49e7-9e79-e280deb8776a,claim=3DStandardContentClaim
 [resourceClaim=3DStandardResourceClaim[id=3D1505264918993-2878, container=
=3Ddefault, section=3D830], offset=3D0, length=3D308314548],offset=3D283108=
779,name=3D150526493445632157215839162_8ad17b27-2d2d-49e7-9e79-e280deb8776a=
,size=3D10485503]] for StandardFlowFileRecord[uuid=3D8ad17b27-2d2d-49e7-9e7=
9-e280deb8776a,claim=3DStandardContentClaim
 [resourceClaim=3DStandardResourceClaim[id=3D1505264918993-2878, container=
=3Ddefault, section=3D830], offset=3D0, length=3D308314548],offset=3D283108=
779,name=3D150526493445632157215839162_8ad17b27-2d2d-49e7-9e79-e280deb8776a=
,size=3D10485503] because the session was committed
 without the stream being closed.</div>
<div class=3D""><br class=3D"">
</div>
<div class=3D"">2017-09-13 09:54:42,628 ERROR [Timer-Driven Process Thread-=
7] o.a.nifi.processors.standard.QueryRecord QueryRecord[id=3D57303d34-015e-=
1000-0000-0000032f37b4] QueryRecord[id=3D57303d34-015e-1000-0000-0000032f37=
b4] failed to process session due to java.lang.IllegalStateException:
 StandardFlowFileRecord[uuid=3D8ad17b27-2d2d-49e7-9e79-e280deb8776a,claim=
=3DStandardContentClaim [resourceClaim=3DStandardResourceClaim[id=3D1505264=
918993-2878, container=3Ddefault, section=3D830], offset=3D0, length=3D3083=
14548],offset=3D283108779,name=3D150526493445632157215839162_8ad17b27-2d2d-=
49e7-9e79-e280deb8776a,size=3D10485503]
 already in use for an active callback or an InputStream created by Process=
Session.read(FlowFile) has not been closed: {}</div>
<div class=3D"">java.lang.IllegalStateException: StandardFlowFileRecord[uui=
d=3D8ad17b27-2d2d-49e7-9e79-e280deb8776a,claim=3DStandardContentClaim [reso=
urceClaim=3DStandardResourceClaim[id=3D1505264918993-2878, container=3Ddefa=
ult, section=3D830], offset=3D0, length=3D308314548],offset=3D283108779,nam=
e=3D150526493445632157215839162_8ad17b27-2d2d-49e7-9e79-e280deb8776a,size=
=3D10485503]
 already in use for an active callback or an InputStream created by Process=
Session.read(FlowFile) has not been closed</div>
<div class=3D""><span style=3D"white-space:pre" class=3D""></span>at org.ap=
ache.nifi.controller.repository.StandardProcessSession.validateRecordState(=
StandardProcessSession.java:3018)</div>
<div class=3D""><span style=3D"white-space:pre" class=3D""></span>at org.ap=
ache.nifi.controller.repository.StandardProcessSession.validateRecordState(=
StandardProcessSession.java:3013)</div>
<div class=3D""><span style=3D"white-space:pre" class=3D""></span>at org.ap=
ache.nifi.controller.repository.StandardProcessSession.transfer(StandardPro=
cessSession.java:1815)</div>
<div class=3D""><span style=3D"white-space:pre" class=3D""></span>at org.ap=
ache.nifi.processors.standard.QueryRecord.onTrigger(QueryRecord.java:355)</=
div>
<div class=3D""><span style=3D"white-space:pre" class=3D""></span>at org.ap=
ache.nifi.processor.AbstractProcessor.onTrigger(AbstractProcessor.java:27)<=
/div>
<div class=3D""><span style=3D"white-space:pre" class=3D""></span>at org.ap=
ache.nifi.controller.StandardProcessorNode.onTrigger(StandardProcessorNode.=
java:1120)</div>
<div class=3D""><span style=3D"white-space:pre" class=3D""></span>at org.ap=
ache.nifi.controller.tasks.ContinuallyRunProcessorTask.call(ContinuallyRunP=
rocessorTask.java:147)</div>
<div class=3D""><span style=3D"white-space:pre" class=3D""></span>at org.ap=
ache.nifi.controller.tasks.ContinuallyRunProcessorTask.call(ContinuallyRunP=
rocessorTask.java:47)</div>
<div class=3D""><span style=3D"white-space:pre" class=3D""></span>at org.ap=
ache.nifi.controller.scheduling.TimerDrivenSchedulingAgent$1.run(TimerDrive=
nSchedulingAgent.java:132)</div>
<div class=3D""><span style=3D"white-space:pre" class=3D""></span>at java.u=
til.concurrent.Executors$RunnableAdapter.call(Executors.java:511)</div>
<div class=3D""><span style=3D"white-space:pre" class=3D""></span>at java.u=
til.concurrent.FutureTask.runAndReset(FutureTask.java:308)</div>
<div class=3D""><span style=3D"white-space:pre" class=3D""></span>at java.u=
til.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(S=
cheduledThreadPoolExecutor.java:180)</div>
<div class=3D""><span style=3D"white-space:pre" class=3D""></span>at java.u=
til.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Schedule=
dThreadPoolExecutor.java:294)</div>
<div class=3D""><span style=3D"white-space:pre" class=3D""></span>at java.u=
til.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)</=
div>
<div class=3D""><span style=3D"white-space:pre" class=3D""></span>at java.u=
til.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)</=
div>
<div class=3D""><span style=3D"white-space:pre" class=3D""></span>at java.l=
ang.Thread.run(Thread.java:748)</div>
</div>
</div>
</blockquote>
</div>
<br class=3D"">
</body>
</html>

--_000_BN3PR15MB08043BF8442F953DA701F897CE6E0BN3PR15MB0804namp_--