Sorry I'm slow following up - guess I'm running out of options. It
all sounds like the runtime check is failing but tricky to know why.
With regard to:
> [WARNING] does not match because declaring type is java.lang.Object, if match
> desired use target(org.apache.log4j.Logger) [Xlint:unmatchedSuperTypeInCall]
we could try loosening up the pointcut and see why it is misbehaving:
From:
pointcut logCall() : call(* org.apache.log4j.Logger.*(..)) &&
!within(*..*Aspect);
to:
pointcut logCall() : call(* *(..)) && !within(*..*Aspect) && target(Logger);
maybe also try removing the percflow() model to see if that makes the
advice spring to life - if not singleton then perhaps try
pertypewithin(com.mycompany.myapp.webservices..*).
that may give us more clues.
cheers
Andy
On 3 June 2011 16:02, Abhijit Inamdar <ainam...@intrepidls.com> wrote:
>> Have you definetly confirmed the advice actually isn't being called?
> Yes that seems to be the case. I ripped out the MDC stuff and put in plain
> logger calls(just like System.out) & also attached a debugger to the tomcat
> instance, but no luck in either case.
>
> > the 'duringMyOp()' is actually redundant here because all advice in a
> 'percflow(X)' aspect has the implicit additional condition ...<snip>
> Thanks for the tip. Please bear with my noobishness here.
>
>>That would just be at one joinpoint though (if you see it once)
> Actually I see it a bunch of times. I'll try to see whether there is any
> correlation between the number of warnings and the number of logger calls. I
> guess it shouldn't matter as we see the join points in the bytecode.
>
>>Tricky to diagnose without a small failing sample.
> The problem is that my small sample(i.e. my prototype) doesn't fail :(. I'll
> continue plugging away at it making small diagnostic changes and see if I can
> come up with some interesting symptoms.
>
> You help is really appreciated. Have a great weekend.
>
> Abhi
>
> ________________________________________
> From: aspectj-users-boun...@eclipse.org [aspectj-users-boun...@eclipse.org]
> on behalf of Andy Clement [andrew.clem...@gmail.com]
> Sent: Friday, June 03, 2011 3:19 PM
> To: aspectj-users@eclipse.org
> Subject: Re: [aspectj-users] Puzzling problem using AspectJ
>
> Hi,
>
> Tricky to diagnose without a small failing sample.
>
> Have you definetly confirmed the advice actually isn't being called?
> Or are you inferring that because the log messages aren't prefixed? I
> just wonder if a System.out.println() in the before/after advice may
> tell us if the advice is actually running. It would seem very strange
> for the other before() advice to run and yet the MDC related advices
> not to run.
>
> Also, just to note:
>
> before():(duringMyOp() && !within(*..*Aspect) && !logCall() ) { ... etc
>
> the 'duringMyOp()' is actually redundant here because all advice in a
> 'percflow(X)' aspect has the implicit additional condition of '&&
> cflow(X)'. It does no harm though as the pointcut optimizer will be
> discarding the dup.
>
>
>> Another possible clue might be(in the compilation) ...
>>
>> [WARNING] does not match because declaring type is java.lang.Object, if
>> match desired use target(org.apache.log4j.Logger)
>> [Xlint:unmatchedSuperTypeInCall]
>
> That would just be at one joinpoint though (if you see it once) - I
> imagine you are expecting many joinpoints to hit. Perhaps another
> interesting datapoint would be changing it to be a call to something
> else. However, that wouldn't explain why it works in your prototype
> and not in the real app.
>
> cheers
> Andy
>
>
> On 3 June 2011 10:53, Abhijit Inamdar <ainam...@intrepidls.com> wrote:
>> One other thing ... I mentioned "my prototype" and "my real app" in my
>> original post and it seems that in your original reply you may have
>> misunderstood that to mean that I was trying load time weaving. Actually
>> neither use load time weaving. "My prototype" only refers to a toy app I
>> have to learn AspectJ, while "my real app" is the production app that I am
>> trying to enhance with AspectJ. The pointcuts in the two are identical
>> besides the fact that the paths in myOp() look different
>> (com.mycompany.myapp.webservices..*(..) vs ajia.messaging..*(..)). In the
>> prototype both myOp() and logCall() work exactly as expected while in the
>> real app only myOp() works while logCall() doesn't.
>
>> ________________________________________
>> From: aspectj-users-boun...@eclipse.org [aspectj-users-boun...@eclipse.org]
>> on behalf of Abhijit Inamdar [ainam...@intrepidls.com]
>> Sent: Friday, June 03, 2011 10:35 AM
>> To: aspectj-users@eclipse.org
>> Subject: Re: [aspectj-users] Puzzling problem using AspectJ
>>
>> Hi Andy,
>> Just to clarify, my aspect looks like this
>>
>> *************************************************
>> public aspect ChainAspect percflow(myop()) { ...
>>
>> <snipped>
>> private static final String MDC_KEY = "caller";
>>
>> pointcut logCall() : call(* org.apache.log4j.Logger.*(..)) &&
>> !within(*..*Aspect);
>>
>> before() : logCall() {
>> MDC.put(MDC_KEY, " " + myId + " " + depth++ + " " + " (" +
>> thisEnclosingJoinPointStaticPart.getSourceLocation()
>> + ") " +
>> thisEnclosingJoinPointStaticPart.getSignature().toShortString());
>> }
>>
>> after() : logCall() {
>> MDC.remove(MDC_KEY);
>> }
>>
>> pointcut myop(): call(* com.mycompany.myapp.webservices..*(..)) ;
>>
>> pointcut duringMyOp() : cflow(myop());
>>
>> before():(duringMyOp() && !within(*..*Aspect) && !logCall() ) { ... etc
>>
>> *************************************************
>>
>> The before advice for myop() works fine. It basically logs entry into
>> methods(basic tracing) with a unique Id per cflow and depth of the call.
>> the logCall() pointcut is intended to wrap existing logging with the unique
>> Id of the cflow. The logCall() pointcut is the one that does not seem to
>> work. i.e. neither the before nor the after advice for it is never entered.
>> In the bytecode below myOp() seems to be myAspect$4$48864b4c, while
>> logCall() is myAspect$3$58016c43.
>>
>> Another possible clue might be(in the compilation) ...
>>
>> [WARNING] does not match because declaring type is java.lang.Object, if
>> match desired use target(org.apache.log4j.Logger)
>> [Xlint:unmatchedSuperTypeInCall]
>>
>> Google shows old discussion about how this is an unhelpful and possibly
>> misleading message.
>>
>> Thanks for all your help,
>> Abhi
>>
>>
>>
>>
>>
>>
>>
>> ________________________________________
>> From: aspectj-users-boun...@eclipse.org [aspectj-users-boun...@eclipse.org]
>> on behalf of Andy Clement [andrew.clem...@gmail.com]
>> Sent: Friday, June 03, 2011 9:35 AM
>> To: aspectj-users@eclipse.org
>> Subject: Re: [aspectj-users] Puzzling problem using AspectJ
>>
>> Hi,
>>
>> I see, that explains it, the [with runtime test] is a check to
>> determine if you are in the cflow.
>>
>>> I am a little puzzled by what seem to be two calls to after(119 & 135).
>>
>> You have after advice, so it must intercept both the main exit paths
>> (after returning) and any exception exit routes (after throwing).
>>
>> This one shows the call to the aspect prior to exiting via exception
>> (athrow):
>>
>>> 119: invokevirtual #336; //Method
>>> com/mycompany/myapp/aspects/tracing/myAspect.ajc$after$com_mycompany_myapp_aspects_tracing_myAspect$3$58016c43:()V
>>> 122: aload 13
>>> 124: athrow
>>
>> Are you positive the trace calls you are expecting to be augmented are
>> in the cflow of the myop() pointcut?
>>
>> Also that wherever myop() is matching is accessible to be woven by
>> AspectJ? It will need to insert code at where myop() matches to tag
>> the subsequent flows as being 'in the cflow of myop()'. You could try
>> something simple like a separate aspect:
>>
>> aspect Foo {
>> before(): myop() {}
>> }
>>
>> Check if that aspect weaves ok or if it complains that it cannot
>> access something in order to weave it.
>>
>> cheers
>> Andy
>>
>> On 31 May 2011 12:52, Abhijit Inamdar <ainam...@intrepidls.com> wrote:
>>> Thanks for your response Andy.
>>> This is not a singleton aspect. It is actually percflow(myop()) { ...
>>> where myop() is another pointcut.
>>>
>>> Here is a snippet of the woven output around a log statement("Entering
>>> isValidRequest" in this case):
>>>
>>> 76: invokestatic #367; //Method
>>> org/aspectj/runtime/reflect/Factory.makeJP:(Lorg/aspectj/lang/JoinPoint$StaticPart;Ljava/lang/Object;Ljava/lang/Object;)Lorg/aspectj/lang/JoinPoint;
>>> 79: getstatic #379; //Field
>>> ajc$tjp_4:Lorg/aspectj/lang/JoinPoint$EnclosingStaticPart;
>>> 82: invokevirtual #355; //Method
>>> com/mycompany/myapp/aspects/tracing/myAspect.ajc$before$com_mycompany_myapp_aspects_tracing_myAspect$4$48864b4c:(Lorg/aspectj/lang/JoinPoint;Lorg/aspectj/lang/JoinPoint$StaticPart;)V
>>> 85: getstatic #34; //Field logger:Lorg/apache/log4j/Logger;
>>> 88: ldc #48; //String Entering isValidRequest
>>> 90: invokestatic #331; //Method
>>> com/mycompany/myapp/aspects/tracing/myAspect.hasAspect:()Z
>>> 93: ifeq 102
>>> 96: invokestatic #325; //Method
>>> com/mycompany/myapp/aspects/tracing/myAspect.aspectOf:()Lcom/mycompany/myapp/aspects/tracing/myAspect;
>>> 99: invokevirtual #328; //Method
>>> com/mycompany/myapp/aspects/tracing/myAspect.ajc$before$com_mycompany_myapp_aspects_tracing_myAspect$2$58016c43:()V
>>> 102: invokevirtual #50; //Method
>>> org/apache/log4j/Logger.warn:(Ljava/lang/Object;)V
>>> 105: goto 125
>>> 108: astore 13
>>> 110: invokestatic #331; //Method
>>> com/mycompany/myapp/aspects/tracing/myAspect.hasAspect:()Z
>>> 113: ifeq 122
>>> 116: invokestatic #325; //Method
>>> com/mycompany/myapp/aspects/tracing/myAspect.aspectOf:()Lcom/mycompany/myapp/aspects/tracing/myAspect;
>>> 119: invokevirtual #336; //Method
>>> com/mycompany/myapp/aspects/tracing/myAspect.ajc$after$com_mycompany_myapp_aspects_tracing_myAspect$3$58016c43:()V
>>> 122: aload 13
>>> 124: athrow
>>> 125: nop
>>> 126: invokestatic #331; //Method
>>> com/mycompany/myapp/aspects/tracing/myAspect.hasAspect:()Z
>>> 129: ifeq 138
>>> 132: invokestatic #325; //Method
>>> com/mycompany/myapp/aspects/tracing/myAspect.aspectOf:()Lcom/mycompany/myapp/aspects/tracing/myAspect;
>>> 135: invokevirtual #336; //Method
>>> com/mycompany/myapp/aspects/tracing/myAspect.ajc$after$com_mycompany_myapp_aspects_tracing_myAspect$3$58016c43:()V
>>>
>>>
>>> I am a little puzzled by what seem to be two calls to after(119 & 135).
>>>
>>>
>>>
>>> ________________________________________
>>> From: aspectj-users-boun...@eclipse.org [aspectj-users-boun...@eclipse.org]
>>> on behalf of Andy Clement [andrew.clem...@gmail.com]
>>> Sent: Monday, May 30, 2011 8:56 AM
>>> To: aspectj-users@eclipse.org
>>> Subject: Re: [aspectj-users] Puzzling problem using AspectJ
>>>
>>> Hi,
>>>
>>> So you are not loadtime weaving, you are just compile time weaving.
>>> The weaveinfo messages indicate the bytecode is being modified. I
>>> guess you could check the woven output from the compile and verify the
>>> calls to the logger have been advised. Using 'javap -private
>>> -verbose' against a class in the woven output you should see wherever
>>> there is a call to getLogger there is a call to the advice?
>>>
>>> Actually, one thing does seem unusual. Is your pointcut definetly just
>>> this:
>>>
>>> call(* org.apache.log4j.Logger.*(..)) && !within(*..*Aspect);
>>>
>>> and in a singleton aspect?
>>>
>>> Because that can be fully statically matched, so I don't understand
>>> why your weaveinfo message is suffixed with '[with runtime test]'. If
>>> the runtime test (whatever it is) is failing it will not be running
>>> your advice. If you want to post the snippet of bytecode around the
>>> calls to getLogger we can check what the runtime test is.
>>>
>>> Andy
>>>
>>>
>>> _______________________________________________
>>> aspectj-users mailing list
>>> aspectj-users@eclipse.org
>>> https://dev.eclipse.org/mailman/listinfo/aspectj-users
>>>
>> _______________________________________________
>> aspectj-users mailing list
>> aspectj-users@eclipse.org
>> https://dev.eclipse.org/mailman/listinfo/aspectj-users
>> _______________________________________________
>> aspectj-users mailing list
>> aspectj-users@eclipse.org
>> https://dev.eclipse.org/mailman/listinfo/aspectj-users
>> _______________________________________________
>> aspectj-users mailing list
>> aspectj-users@eclipse.org
>> https://dev.eclipse.org/mailman/listinfo/aspectj-users
>>
> _______________________________________________
> aspectj-users mailing list
> aspectj-users@eclipse.org
> https://dev.eclipse.org/mailman/listinfo/aspectj-users
> _______________________________________________
> aspectj-users mailing list
> aspectj-users@eclipse.org
> https://dev.eclipse.org/mailman/listinfo/aspectj-users
>
_______________________________________________
aspectj-users mailing list
aspectj-users@eclipse.org
https://dev.eclipse.org/mailman/listinfo/aspectj-users
