You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@nifi.apache.org by Carl Berndt <cs...@gmail.com> on 2017/02/09 17:12:03 UTC
Bug, Groovy log.info() does not work in version 1.1.1
Hi,
I recently upgraded from version 0.7 to 1.1.1
This can be recreated in Windows and Linux (Amazon Ec2).
The log.info is not working in 1.1.1 from a Groovy script.
It did work in nifi 0.7 with groovy script 'ExecuteScript processor'.
I fed the ExecuteScript with a Generate Flow File processor.
Here is the test script I used to prove it: 6 lines...
log.info("Hello from Groovy!") ;
def flowFile = session.get();
if (!flowFile) return;
flowFile = session.putAttribute(flowFile, 'my-property', 'my-value');
session.transfer(flowFile, REL_SUCCESS)
Here is the output I get:
(snippets from the nifi-app.log's)
version 0.7.1 windows
2017-02-09 10:29:28,810 INFO [StandardProcessScheduler Thread-4]
o.a.n.c.s.TimerDrivenSchedulingAgent Scheduled
GenerateFlowFile[id=603b4bc8-ca9b-48b9-abb8-11967b6f28bf] to run with 1
threads
2017-02-09 10:29:31,643 INFO [StandardProcessScheduler Thread-1]
o.a.n.c.s.TimerDrivenSchedulingAgent Scheduled
ExecuteScript[id=e2fa6e2b-caa5-40af-be1c-d265b2509941] to run with 1 threads
2017-02-09 10:29:32,791 INFO [Timer-Driven Process Thread-2]
o.a.nifi.processors.script.ExecuteScript
ExecuteScript[id=e2fa6e2b-caa5-40af-be1c-d265b2509941] Hello from Groovy!
version 1.1.1 windows
no log.info() results outputted in nifi-app.log
2017-02-09 10:44:53,390 INFO [StandardProcessScheduler Thread-3]
o.a.n.c.s.TimerDrivenSchedulingAgent Scheduled
GenerateFlowFile[id=f6d91eaa-100c-115a-957e-f0f9c124ad13] to run with 1
threads
2017-02-09 10:44:53,524 INFO [StandardProcessScheduler Thread-4]
o.a.n.c.s.TimerDrivenSchedulingAgent Scheduled
ExecuteScript[id=f6d91ea9-100c-115a-6c5c-bd8ae0e515d4] to run with 1 threads
2017-02-09 10:44:55,240 INFO [Flow Service Tasks Thread-1]
o.a.nifi.controller.StandardFlowService Saved flow controller
org.apache.nifi.controller.FlowController@3429ba07 // Another save pending
= false
2017-02-09 10:44:56,509 INFO [NiFi Web Server-18]
o.a.n.controller.StandardProcessorNode Stopping processor: class
org.apache.nifi.processors.script.ExecuteScript
2017-02-09 10:44:56,520 INFO [StandardProcessScheduler Thread-8]
o.a.n.c.s.TimerDrivenSchedulingAgent Stopped scheduling
ExecuteScript[id=f6d91ea9-100c-115a-6c5c-bd8ae0e515d4] to run
This same problem also occurs in my amazon ec2 nifi 1.1.1.
workaround:
I can use a groovy print() to cause output to show in the bootstrap .log
file.....
Thanks for a product!
Carl
Re: Bug, Groovy log.info() does not work in version 1.1.1
Posted by Carl Berndt <cs...@gmail.com>.
James & Mark,
I added the <logger name="org.apache.nifi.processors.script.ExecuteScript"
level="INFO"/> to logback.xml
And it's logging like a champ!
Thank both!
Carl
On Thu, Feb 9, 2017 at 11:37 AM, James Wing <jv...@gmail.com> wrote:
> Carl,
>
> I think logging still works in ExecuteScript. But starting in NiFi 1.0,
> the default log level for processors was set from 'INFO' back to 'WARN' to
> reduce log volumes. To receive INFO messages from ExecuteScript, you will
> want to do one or both of two things:
>
> 1.) Set the bulletin level of the specific ExecuteScript processor to
> 'INFO'. This will let you see the log messages directly in the UI,
> although the bulletin mechanism has an error handling feel to it.
>
> 2.) Configure conf/logback.xml to set the log capture level to 'INFO' for
> the ExecuteScript processor. This requires something like the following:
>
> <logger name="org.apache.nifi.processors.script.ExecuteScript"
> level="INFO"/>
>
> There is a similar entry for LogAttribute around line 90. After doing
> this, you should see your info messages in the nifi-app.log file. I hope
> that helps.
>
> Thanks,
>
> James
>
> On Thu, Feb 9, 2017 at 9:12 AM, Carl Berndt <cs...@gmail.com> wrote:
>
>> Hi,
>>
>> I recently upgraded from version 0.7 to 1.1.1
>> This can be recreated in Windows and Linux (Amazon Ec2).
>>
>> The log.info is not working in 1.1.1 from a Groovy script.
>> It did work in nifi 0.7 with groovy script 'ExecuteScript processor'.
>>
>> I fed the ExecuteScript with a Generate Flow File processor.
>> Here is the test script I used to prove it: 6 lines...
>>
>> log.info("Hello from Groovy!") ;
>> def flowFile = session.get();
>> if (!flowFile) return;
>>
>> flowFile = session.putAttribute(flowFile, 'my-property', 'my-value');
>> session.transfer(flowFile, REL_SUCCESS)
>>
>> Here is the output I get:
>> (snippets from the nifi-app.log's)
>>
>> version 0.7.1 windows
>> 2017-02-09 10:29:28,810 INFO [StandardProcessScheduler Thread-4]
>> o.a.n.c.s.TimerDrivenSchedulingAgent Scheduled
>> GenerateFlowFile[id=603b4bc8-ca9b-48b9-abb8-11967b6f28bf] to run with 1
>> threads
>> 2017-02-09 10:29:31,643 INFO [StandardProcessScheduler Thread-1]
>> o.a.n.c.s.TimerDrivenSchedulingAgent Scheduled
>> ExecuteScript[id=e2fa6e2b-caa5-40af-be1c-d265b2509941] to run with 1
>> threads
>> 2017-02-09 10:29:32,791 INFO [Timer-Driven Process Thread-2]
>> o.a.nifi.processors.script.ExecuteScript ExecuteScript[id=e2fa6e2b-caa5-40af-be1c-d265b2509941]
>> Hello from Groovy!
>>
>> version 1.1.1 windows
>> no log.info() results outputted in nifi-app.log
>>
>> 2017-02-09 10:44:53,390 INFO [StandardProcessScheduler Thread-3]
>> o.a.n.c.s.TimerDrivenSchedulingAgent Scheduled
>> GenerateFlowFile[id=f6d91eaa-100c-115a-957e-f0f9c124ad13] to run with 1
>> threads
>> 2017-02-09 10:44:53,524 INFO [StandardProcessScheduler Thread-4]
>> o.a.n.c.s.TimerDrivenSchedulingAgent Scheduled
>> ExecuteScript[id=f6d91ea9-100c-115a-6c5c-bd8ae0e515d4] to run with 1
>> threads
>> 2017-02-09 10:44:55,240 INFO [Flow Service Tasks Thread-1]
>> o.a.nifi.controller.StandardFlowService Saved flow controller
>> org.apache.nifi.controller.FlowController@3429ba07 // Another save
>> pending = false
>>
>> 2017-02-09 10:44:56,509 INFO [NiFi Web Server-18]
>> o.a.n.controller.StandardProcessorNode Stopping processor: class
>> org.apache.nifi.processors.script.ExecuteScript
>> 2017-02-09 10:44:56,520 INFO [StandardProcessScheduler Thread-8]
>> o.a.n.c.s.TimerDrivenSchedulingAgent Stopped scheduling
>> ExecuteScript[id=f6d91ea9-100c-115a-6c5c-bd8ae0e515d4] to run
>>
>>
>> This same problem also occurs in my amazon ec2 nifi 1.1.1.
>>
>> workaround:
>> I can use a groovy print() to cause output to show in the bootstrap .log
>> file.....
>>
>> Thanks for a product!
>> Carl
>>
>
>
Re: Bug, Groovy log.info() does not work in version 1.1.1
Posted by James Wing <jv...@gmail.com>.
Carl,
I think logging still works in ExecuteScript. But starting in NiFi 1.0,
the default log level for processors was set from 'INFO' back to 'WARN' to
reduce log volumes. To receive INFO messages from ExecuteScript, you will
want to do one or both of two things:
1.) Set the bulletin level of the specific ExecuteScript processor to
'INFO'. This will let you see the log messages directly in the UI,
although the bulletin mechanism has an error handling feel to it.
2.) Configure conf/logback.xml to set the log capture level to 'INFO' for
the ExecuteScript processor. This requires something like the following:
<logger name="org.apache.nifi.processors.script.ExecuteScript"
level="INFO"/>
There is a similar entry for LogAttribute around line 90. After doing
this, you should see your info messages in the nifi-app.log file. I hope
that helps.
Thanks,
James
On Thu, Feb 9, 2017 at 9:12 AM, Carl Berndt <cs...@gmail.com> wrote:
> Hi,
>
> I recently upgraded from version 0.7 to 1.1.1
> This can be recreated in Windows and Linux (Amazon Ec2).
>
> The log.info is not working in 1.1.1 from a Groovy script.
> It did work in nifi 0.7 with groovy script 'ExecuteScript processor'.
>
> I fed the ExecuteScript with a Generate Flow File processor.
> Here is the test script I used to prove it: 6 lines...
>
> log.info("Hello from Groovy!") ;
> def flowFile = session.get();
> if (!flowFile) return;
>
> flowFile = session.putAttribute(flowFile, 'my-property', 'my-value');
> session.transfer(flowFile, REL_SUCCESS)
>
> Here is the output I get:
> (snippets from the nifi-app.log's)
>
> version 0.7.1 windows
> 2017-02-09 10:29:28,810 INFO [StandardProcessScheduler Thread-4] o.a.n.c.s.TimerDrivenSchedulingAgent
> Scheduled GenerateFlowFile[id=603b4bc8-ca9b-48b9-abb8-11967b6f28bf] to
> run with 1 threads
> 2017-02-09 10:29:31,643 INFO [StandardProcessScheduler Thread-1] o.a.n.c.s.TimerDrivenSchedulingAgent
> Scheduled ExecuteScript[id=e2fa6e2b-caa5-40af-be1c-d265b2509941] to run
> with 1 threads
> 2017-02-09 10:29:32,791 INFO [Timer-Driven Process Thread-2]
> o.a.nifi.processors.script.ExecuteScript ExecuteScript[id=e2fa6e2b-caa5-40af-be1c-d265b2509941]
> Hello from Groovy!
>
> version 1.1.1 windows
> no log.info() results outputted in nifi-app.log
>
> 2017-02-09 10:44:53,390 INFO [StandardProcessScheduler Thread-3] o.a.n.c.s.TimerDrivenSchedulingAgent
> Scheduled GenerateFlowFile[id=f6d91eaa-100c-115a-957e-f0f9c124ad13] to
> run with 1 threads
> 2017-02-09 10:44:53,524 INFO [StandardProcessScheduler Thread-4] o.a.n.c.s.TimerDrivenSchedulingAgent
> Scheduled ExecuteScript[id=f6d91ea9-100c-115a-6c5c-bd8ae0e515d4] to run
> with 1 threads
> 2017-02-09 10:44:55,240 INFO [Flow Service Tasks Thread-1]
> o.a.nifi.controller.StandardFlowService Saved flow controller
> org.apache.nifi.controller.FlowController@3429ba07 // Another save
> pending = false
>
> 2017-02-09 10:44:56,509 INFO [NiFi Web Server-18] o.a.n.controller.StandardProcessorNode
> Stopping processor: class org.apache.nifi.processors.script.ExecuteScript
> 2017-02-09 10:44:56,520 INFO [StandardProcessScheduler Thread-8] o.a.n.c.s.TimerDrivenSchedulingAgent
> Stopped scheduling ExecuteScript[id=f6d91ea9-100c-115a-6c5c-bd8ae0e515d4]
> to run
>
>
> This same problem also occurs in my amazon ec2 nifi 1.1.1.
>
> workaround:
> I can use a groovy print() to cause output to show in the bootstrap .log
> file.....
>
> Thanks for a product!
> Carl
>
Re: Bug, Groovy log.info() does not work in version 1.1.1
Posted by Mark Payne <ma...@hotmail.com>.
Hey Carl,
In version 1.0.0, the default log level for the 'org.apache.nifi.processors' class was changed
from INFO level to WARN level. This was done because there is a tremendous amount of
information logged by most of the standard processors, and many users were complaining
that the logs were too noisy to find the information they need. The Data Provenance feature
also makes most of the INFO-level log messages irrelevant.
You can certainly change the level back to INFO if you would like by updating the $NIFI_HOME/conf/logback.xml
file and change the line:
<logger name="org.apache.nifi.processors" level="WARN" />
to:
<logger name="org.apache.nifi.processors" level="INFO" />
Let us know if this doesn't resolve your issue, and we can dig more into it!
Thanks
-Mark
On Feb 9, 2017, at 12:12 PM, Carl Berndt <cs...@gmail.com>> wrote:
Hi,
I recently upgraded from version 0.7 to 1.1.1
This can be recreated in Windows and Linux (Amazon Ec2).
The log.info<http://log.info/> is not working in 1.1.1 from a Groovy script.
It did work in nifi 0.7 with groovy script 'ExecuteScript processor'.
I fed the ExecuteScript with a Generate Flow File processor.
Here is the test script I used to prove it: 6 lines...
log.info<http://log.info/>("Hello from Groovy!") ;
def flowFile = session.get();
if (!flowFile) return;
flowFile = session.putAttribute(flowFile, 'my-property', 'my-value');
session.transfer(flowFile, REL_SUCCESS)
Here is the output I get:
(snippets from the nifi-app.log's)
version 0.7.1 windows
2017-02-09 10:29:28,810 INFO [StandardProcessScheduler Thread-4] o.a.n.c.s.TimerDrivenSchedulingAgent Scheduled GenerateFlowFile[id=603b4bc8-ca9b-48b9-abb8-11967b6f28bf] to run with 1 threads
2017-02-09 10:29:31,643 INFO [StandardProcessScheduler Thread-1] o.a.n.c.s.TimerDrivenSchedulingAgent Scheduled ExecuteScript[id=e2fa6e2b-caa5-40af-be1c-d265b2509941] to run with 1 threads
2017-02-09 10:29:32,791 INFO [Timer-Driven Process Thread-2] o.a.nifi.processors.script.ExecuteScript ExecuteScript[id=e2fa6e2b-caa5-40af-be1c-d265b2509941] Hello from Groovy!
version 1.1.1 windows
no log.info<http://log.info/>() results outputted in nifi-app.log
2017-02-09 10:44:53,390 INFO [StandardProcessScheduler Thread-3] o.a.n.c.s.TimerDrivenSchedulingAgent Scheduled GenerateFlowFile[id=f6d91eaa-100c-115a-957e-f0f9c124ad13] to run with 1 threads
2017-02-09 10:44:53,524 INFO [StandardProcessScheduler Thread-4] o.a.n.c.s.TimerDrivenSchedulingAgent Scheduled ExecuteScript[id=f6d91ea9-100c-115a-6c5c-bd8ae0e515d4] to run with 1 threads
2017-02-09 10:44:55,240 INFO [Flow Service Tasks Thread-1] o.a.nifi.controller.StandardFlowService Saved flow controller org.apache.nifi.controller.FlowController@3429ba07 // Another save pending = false
2017-02-09 10:44:56,509 INFO [NiFi Web Server-18] o.a.n.controller.StandardProcessorNode Stopping processor: class org.apache.nifi.processors.script.ExecuteScript
2017-02-09 10:44:56,520 INFO [StandardProcessScheduler Thread-8] o.a.n.c.s.TimerDrivenSchedulingAgent Stopped scheduling ExecuteScript[id=f6d91ea9-100c-115a-6c5c-bd8ae0e515d4] to run
This same problem also occurs in my amazon ec2 nifi 1.1.1.
workaround:
I can use a groovy print() to cause output to show in the bootstrap .log file.....
Thanks for a product!
Carl