1

Problem

I want to print out the request url and response before running all calls to method

public class UpdateRequester {
   private void throwMessage(String requestUrl, String page) {
      //Some code inside
   }
}

the method will be called is in the Test class:

public class Test {
  public void testUpdate() {
    Executors.scheduleWithFixedDelay(new Runnable() {
        public void run() {
          //It will call throwMessage sometimes in the future
        }
    }, ...);
  }  
}

so I designed an aspect:

public aspect TestUpdate {
   static final void println(String s) {
     System.out.println(s);
   }

   pointcut testUpdateFlow() : cflow(this(Test) && execution(void testUpdate()));

   pointcut throwMessageCut(String url, String response) : this(UpdateRequester) && args(url, response) && execution(void throwMessage(String, String));

   before(String url, String response) : testUpdateFlow() && throwMessageCut( url,  response) {
    println("=============Url============");
    println(url);
    println("============Respnse=========");
    println(response);
   }
}

The aspect doesn't print anything to the console. If I remove testUpdateFlow(), it did print to the console. I think that cflow in aspectJ doesn't consider the code running by Executors.scheduleWithFixedDelay to be in the flow of testUpdate(). Is there any way I can use for aspectJ to detect thread-crossing call in this situation?

Tuan Do
  • 357
  • 1
  • 2
  • 11

1 Answers1

2

Let us assume we have these classes:

package de.scrum_master.app;

public class UpdateRequester {
    public void doSomething() {
        throwMessage("http://my.url.org/foo", "my page");
    }

    private void throwMessage(String requestUrl, String page) {
        System.out.println("Throwing message for request " + requestUrl + " on page '" + page + "'");
    }
}

Because throwMessage(..) is private in your example, I deliberately added a public method doSomething() which can be called by the test class to which I also added a main(..) method as an entry point for my test:

package de.scrum_master.app;

import java.util.concurrent.Executors;
import java.util.concurrent.ScheduledExecutorService;
import java.util.concurrent.TimeUnit;

public class Test {
    public void testUpdate() {
        ScheduledExecutorService executorService = Executors.newScheduledThreadPool(10);
        executorService.scheduleWithFixedDelay(
            new Runnable() {
                public void run() {
                    new UpdateRequester().doSomething();
                }
            },
            500L,
            1000L,
            TimeUnit.MILLISECONDS
        );
    }

    public static void main(String[] args) {
        new Test().testUpdate();
    }
}

Now let us print an exception stack trace from our before() advice in order to find out what the control flow really is:

package de.scrum_master.app;

import de.scrum_master.app.UpdateRequester;

public aspect TestUpdate {
    pointcut throwMessageCut(String url, String response) :
        this(UpdateRequester) &&
        args(url, response) &&
        execution(void throwMessage(String, String));

    before(String url, String response) :
        /*testUpdateFlow() &&*/
        throwMessageCut(url,  response)
    {
        System.out.println(thisJoinPoint);
        new Exception().printStackTrace(System.out);
    }
}

You see a stack trace like this:

execution(void de.scrum_master.app.UpdateRequester.throwMessage(String, String))
java.lang.Exception
    at de.scrum_master.app.TestUpdate.ajc$before$de_scrum_master_app_TestUpdate$1$33fbc0c(TestUpdate.aj:16)
    at de.scrum_master.app.UpdateRequester.throwMessage(UpdateRequester.java:9)
    at de.scrum_master.app.UpdateRequester.doSomething(UpdateRequester.java:5)
    at de.scrum_master.app.Test$1.run(Test.java:13)
    at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
    at java.util.concurrent.FutureTask.runAndReset(Unknown Source)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(Unknown Source)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
    at java.lang.Thread.run(Unknown Source)
Throwing message for request http://my.url.org/foo on page 'my page'

I.e. that this() is not Test but Test$1 which is the anonymous inner Runnable subclass you define in your code. You also see that Test.testUpdate() is not really in the control flow as it is nowhere to be seen in the stack trace. You can modify the pointcut like this:

pointcut testUpdateFlow() :
    cflow(
        this(Runnable) &&
        withincode(public void Test..*.run(..)) &&
        call(* UpdateRequester.*(..))
    );

It means: In the control flow of

  • an instance of Runnable,
  • somewhere within the code of a public void run(..) method defined below Test (inner class),
  • calling any method of UpdateRequester.

I.e. now the aspect looks like this (the console output stays the same):

package de.scrum_master.app;

import de.scrum_master.app.UpdateRequester;
import java.lang.Runnable;

public aspect TestUpdate {
    pointcut testUpdateFlow() :
        cflow(
            this(Runnable) &&
            withincode(public void Test..*.run(..)) &&
            call(* UpdateRequester.*(..))
        );

    pointcut throwMessageCut(String url, String response) :
        this(UpdateRequester) &&
        args(url, response) &&
        execution(void throwMessage(String, String));

    before(String url, String response) :
        testUpdateFlow() &&
        throwMessageCut(url,  response)
    {
        System.out.println(thisJoinPoint);
        new Exception().printStackTrace(System.out);
    }
}

You could also use nested cflow() statements like this:

pointcut testUpdateFlow() :
    cflow(
        this(Runnable) &&
        cflow(execution(public void Test..*.run(..))) &&
        call(* UpdateRequester.*(..))
    );

Alternatively, in order to avoid the anonymous inner class you can create a named inner class:

package de.scrum_master.app;

import java.util.concurrent.Executors;
import java.util.concurrent.ScheduledExecutorService;
import java.util.concurrent.TimeUnit;

public class Test {
    public static class UpdateRequesterStarter implements Runnable {
        public void run() {
            new UpdateRequester().doSomething();
        }
    }

    public void testUpdate() {
        ScheduledExecutorService executorService = Executors.newScheduledThreadPool(10);
        executorService.scheduleWithFixedDelay(
            new UpdateRequesterStarter(),
            500L,
            1000L,
            TimeUnit.MILLISECONDS
        );
    }

    public static void main(String[] args) {
        new Test().testUpdate();
    }
}

Now the output changes, please note the difference in the call stack:

execution(void de.scrum_master.app.UpdateRequester.throwMessage(String, String))
java.lang.Exception
    at de.scrum_master.app.TestUpdate.ajc$before$de_scrum_master_app_TestUpdate$1$9c6f966b(TestUpdate.aj:24)
    at de.scrum_master.app.UpdateRequester.throwMessage(UpdateRequester.java:9)
    at de.scrum_master.app.UpdateRequester.doSomething(UpdateRequester.java:5)
    at de.scrum_master.app.Test$UpdateRequesterStarter.run(Test.java:10)
    at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
    at java.util.concurrent.FutureTask.runAndReset(Unknown Source)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(Unknown Source)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
    at java.lang.Thread.run(Unknown Source)
Throwing message for request http://my.url.org/foo on page 'my page'

Now you can refine/simplify the testUpdateFlow() pointcut to:

package de.scrum_master.app;

import de.scrum_master.app.UpdateRequester;
import de.scrum_master.app.Test.UpdateRequesterStarter;

public aspect TestUpdate {
    pointcut testUpdateFlow() :
        cflow(execution(public void UpdateRequesterStarter.run(..)));

    pointcut throwMessageCut(String url, String response) :
        this(UpdateRequester) &&
        args(url, response) &&
        execution(void throwMessage(String, String));

    before(String url, String response) :
        testUpdateFlow() &&
        throwMessageCut(url,  response)
    {
        System.out.println(thisJoinPoint);
        new Exception().printStackTrace(System.out);
    }
}

Please also note the changed import statements.

kriegaex
  • 63,017
  • 15
  • 111
  • 202
  • I didn't know about the syntax specifying "somewhere within the code of a public void run(..) method defined below Test (inner class)". Thanks a lot. – Tuan Do Mar 29 '16 at 01:41