You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@nifi.apache.org by Russell Bateman <ru...@windofkeltia.com> on 2018/04/12 14:46:45 UTC
Calling getLogger() from @OnScheduled, @OnStopped, etc.
I seem to crash NiFi JUnit test runner when I have code that calls
getLogger()or attempts to make use of the product of calling
getLogger()in situations where some context (probably) is missing like
methods annotated for call at "special" times. This makes sense, but is
there a technique I can use to profile my custom processor in order to
observe (easily, such as using the logger) the behavior of (i.e.:
log-TRACE through) my processor in respect to @OnScheduled,
@OnUnscheduled, @OnStopped, etc. moments?
Many thanks,
Russ
Re: Calling getLogger() from @OnScheduled, @OnStopped, etc.
Posted by Russell Bateman <ru...@windofkeltia.com>.
Yes, this is what I assumed, but I was hoping that someone had developed
a technique for reaching the log in some (twisted) way perhaps that I
hadn't figured out yet. It would really help me visualize the order in
which my code's called and help me feel better about what I've written.
Thanks,
Russ
On 04/12/2018 03:41 PM, Bryan Bende wrote:
> The example processor you showed won’t work because you are calling
> getLogger() inline as part of the variable declaration.
>
> The logger is given to the processor in an init method which hasn’t been
> called yet at that point, so that is assigning null to the variable.
>
> Generally you should just call getLogger() whenever it is needed, or you
> could assign it to a variable from inside OnScheduled.
>
> On Thu, Apr 12, 2018 at 5:28 PM Russell Bateman <ru...@windofkeltia.com>
> wrote:
>
>> Thanks for responding, Andy.
>>
>> I am able to use it, like you, in onTrigger(). Where I haven't been able
>> to use it is from annotated methods (in the sense that onTrigger()isn't
>> annotated except by @Overridewhich is not relevant in this question).
>> Imagine:
>>
>> public class Fun extends AbstractProcessor
>> {
>> private ComponentLog logger = getLogger();
>>
>> @Override
>> public void onTrigger( final ProcessContext context, final
>> ProcessSession session ) throws ProcessException
>> {
>> logger.trace( "[PROFILE] onTrigger()" );*/* A */*
>> ...
>> }
>>
>> *@OnScheduled*
>> public void processProperties( final ProcessContext context )
>> {
>> logger.trace( "[PROFILE] processProperties()" );*/* B */*
>> ...
>> }
>>
>> *@OnStopped*
>> public void dropEverything()
>> {
>> logger.trace( "[PROFILE] dropEverything()" );*/* C */*
>> ...
>> }
>> ...
>> }
>>
>>
>> Now, imaging suitable test code, FunTest.test() which sets up
>>
>> runner = TestRunners.newTestRunner( processor = new Fun() );
>>
>> etc., then
>>
>> runner.run( 1 );
>>
>> Above, instance A works fine (it's the one you illustrated in footnote
>> [1]). Instances B and C cause the error:
>>
>> java.lang.AssertionError: Could not invoke methods annotated with
>> @OnScheduled (or @OnStopped) annotation due to:
>> java.lang.reflect.InvocationTargetException
>>
>> Russ
>>
>> On 04/12/2018 02:52 PM, Andy LoPresto wrote:
>>> Hi Russ,
>>>
>>> Are you saying the code that breaks is having “getLogger()” executed
>>> inside one of the processor lifecycle methods (i.e.
>>> GetFile#onTrigger()) or in your test code (i.e.
>>> GetFileTest#testOnTriggerShouldReadFile())?
>>>
>>> I’m not aware of anything with the JUnit runner that would cause
>>> issues here. I use the loggers extensively in both my application code
>>> [1] and the tests [2]. Obviously in the tests, I instantiate a new
>>> Logger instance for the test class.
>>>
>>> Can you share an example of the code that breaks this for you?
>>>
>>> [1]
>>>
>> https://github.com/apache/nifi/blob/master/nifi-nar-bundles/nifi-standard-bundle/nifi-standard-processors/src/main/java/org/apache/nifi/processors/standard/EncryptContent.java#L511
>>> [2]
>>>
>> https://github.com/apache/nifi/pull/2628/files#diff-e9cfa232683ae75b1fc505d6c9bd3b24R447
>>> Andy LoPresto
>>> alopresto@apache.org <ma...@apache.org>
>>> /alopresto.apache@gmail.com <ma...@gmail.com>/
>>> PGP Fingerprint: 70EC B3E5 98A6 5A3F D3C4 BACE 3C6E F65B 2F7D EF69
>>>
>>>> On Apr 12, 2018, at 3:46 PM, Russell Bateman <russ@windofkeltia.com
>>>> <ma...@windofkeltia.com>> wrote:
>>>>
>>>> I seem to crash NiFi JUnit test runner when I have code that calls
>>>> getLogger()or attempts to make use of the product of calling
>>>> getLogger()in situations where some context (probably) is missing
>>>> like methods annotated for call at "special" times. This makes sense,
>>>> but is there a technique I can use to profile my custom processor in
>>>> order to observe (easily, such as using the logger) the behavior of
>>>> (i.e.: log-TRACE through) my processor in respect to @OnScheduled,
>>>> @OnUnscheduled, @OnStopped, etc. moments?
>>>>
>>>> Many thanks,
>>>> Russ
>> --
> Sent from Gmail Mobile
>
Re: Calling getLogger() from @OnScheduled, @OnStopped, etc.
Posted by Bryan Bende <bb...@gmail.com>.
The example processor you showed won’t work because you are calling
getLogger() inline as part of the variable declaration.
The logger is given to the processor in an init method which hasn’t been
called yet at that point, so that is assigning null to the variable.
Generally you should just call getLogger() whenever it is needed, or you
could assign it to a variable from inside OnScheduled.
On Thu, Apr 12, 2018 at 5:28 PM Russell Bateman <ru...@windofkeltia.com>
wrote:
> Thanks for responding, Andy.
>
> I am able to use it, like you, in onTrigger(). Where I haven't been able
> to use it is from annotated methods (in the sense that onTrigger()isn't
> annotated except by @Overridewhich is not relevant in this question).
> Imagine:
>
> public class Fun extends AbstractProcessor
> {
> private ComponentLog logger = getLogger();
>
> @Override
> public void onTrigger( final ProcessContext context, final
> ProcessSession session ) throws ProcessException
> {
> logger.trace( "[PROFILE] onTrigger()" );*/* A */*
> ...
> }
>
> *@OnScheduled*
> public void processProperties( final ProcessContext context )
> {
> logger.trace( "[PROFILE] processProperties()" );*/* B */*
> ...
> }
>
> *@OnStopped*
> public void dropEverything()
> {
> logger.trace( "[PROFILE] dropEverything()" );*/* C */*
> ...
> }
> ...
> }
>
>
> Now, imaging suitable test code, FunTest.test() which sets up
>
> runner = TestRunners.newTestRunner( processor = new Fun() );
>
> etc., then
>
> runner.run( 1 );
>
> Above, instance A works fine (it's the one you illustrated in footnote
> [1]). Instances B and C cause the error:
>
> java.lang.AssertionError: Could not invoke methods annotated with
> @OnScheduled (or @OnStopped) annotation due to:
> java.lang.reflect.InvocationTargetException
>
> Russ
>
> On 04/12/2018 02:52 PM, Andy LoPresto wrote:
> > Hi Russ,
> >
> > Are you saying the code that breaks is having “getLogger()” executed
> > inside one of the processor lifecycle methods (i.e.
> > GetFile#onTrigger()) or in your test code (i.e.
> > GetFileTest#testOnTriggerShouldReadFile())?
> >
> > I’m not aware of anything with the JUnit runner that would cause
> > issues here. I use the loggers extensively in both my application code
> > [1] and the tests [2]. Obviously in the tests, I instantiate a new
> > Logger instance for the test class.
> >
> > Can you share an example of the code that breaks this for you?
> >
> > [1]
> >
> https://github.com/apache/nifi/blob/master/nifi-nar-bundles/nifi-standard-bundle/nifi-standard-processors/src/main/java/org/apache/nifi/processors/standard/EncryptContent.java#L511
> > [2]
> >
> https://github.com/apache/nifi/pull/2628/files#diff-e9cfa232683ae75b1fc505d6c9bd3b24R447
> >
> > Andy LoPresto
> > alopresto@apache.org <ma...@apache.org>
> > /alopresto.apache@gmail.com <ma...@gmail.com>/
> > PGP Fingerprint: 70EC B3E5 98A6 5A3F D3C4 BACE 3C6E F65B 2F7D EF69
> >
> >> On Apr 12, 2018, at 3:46 PM, Russell Bateman <russ@windofkeltia.com
> >> <ma...@windofkeltia.com>> wrote:
> >>
> >> I seem to crash NiFi JUnit test runner when I have code that calls
> >> getLogger()or attempts to make use of the product of calling
> >> getLogger()in situations where some context (probably) is missing
> >> like methods annotated for call at "special" times. This makes sense,
> >> but is there a technique I can use to profile my custom processor in
> >> order to observe (easily, such as using the logger) the behavior of
> >> (i.e.: log-TRACE through) my processor in respect to @OnScheduled,
> >> @OnUnscheduled, @OnStopped, etc. moments?
> >>
> >> Many thanks,
> >> Russ
> >
>
> --
Sent from Gmail Mobile
Re: Calling getLogger() from @OnScheduled, @OnStopped, etc.
Posted by Matt Burgess <ma...@gmail.com>.
I’m AFK right now but I’m thinking there is a point in the lifecycle where you can expect a logger, and before that (like when the processor is instantiated as you have it coded), you may not be able to assume there is a logger (either in real NiFi or the mock-verse :)
My guess is the rule of thumb is that if you have a Context (either ProcessContext, ProcessorInitializationContext, ConfigurationContext, etc) then you can assume the logger is available, and just call getLogger() there.
Sent from my iPhone
> On Apr 12, 2018, at 5:27 PM, Russell Bateman <ru...@windofkeltia.com> wrote:
>
> Thanks for responding, Andy.
>
> I am able to use it, like you, in onTrigger(). Where I haven't been able to use it is from annotated methods (in the sense that onTrigger()isn't annotated except by @Overridewhich is not relevant in this question). Imagine:
>
> public class Fun extends AbstractProcessor
> {
> private ComponentLog logger = getLogger();
>
> @Override
> public void onTrigger( final ProcessContext context, final ProcessSession session ) throws ProcessException
> {
> logger.trace( "[PROFILE] onTrigger()" );*/* A */*
> ...
> }
>
> *@OnScheduled*
> public void processProperties( final ProcessContext context )
> {
> logger.trace( "[PROFILE] processProperties()" );*/* B */*
> ...
> }
>
> *@OnStopped*
> public void dropEverything()
> {
> logger.trace( "[PROFILE] dropEverything()" );*/* C */*
> ...
> }
> ...
> }
>
>
> Now, imaging suitable test code, FunTest.test() which sets up
>
> runner = TestRunners.newTestRunner( processor = new Fun() );
>
> etc., then
>
> runner.run( 1 );
>
> Above, instance A works fine (it's the one you illustrated in footnote [1]). Instances B and C cause the error:
>
> java.lang.AssertionError: Could not invoke methods annotated with
> @OnScheduled (or @OnStopped) annotation due to:
> java.lang.reflect.InvocationTargetException
>
> Russ
>
>> On 04/12/2018 02:52 PM, Andy LoPresto wrote:
>> Hi Russ,
>>
>> Are you saying the code that breaks is having “getLogger()” executed inside one of the processor lifecycle methods (i.e. GetFile#onTrigger()) or in your test code (i.e. GetFileTest#testOnTriggerShouldReadFile())?
>>
>> I’m not aware of anything with the JUnit runner that would cause issues here. I use the loggers extensively in both my application code [1] and the tests [2]. Obviously in the tests, I instantiate a new Logger instance for the test class.
>>
>> Can you share an example of the code that breaks this for you?
>>
>> [1] https://github.com/apache/nifi/blob/master/nifi-nar-bundles/nifi-standard-bundle/nifi-standard-processors/src/main/java/org/apache/nifi/processors/standard/EncryptContent.java#L511
>> [2] https://github.com/apache/nifi/pull/2628/files#diff-e9cfa232683ae75b1fc505d6c9bd3b24R447
>>
>> Andy LoPresto
>> alopresto@apache.org <ma...@apache.org>
>> /alopresto.apache@gmail.com <ma...@gmail.com>/
>> PGP Fingerprint: 70EC B3E5 98A6 5A3F D3C4 BACE 3C6E F65B 2F7D EF69
>>
>>> On Apr 12, 2018, at 3:46 PM, Russell Bateman <russ@windofkeltia.com <ma...@windofkeltia.com>> wrote:
>>>
>>> I seem to crash NiFi JUnit test runner when I have code that calls getLogger()or attempts to make use of the product of calling getLogger()in situations where some context (probably) is missing like methods annotated for call at "special" times. This makes sense, but is there a technique I can use to profile my custom processor in order to observe (easily, such as using the logger) the behavior of (i.e.: log-TRACE through) my processor in respect to @OnScheduled, @OnUnscheduled, @OnStopped, etc. moments?
>>>
>>> Many thanks,
>>> Russ
>>
>
Re: Calling getLogger() from @OnScheduled, @OnStopped, etc.
Posted by Russell Bateman <ru...@windofkeltia.com>.
Thanks for responding, Andy.
I am able to use it, like you, in onTrigger(). Where I haven't been able
to use it is from annotated methods (in the sense that onTrigger()isn't
annotated except by @Overridewhich is not relevant in this question).
Imagine:
public class Fun extends AbstractProcessor
{
private ComponentLog logger = getLogger();
@Override
public void onTrigger( final ProcessContext context, final ProcessSession session ) throws ProcessException
{
logger.trace( "[PROFILE] onTrigger()" );*/* A */*
...
}
*@OnScheduled*
public void processProperties( final ProcessContext context )
{
logger.trace( "[PROFILE] processProperties()" );*/* B */*
...
}
*@OnStopped*
public void dropEverything()
{
logger.trace( "[PROFILE] dropEverything()" );*/* C */*
...
}
...
}
Now, imaging suitable test code, FunTest.test() which sets up
runner = TestRunners.newTestRunner( processor = new Fun() );
etc., then
runner.run( 1 );
Above, instance A works fine (it's the one you illustrated in footnote
[1]). Instances B and C cause the error:
java.lang.AssertionError: Could not invoke methods annotated with
@OnScheduled (or @OnStopped) annotation due to:
java.lang.reflect.InvocationTargetException
Russ
On 04/12/2018 02:52 PM, Andy LoPresto wrote:
> Hi Russ,
>
> Are you saying the code that breaks is having “getLogger()” executed
> inside one of the processor lifecycle methods (i.e.
> GetFile#onTrigger()) or in your test code (i.e.
> GetFileTest#testOnTriggerShouldReadFile())?
>
> I’m not aware of anything with the JUnit runner that would cause
> issues here. I use the loggers extensively in both my application code
> [1] and the tests [2]. Obviously in the tests, I instantiate a new
> Logger instance for the test class.
>
> Can you share an example of the code that breaks this for you?
>
> [1]
> https://github.com/apache/nifi/blob/master/nifi-nar-bundles/nifi-standard-bundle/nifi-standard-processors/src/main/java/org/apache/nifi/processors/standard/EncryptContent.java#L511
> [2]
> https://github.com/apache/nifi/pull/2628/files#diff-e9cfa232683ae75b1fc505d6c9bd3b24R447
>
> Andy LoPresto
> alopresto@apache.org <ma...@apache.org>
> /alopresto.apache@gmail.com <ma...@gmail.com>/
> PGP Fingerprint: 70EC B3E5 98A6 5A3F D3C4 BACE 3C6E F65B 2F7D EF69
>
>> On Apr 12, 2018, at 3:46 PM, Russell Bateman <russ@windofkeltia.com
>> <ma...@windofkeltia.com>> wrote:
>>
>> I seem to crash NiFi JUnit test runner when I have code that calls
>> getLogger()or attempts to make use of the product of calling
>> getLogger()in situations where some context (probably) is missing
>> like methods annotated for call at "special" times. This makes sense,
>> but is there a technique I can use to profile my custom processor in
>> order to observe (easily, such as using the logger) the behavior of
>> (i.e.: log-TRACE through) my processor in respect to @OnScheduled,
>> @OnUnscheduled, @OnStopped, etc. moments?
>>
>> Many thanks,
>> Russ
>
Re: Calling getLogger() from @OnScheduled, @OnStopped, etc.
Posted by Andy LoPresto <al...@apache.org>.
Hi Russ,
Are you saying the code that breaks is having “getLogger()” executed inside one of the processor lifecycle methods (i.e. GetFile#onTrigger()) or in your test code (i.e. GetFileTest#testOnTriggerShouldReadFile())?
I’m not aware of anything with the JUnit runner that would cause issues here. I use the loggers extensively in both my application code [1] and the tests [2]. Obviously in the tests, I instantiate a new Logger instance for the test class.
Can you share an example of the code that breaks this for you?
[1] https://github.com/apache/nifi/blob/master/nifi-nar-bundles/nifi-standard-bundle/nifi-standard-processors/src/main/java/org/apache/nifi/processors/standard/EncryptContent.java#L511 <https://github.com/apache/nifi/blob/master/nifi-nar-bundles/nifi-standard-bundle/nifi-standard-processors/src/main/java/org/apache/nifi/processors/standard/EncryptContent.java#L511>
[2] https://github.com/apache/nifi/pull/2628/files#diff-e9cfa232683ae75b1fc505d6c9bd3b24R447 <https://github.com/apache/nifi/pull/2628/files#diff-e9cfa232683ae75b1fc505d6c9bd3b24R447>
Andy LoPresto
alopresto@apache.org
alopresto.apache@gmail.com
PGP Fingerprint: 70EC B3E5 98A6 5A3F D3C4 BACE 3C6E F65B 2F7D EF69
> On Apr 12, 2018, at 3:46 PM, Russell Bateman <ru...@windofkeltia.com> wrote:
>
> I seem to crash NiFi JUnit test runner when I have code that calls getLogger()or attempts to make use of the product of calling getLogger()in situations where some context (probably) is missing like methods annotated for call at "special" times. This makes sense, but is there a technique I can use to profile my custom processor in order to observe (easily, such as using the logger) the behavior of (i.e.: log-TRACE through) my processor in respect to @OnScheduled, @OnUnscheduled, @OnStopped, etc. moments?
>
> Many thanks,
> Russ