Re: [aspectj-users] Met [org.aspectj.lang.NoAspectBoundException] while

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index] [List Home]

Re: [aspectj-users] Met [org.aspectj.lang.NoAspectBoundException] while running a post-compile woven (bytecode woven) apache thrift library

From: "Alexander Kriegisch" <alexander@xxxxxxxxxxxxxx>
Date: Sat, 26 May 2018 06:03:27 +0200 (CEST)
Delivered-to: aspectj-users@xxxxxxxxxxx
List-archive: <https://dev.eclipse.org/mailman/private/aspectj-users>
List-help: <mailto:aspectj-users-request@eclipse.org?subject=help>
List-subscribe: <https://dev.eclipse.org/mailman/listinfo/aspectj-users>, <mailto:aspectj-users-request@eclipse.org?subject=subscribe>
List-unsubscribe: <https://dev.eclipse.org/mailman/options/aspectj-users>, <mailto:aspectj-users-request@eclipse.org?subject=unsubscribe>
User-agent: ALL-INKL Webmail 2.11

@Yongle

When I measured my own vs your code using my own test program with a loop counter of 10,000 (i.e. 60,000 threads get created) with deactivated log output, both versions had the same runtime of on average 9,500 ms (9.5 s). I could not detect a performance penalty there. But maybe there is one in other scenarios.

What is most important, though, it that the code does the right thing. And your ThreadLocal approach is just not doing that because of how ThreadLocal works: It gets re-initialised for new threads.

But first the updated source code (see attached ZIP file, not quoting everything inline this time). I only slightly changed your solution (not its base functionality) by adding more static member:

  public static boolean ACTIVE = true;
  public static final Set<String> instanceIDs = Collections.synchronizedSet(new HashSet<>());

ACTIVE can (de)activate the pointcuts in your aspect as well as in mine. This way I could more easily switch between both our implementations by just switching a toggle in the test program. Of course you don't need that in production if you don't like it. It just makes testing multiple variants easier.

instanceIDs is an additional set counting all threads created so as to have a double-checking mechanism. We will see that later in the source code.

My own code has the same members. You can configure the test by changing this part:

  private static boolean useOriginalAspect = true;

  public static void main(String[] args) throws InterruptedException {
    final int MAX_COUNT = 1;

Just edit useOriginalAspect and/or MAX_COUNT to your liking. The default setting uses your aspect class RunnablesCallables, the 'false' setting uses mine called RunnablesCallablesAspect.

Oh, BTW, I factored out the interface InstrumentedRunnableCallable and its aspect part into its own aspect class so as to make it usable for both our aspects mentioned above. If I did not do that, there would be compilation problems because the ITD stuff would be done twice. This also makes the aspects a bit easier to read, separating the ITD from the other cross-cutting part. Only Eclipse behaves a bit strangely, compiling everything just fine but sometimes showing error markers in RunnablesCallables and RunnablesCallablesAspect.

Now, when running the test program with my aspect (useOriginalAspect = false), the console log says:

[Create Runnable/Callable] TID=1, de.scrum_master.app.SomeRunnable(instanceID=0, creatorTID=1)
[Create Runnable/Callable] TID=1, de.scrum_master.app.Application$InnerStaticRunnable(instanceID=0, creatorTID=1)
[Create Runnable/Callable] TID=1, de.scrum_master.app.Application$InnerRunnable(instanceID=0, creatorTID=1)
[Create Runnable/Callable] TID=1, de.scrum_master.app.SomeRunnable(instanceID=1, creatorTID=1)
[Create Runnable/Callable] TID=12, de.scrum_master.app.SomeRunnable(instanceID=2, creatorTID=12)
[Create Runnable/Callable] TID=1, de.scrum_master.app.RunnableBase(instanceID=0, creatorTID=1)
Duration (minus sleeping time) = 19 ms

So far, so good. When running the test program with your aspect (useOriginalAspect = true), the console log says:

[Create Runnable/Callable] TID=1, de.scrum_master.app.SomeRunnable(instanceID=0, creatorTID=1)
[Create Runnable/Callable] TID=1, de.scrum_master.app.Application$InnerStaticRunnable(instanceID=0, creatorTID=1)
[Create Runnable/Callable] TID=1, de.scrum_master.app.Application$InnerRunnable(instanceID=0, creatorTID=1)
[Create Runnable/Callable] TID=1, de.scrum_master.app.SomeRunnable(instanceID=1, creatorTID=1)
[Create Runnable/Callable] TID=12, de.scrum_master.app.SomeRunnable(instanceID=0, creatorTID=12)
[Create Runnable/Callable] TID=1, de.scrum_master.app.RunnableBase(instanceID=0, creatorTID=1)
Duration (minus sleeping time) = 22 ms
Unexpected counter value for class de.scrum_master.app.SomeRunnable: expected=3, actual=2
Unexpected number of total IDs: expected=6, actual=5

Uh-oh! I highlighted the problematic part for you.

Bottom line: Maybe you want to use my code and get rid of your ThreadLocal example. Maybe you misunderstand what TL does. It does not lock or synchronise anything. On opposite, it just spawns new variable copies for each new thread. If you still insist that TL has any value here (even though I would not understand why), there sure is a way to fix your code, too, but I did not look into it.

Regards
--
Alexander Kriegisch
https://scrum-master.de

Yongle Zhang schrieb am 23.05.2018 10:15:

Hi Alexander,

Thank you for your detailed review and explanation. Really appreciate your effort and time into this. And thank you for showing how to write good-quality code.

There are several things that I want to clarify.

I made a mistake copying code and renaming stuff from my code base.

Thanks for pointing it out. Instead of using a HashMap<java.lang.Class, ThreadLocal>, a ConcurrentHashMap<java.lang.Class, ThreadLocal> should be used.
id_assigned guard

Thanks for pointing out that “after returning” advice works for nested constructors like this(11). I removed it.
ThreadLocal

From my understanding, ThreadLocal is a ConcurrentHashMap whose key is Thread and value is the object inside ThreadLocal.

I think I didn’t make it clear. Using ThreadLocal means that I’m actually using (ThreadID and MyID) combined as the ID. And I ignored that ThreadID could be reused because I’m targeting for thread pools that use long-live threads. My current project requires my instrumentation to minimize introduction of any resource contention, so I tried to minimize introduced synchronization in this way.

Using ConcurrentHashMap without proper synchronization doesn’t work, but using ConcurrentHashMap<XXX, ThreadLocal> with minimum synchronization (i.e., only synchronize when initializing the ThreadLocal - double check luckily works) does work. I put a test that could be compiled and executed here.

Test that shows it works

import java.util.*;
import java.util.concurrent.ConcurrentHashMap;
import java.util.concurrent.atomic.AtomicInteger;

public class ConcurrentErrorTest {

  public static Map<MyClass, ThreadLocal<Long>> counters = new
      ConcurrentHashMap<MyClass, ThreadLocal<Long>>();

  public static long getMyCounter(MyClass clazz) {
    ThreadLocal<Long> local = counters.get(clazz);
    if (local == null) {
      // need to initialize the ThreadLocal
      // This is the only place that needs synchronization.
      synchronized (clazz) { // synchronize on the given clazz is enough
        // Double check to avoid multi threads entered the previous if statement
        if (local == null) {
          local = new ThreadLocal<Long>() {
            @Override
            protected Long initialValue() {
              return (long) 0;
            }
          };
          counters.put(clazz, local);
        }
      }
    }
    return (long) local.get();
  }

  private static void setMyCounter(MyClass clazz, long counter) {
    ThreadLocal<Long> local = counters.get(clazz);
    // This function is only called in incrementMyCounter() so it's not null.
    assert local != null;
    local.remove();
    local.set(counter);
  }

  public static void incrementMyCounter(MyClass clazz) {
    setMyCounter(clazz, getMyCounter(clazz)+1);
  }
   
  private static final java.util.Random RANDOM = new java.util.Random();
  // passed this unsafe test, but it takes a long time, please change ConcurrentErrorTest.limit = 100 before testing with this method.   
  public static void incrementMyCounterUnsafe(MyClass clazz)
      throws InterruptedException {
    long counter = getMyCounter(clazz);
    try {
      Thread.sleep(RANDOM.nextInt(10));
    } catch (InterruptedException e) {
      throw e;
    }
    setMyCounter(clazz, counter + 1);
  }

  static final AtomicInteger errCount = new AtomicInteger();
  static final int numThreads = 10;
    static final int limit = 1000;


  // Mimic java.lang.Class<?> objects
  private static List<MyClass> keys;
  static {
    keys = new ArrayList<MyClass>();
    for (int j = 0; j < limit; j++) {
      keys.add(new MyClass(j));
    }
  }

  private static class MyClass {
    private int id;
    public MyClass(int id) {
      this.id = id;
    }
    @Override
    public String toString() {
      return Integer.toString(id);
    }
  }

  public static void main(String[] args) throws InterruptedException
  {
    long startTime = System.currentTimeMillis();

    List<Thread> threads = new LinkedList<Thread>();

    for (int i = 0; i < numThreads; i++)
    {
      Thread t = getThread();
      threads.add(t);
      t.start();
    }

    for (int i = 0; i < numThreads; i++)
    {
      threads.get(i).join();
    }

    System.out.println("Length:" + counters.size());
    System.out.println("Errors recorded: " + errCount.get());

    long stopTime = System.currentTimeMillis();
    long elapsedTime = stopTime - startTime;
    System.out.println(elapsedTime);
  }

  private static Thread getThread()
  {
    return new Thread(new Runnable() {
      public void run()
      {
          try
          {
            for (MyClass key : keys) {
              for (int i = 0; i < limit; i++) {
                getMyCounter(key);
                incrementMyCounter(key);
              }
            }
          }
          catch (Exception e)
          {
            System.out.println("P - Error occured: " + e.toString());
            e.printStackTrace();
            errCount.incrementAndGet();
          }

      }
    });
  }
}

Running it on my laptop costs 392 milliseconds. I also tested using your method (replace the map and getter and incrementor function as follows), it took 1566 milliseconds.

  private static final Map<MyClass, Long> counters =
      new ConcurrentHashMap<MyClass, Long>();

  public static synchronized long getMyCounter(MyClass clazz) {
      Long counter = counters.get(clazz);
      return counter == null ? 0 : counter;
  }

  private static synchronized void incrementMyCounter(MyClass clazz) {
      counters.put(clazz, getMyCounter(clazz) + 1);
  }

Extra synchronization needed in your method

In the constructor, an extra synchronization is needed (without this synchronization, the incrementation would be correct, but 2 InstrumentedRunnableCallable could get the same ID):

  after() returning(InstrumentedRunnableCallable runnableCallable) :
    call(InstrumentedRunnableCallable+.new(..))
  {
    runnableCallable.setCreatorTID(currentThread().getId());
     
    // without this synchronization, the incrementation would be correct,  
    // but 2 InstrumentedRunnableCallable could get the same ID.  
    synchronized(instanceCounters) {
        runnableCallable.setId(getInstanceCounter(runnableCallable.getClass()));
        incrementInstanceCounter(runnableCallable.getClass());
    }
    // Use this instead in order to mess up instance counters  
    //incrementInstanceCounterThreadUnsafe(runnableCallable.getClass());
    printLogMessage("[Create Runnable/Callable]", runnableCallable);
  }

After fixing bugs and refactoring for my previous aspect

Change the HashMap to ConcurrentHashMap
Removed _id_assigned guard.

import java.util.HashMap;
import java.util.Map;
import java.util.concurrent.Callable;
import java.lang.Runnable;
import java.util.concurrent.ConcurrentHashMap;
import java.util.concurrent.Future;

privileged aspect RunnablesCallables {

  public static Map<java.lang.Class, ThreadLocal<Long<>()>> _counters = new
      ConcurrentHashMap();

  public static long getCounter(java.lang.Class clazz) {
    ThreadLocal<Long> local = _counters.get(clazz);
    if (local == null) { // need to initialize the ThreadLocal
      synchronized (clazz) { // synchronize on the given clazz is enough
        // Check again to avoid multi threads entered the previous if statement
        if (local == null) {
          local = new ThreadLocal<Long>() {
            @Override
            protected Long initialValue() {
              return (long) 0;
            }
          };
          _counters.put(clazz, local);
        }
      }
    }
    return (long) local.get();
  }

  private static void setCounter(java.lang.Class clazz, long counter) {
    ThreadLocal<Long> local = _counters.get(clazz);
    local.remove();
    local.set(counter);
  }

  public static void incrementCounter(java.lang.Class clazz) {
    setCounter(clazz, getCounter(clazz)+1);
  }

  public interface InstrumentedRunnableCallable {}

  private long InstrumentedRunnableCallable._id = -1;

  // Java could reuse thread ID. Ignored for now since we target thread pool that use long-live threads.  

  // Records which thread created this Object.
  private long InstrumentedRunnableCallable._creator_tid = -1;

  public long InstrumentedRunnableCallable.getId() {
    return _id;
  }
  public void InstrumentedRunnableCallable.setId(long id) {
    _id = id;
  }

  public long InstrumentedRunnableCallable.getCreatorTid() {
    return _creator_tid;
  }
  public void InstrumentedRunnableCallable.setCreatorTid(long id) {
    _creator_tid = id;
  }

  declare parents: (Runnable)+ implements InstrumentedRunnableCallable;
  declare parents: (Callable)+ implements InstrumentedRunnableCallable;

  after() returning(InstrumentedRunnableCallable r):
      (call(InstrumentedRunnableCallable+.new(..))) {

      r.setCreatorTid(Thread.currentThread().getId());
      r.setId(RunnablesCallables.getCounter(r.getClass()));
      RunnablesCallables.incrementCounter(r.getClass());

  }

  Object around(InstrumentedRunnableCallable runnableCallable):
    this(runnableCallable) &&
    (execution(void Runnable+.run(..)) || execution(* Callable+.call(..)))
  {
    printLogMessage("[Before Runnable.run() / Callable.call()]", runnableCallable);
    Object result = proceed(runnableCallable);
    printLogMessage("[After  Runnable.run() / Callable.call()]", runnableCallable);
    return result;
  }

  private void printLogMessage(String prefix, InstrumentedRunnableCallable runnableCallable) {
    System.out.printf("%s TID=%d, %s%n", prefix, Thread.currentThread().getId(), runnableCallable.toStringIRC());
  }

  public String InstrumentedRunnableCallable.toStringIRC() {
    return getClass().getName() + "(instanceID=" + _id + ", creatorTID=" + _creator_tid + ")";
  }

}

My aspect could be over-engineered for usual use cases.

Added extra needed synchronization in your aspect

package de.scrum_master.aspect;

import static java.lang.Thread.currentThread;

import java.util.Map;
import java.util.concurrent.Callable;
import java.util.concurrent.ConcurrentHashMap;

public privileged aspect RunnablesCallablesAspect {
  private static final Map<Class<?>, Long> instanceCounters = new ConcurrentHashMap<>();

  public static synchronized long getInstanceCounter(Class<?> clazz) {
    Long counter = instanceCounters.get(clazz);
    return counter == null ? 0 : counter;
  }

  private static synchronized void incrementInstanceCounter(Class<?> clazz) {
    instanceCounters.put(clazz, getInstanceCounter(clazz) + 1);
  }

  // Only for demo purposes, can be deleted
  private static final java.util.Random RANDOM = new java.util.Random();  
  private static void incrementInstanceCounterThreadUnsafe(Class<?> clazz) {
    long counter = getInstanceCounter(clazz);
    try {
      Thread.sleep(RANDOM.nextInt(10));
    } catch (InterruptedException e) {
      throw new org.aspectj.lang.SoftException(e);
    }
    instanceCounters.put(clazz, counter + 1);
  }

  after() returning(InstrumentedRunnableCallable runnableCallable) :
    call(InstrumentedRunnableCallable+.new(..))
  {
    runnableCallable.setCreatorTID(currentThread().getId());
     
    synchronize(instanceCounters){
        runnableCallable.setId(getInstanceCounter(runnableCallable.getClass()));
        incrementInstanceCounter(runnableCallable.getClass());
    }
    // Use this instead in order to mess up instance counters  
    //incrementInstanceCounterThreadUnsafe(runnableCallable.getClass());
    printLogMessage("[Create Runnable/Callable]", runnableCallable);
  }

  Object around(InstrumentedRunnableCallable runnableCallable):
    this(runnableCallable) &&
    (execution(void Runnable+.run(..)) || execution(* Callable+.call(..)))
  {
    printLogMessage("[Before Runnable.run() / Callable.call()]", runnableCallable);
    Object result = proceed(runnableCallable);
    printLogMessage("[After  Runnable.run() / Callable.call()]", runnableCallable);
    return result;
  }

  private void printLogMessage(String prefix, InstrumentedRunnableCallable runnableCallable) {
    System.out.printf("%s TID=%d, %s%n", prefix, currentThread().getId(), runnableCallable.toStringIRC());
  }

  public interface InstrumentedRunnableCallable {}

  private long InstrumentedRunnableCallable.id = -1;
  private long InstrumentedRunnableCallable.creatorTID = -1;

  public long InstrumentedRunnableCallable.getId() { return id; }
  public void InstrumentedRunnableCallable.setId(long id) { this.id = id; }

  public long InstrumentedRunnableCallable.getCreatorTID() { return creatorTID; }
  public void InstrumentedRunnableCallable.setCreatorTID(long creatorTID) { this.creatorTID = creatorTID; }

  public String InstrumentedRunnableCallable.toStringIRC() {
    return getClass().getName() + "(instanceID=" + id + ", creatorTID=" + creatorTID + ")";
  }

  declare parents: Runnable+ implements InstrumentedRunnableCallable;
  declare parents: Callable+ implements InstrumentedRunnableCallable;
}

Thank you again for your responsiveness. Please feel free to give any more advice.

regards,

Yongle

On May 22, 2018 at 7:45:10 AM, Alexander Kriegisch (alexander@xxxxxxxxxxxxxx) wrote:

Hi Yongle!

ThreadLocal (TL) is not helping you here, as I said. Either you misunderstand what TL does or it was just a simple error in your analysis or maybe a refactoring artifact. Maybe in an older implementation of your code it was somehow helpful, but certainly not here. Here is a refactored aspect. I changed several things, among them the following:

As I said, no more ThreadLocal, i.e. also no more null checks.

Got rid of unnecessary boolean flag in the interface implementation. If you wanted to, you could just check if the ID or creator thread ID are != -1 in order to find out if the members have been initialised or not. But actually that is not necessary because the "after returning" advice for constructor calls will not trigger for super class constructors or calls like this(11) in constructors.

Made the accessor methods for the counters in the map synchronized. Synchronizing on whole classes like you did is a bit too much. I also got rid of the set* method, the increment* one is enough. I also made everything but getInstanceCounter(Class<?> clazz) private, and the latter is only public because the driver application uses it for checking if the counters are as expected.

Changed the static map into a ConcurrentHashMap. Actually this is not strictly necessary for this implementation because the accessor methods are already synchronised, but it does not hurt either.

Added a non-threadsafe method incrementInstanceCounterThreadUnsafe(Class<?> clazz) which you can use to demonstrate how not to do it. This demonstrates that ConcurrentHashMap does not help at all if you just do synchronisation wrong.

Compounded your before/after advices into one around advice.

Factored out some redundant logging code into a helper method.

Renamed your members to use the Java standardNamingStyle instead of Non_standardScheme. I also got rid of the irritating "My_" prefix.

Also renamed members and accessor methods in the interface implementation.

Renamed the whole aspect.

Added some more complexity to the driver application with the sample classes in order to more properly test for concurrency.

So here is the revised code:
package de.scrum_master.app;

class RunnableBase implements Runnable {
  @Override
  public void run() {
//    System.out.println("Running runnable base");
  }
}
package de.scrum_master.app;

class SomeRunnable extends RunnableBase {
  public SomeRunnable() {
    this(11);
//    System.out.println("SomeRunnable default constructor");
  }

  public SomeRunnable(int dummyParameter) {
    super();
//    System.out.println("SomeRunnable parametrised constructor");
  }

  @Override
  public void run() {
//    System.out.println("Running some runnable");
  }
}
package de.scrum_master.app;

import static de.scrum_master.aspect.RunnablesCallablesAspect.getInstanceCounter;
import static java.lang.System.currentTimeMillis;

public class Application {
  private static class InnerStaticRunnable implements Runnable {
    @Override
    public void run() {
//      System.out.println("Running inner static runnable");
    }
  }

  private class InnerRunnable implements Runnable {
    @Override
    public void run() {
//      System.out.println("Running inner runnable");
      new Thread(new SomeRunnable()).start();
    }
  }

  public void doSomething() {
    new Thread(new InnerRunnable()).start();
    new Thread(new SomeRunnable()).start();
  }

  private static void checkCounter(Class<?> clazz, long expectedCount) throws RuntimeException {
    long instanceCounter = getInstanceCounter(clazz);
    if (instanceCounter != expectedCount)
      throw new RuntimeException(
        "Unexpected counter value for class " + clazz.getName() +
        ": expected="+ expectedCount +
        ", actual=" + instanceCounter
      );
  }

  public static void main(String[] args) throws InterruptedException {
    final int MAX_COUNT = 100;

    long startTime = currentTimeMillis();
    for (int i = 0; i < MAX_COUNT; i++) {
      new Thread(new SomeRunnable()).start();
      new Thread(new Application.InnerStaticRunnable()).start();
      new Application().doSomething();
      new Thread(new RunnableBase()).start();
    }
    Thread.sleep(250); // Unelegant way to wait for threads to finish
    System.out.printf("Duration (minus sleeping time) = %d ms%n", currentTimeMillis() - startTime - 250);

    checkCounter(Application.InnerStaticRunnable.class, MAX_COUNT);
    checkCounter(Application.InnerRunnable.class, MAX_COUNT);
    checkCounter(SomeRunnable.class, MAX_COUNT * 3);
    checkCounter(RunnableBase.class, MAX_COUNT);
  }
}
package de.scrum_master.aspect;

import static java.lang.Thread.currentThread;

import java.util.Map;
import java.util.concurrent.Callable;
import java.util.concurrent.ConcurrentHashMap;

public privileged aspect RunnablesCallablesAspect {
  private static final Map<Class<?>, Long> instanceCounters = new ConcurrentHashMap<>();

  public static synchronized long getInstanceCounter(Class<?> clazz) {
    Long counter = instanceCounters.get(clazz);
    return counter == null ? 0 : counter;
  }

  private static synchronized void incrementInstanceCounter(Class<?> clazz) {
    instanceCounters.put(clazz, getInstanceCounter(clazz) + 1);
  }

  // Only for demo purposes, can be deleted
  private static final java.util.Random RANDOM = new java.util.Random();  
  private static void incrementInstanceCounterThreadUnsafe(Class<?> clazz) {
    long counter = getInstanceCounter(clazz);
    try {
      Thread.sleep(RANDOM.nextInt(10));
    } catch (InterruptedException e) {
      throw new org.aspectj.lang.SoftException(e);
    }
    instanceCounters.put(clazz, counter + 1);
  }

  after() returning(InstrumentedRunnableCallable runnableCallable) :
    call(InstrumentedRunnableCallable+.new(..))
  {
    runnableCallable.setCreatorTID(currentThread().getId());
    runnableCallable.setId(getInstanceCounter(runnableCallable.getClass()));
    incrementInstanceCounter(runnableCallable.getClass());
    // Use this instead in order to mess up instance counters  
    //incrementInstanceCounterThreadUnsafe(runnableCallable.getClass());
    printLogMessage("[Create Runnable/Callable]", runnableCallable);
  }

  Object around(InstrumentedRunnableCallable runnableCallable):
    this(runnableCallable) &&
    (execution(void Runnable+.run(..)) || execution(* Callable+.call(..)))
  {
    printLogMessage("[Before Runnable.run() / Callable.call()]", runnableCallable);
    Object result = proceed(runnableCallable);
    printLogMessage("[After  Runnable.run() / Callable.call()]", runnableCallable);
    return result;
  }

  private void printLogMessage(String prefix, InstrumentedRunnableCallable runnableCallable) {
    System.out.printf("%s TID=%d, %s%n", prefix, currentThread().getId(), runnableCallable.toStringIRC());
  }

  public interface InstrumentedRunnableCallable {}

  private long InstrumentedRunnableCallable.id = -1;
  private long InstrumentedRunnableCallable.creatorTID = -1;

  public long InstrumentedRunnableCallable.getId() { return id; }
  public void InstrumentedRunnableCallable.setId(long id) { this.id = id; }

  public long InstrumentedRunnableCallable.getCreatorTID() { return creatorTID; }
  public void InstrumentedRunnableCallable.setCreatorTID(long creatorTID) { this.creatorTID = creatorTID; }

  public String InstrumentedRunnableCallable.toStringIRC() {
    return getClass().getName() + "(instanceID=" + id + ", creatorTID=" + creatorTID + ")";
  }

  declare parents: Runnable+ implements InstrumentedRunnableCallable;
  declare parents: Callable+ implements InstrumentedRunnableCallable;
}
Enjoy!

--
Alexander Kriegisch
https://scrum-master.de

Yongle Zhang schrieb am 21.05.2018 21:29:
ThreadLocal is used to avoid multiple threads creating objects of the same class and need to increment the counter at the same time.

Thanks for your time reviewing it! I’d really appreciate it if you want to help to refactor it.
On May 21, 2018 at 9:58:16 AM, Alexander Kriegisch (alexander@xxxxxxxxxxxxxx) wrote:
I am happy you found a workaround for your problem, although it seems a bit over-engineered. There are several parts which could use refactoring, but most of all I am irritated by the ThreadLocal. Why would you need that? You are keeping only one ID (truly just a simple counter) per class. What are you gaining by using the ThreadLocal there?

Yongle Zhang schrieb am 21.05.2018 02:17:
Thank you for your quick reply! Really appreciate your effort!

In terms of my original goal, I had to come up with some workaround.

The general idea is to just maintain a Map<java.lang.class, counter> by myself. There’s some synchronization and optimization to do.

I’ll post here in case it’s helpful for others.

To make it clear, this method works for “inserting an ID for objects of classes in any jar” except for rt.jar.
import java.util.HashMap;
import java.util.Map;
import java.util.concurrent.Callable;
import java.lang.Runnable;

privileged aspect MyRunnablesCallables {

  public static Map<java.lang.Class, ThreadLocal<Long>> My_counters = new
      HashMap<java.lang.Class, ThreadLocal<Long>>();

  public static long getMyCounter(java.lang.Class clazz) {
    ThreadLocal<Long> local = My_counters.get(clazz);
    if (local == null) {    
         // need to initialize the ThreadLocal
         // This is the only place that needs synchronization.    
      synchronized (clazz) { // synchronize on the given clazz is enough
        // Double check to avoid multi threads entered the previous if statement
        if (local == null) {
          local = new ThreadLocal<Long>() {
            @Override
            protected Long initialValue() {
              return (long) 0;
            }
          };
          My_counters.put(clazz, local);
        }
      }
    }
    return (long) local.get();
  }

  private static void setMyCounter(java.lang.Class clazz, long counter) {
    ThreadLocal<Long> local = My_counters.get(clazz);
    // This function is only called in incrementMyCounter() so it's not null.
    assert local != null;
    local.remove();
    local.set(counter);
  }

  public static void incrementMyCounter(java.lang.Class clazz) {
    setMyCounter(clazz, getMyCounter(clazz)+1);
  }

  public interface InstrumentedRunnableCallable {}

  private boolean InstrumentedRunnableCallable.My_id_assigned = false;

  // here we use (thread id + a thread local id) as this object's ID.    
  // For now we don't consider the case when Thread ID could be reused.    
  private long InstrumentedRunnableCallable.My_id = -1;
  private long InstrumentedRunnableCallable.My_creator_tid = -1;

  public long InstrumentedRunnableCallable.getMyId() {
    return My_id;
  }
  public void InstrumentedRunnableCallable.setMyId(long id) {
    My_id = id;
  }

  public long InstrumentedRunnableCallable.getCreatorTid() {
    return My_creator_tid;
  }
  public void InstrumentedRunnableCallable.setCreatorTid(long id) {
    My_creator_tid = id;
  }

  public boolean InstrumentedRunnableCallable.getMyIdAssigned() {
    return My_id_assigned;
  }
  public void InstrumentedRunnableCallable.setMyIdAssigned(boolean assigned) {
    My_id_assigned = assigned;
  }

  declare parents: (Runnable)+ implements InstrumentedRunnableCallable;
  declare parents: (Callable)+ implements InstrumentedRunnableCallable;

  after() returning(InstrumentedRunnableCallable r):
      (call(InstrumentedRunnableCallable+.new(..))) {
    if (r.getMyIdAssigned() == false) { // in case there're nested constructors
      r.setMyIdAssigned(true);

      r.setCreatorTid(Thread.currentThread().getId());

      r.setMyId(MyRunnablesCallables.getMyCounter(r.getClass()));

      MyRunnablesCallables.incrementMyCounter(r.getClass());

    }
    System.out.println( "[Create Runnable/Callable] " +
        "TID: " + Thread.currentThread().getId()
        + " creator tid " + r.getCreatorTid()
        + " id " + r.getMyId()
        + " class " + r.getClass().getName()
    );
  }

  before(InstrumentedRunnableCallable r):
      this(r) &&
      (execution(void Runnable+.run(..)) || execution(* Callable+.call(..))) {
    System.out.println( "[Before Runnable run() / Callable call() ] " +
        "TID: " + Thread.currentThread().getId()
        + " creator tid " + r.getCreatorTid()
        + " id " + r.getMyId()
        + " class " + r.getClass().getName()
    );
  }

  after(InstrumentedRunnableCallable r):
      this(r) &&
      (execution(void Runnable+.run(..)) || execution(* Callable+.call(..))) {
    System.out.println( "[After Runnable run() / Callable call() ] " +
        "TID: " + Thread.currentThread().getId()
        + " creator tid " + r.getCreatorTid()
        + " id " + r.getMyId()
        + " class " + r.getClass().getName()
    );
  }
}
On May 19, 2018 at 7:01:56 AM, Alexander Kriegisch (alexander@xxxxxxxxxxxxxx) wrote:
Okay, I think I figured it out. It is not per se a problem with the 3rd party code, I can reproduce it with or without Thrift. The core problem is that the inner class you want to instrument in the library is non-public. To be exact, it is a private, non-static inner class. But what really matters is that it is anything but public/protected, static or not is not so important.

To Andy Clement: Maybe this is a shortcoming in AspectJ and we need a Bugzilla ticket for it, but first I am going to post some sample code here:
package de.scrum_master.app;

public class Application {
  private static class InnerStaticRunnable implements Runnable {
    @Override
    public void run() {
      System.out.println("Running inner static runnable");
    }
  }

  private class InnerRunnable implements Runnable {
    @Override
    public void run() {
      System.out.println("Running inner runnable");
    }
  }

  public void doSomething() {
    new InnerRunnable().run();
  }

  public static void main(String[] args) {
    new SomeRunnable().run();
    new Application.InnerStaticRunnable().run();
    new Application().doSomething();
  }
}
package de.scrum_master.aspect;

privileged aspect MyRunnables {
  public interface InstrumentedRunnable {}
  private long InstrumentedRunnable.myid = -1;
  public long InstrumentedRunnable.getMyid() { return myid; }
  public void InstrumentedRunnable.setMyid(long id) { myid = id; }

  declare parents : Runnable+ implements InstrumentedRunnable;

  after() returning(InstrumentedRunnable r) : call(java.lang.Runnable+.new(..)) {
    System.out.println(thisJoinPoint);
    System.out.println("  Runnable: " + r);
    System.out.println("  Has aspect: " + PerRunnable.hasAspect(r.getClass()));
    long id = PerRunnable.aspectOf(r.getClass()).getCounter();
    r.setMyid(id);
    PerRunnable.aspectOf(r.getClass()).incrementCounter();
  }
}
package de.scrum_master.aspect;

privileged aspect PerRunnable pertypewithin(java.lang.Runnable+) {
  public long counter = 0;
  public long getCounter() { return counter; }
  public void incrementCounter() { counter++; }

  after() : staticinitialization(*) {
    System.out.println("getWithinTypeName() = " + getWithinTypeName());
  }
}
Now let's run the code after Ajc compilation and check the console log:
getWithinTypeName() = de.scrum_master.app.SomeRunnable
call(de.scrum_master.app.SomeRunnable())
  Runnable: de.scrum_master.app.SomeRunnable@5674cd4d
  Has aspect: true
Running some runnable
getWithinTypeName() = de.scrum_master.app.Application$InnerStaticRunnable
call(de.scrum_master.app.Application.InnerStaticRunnable(Application.InnerStaticRunnable))
  Runnable: de.scrum_master.app.Application$InnerStaticRunnable@65b54208
  Has aspect: false
Exception in thread "main" org.aspectj.lang.NoAspectBoundException
    at de.scrum_master.aspect.PerRunnable.aspectOf(PerRunnable.aj:1)
    at de.scrum_master.aspect.MyRunnables.ajc$afterReturning$de_scrum_master_aspect_MyRunnables$1$8a935d86(MyRunnables.aj:15)
    at de.scrum_master.app.Application.main(Application.java:24)
Please note "Has aspect: false" right before the exception. Now change the inner classes to public or protected and the code works:
getWithinTypeName() = de.scrum_master.app.SomeRunnable
call(de.scrum_master.app.SomeRunnable())
  Runnable: de.scrum_master.app.SomeRunnable@5674cd4d
  Has aspect: true
Running some runnable
getWithinTypeName() = de.scrum_master.app.Application$InnerStaticRunnable
call(de.scrum_master.app.Application.InnerStaticRunnable())
  Runnable: de.scrum_master.app.Application$InnerStaticRunnable@65b54208
  Has aspect: true
Running inner static runnable
getWithinTypeName() = de.scrum_master.app.Application$InnerRunnable
call(de.scrum_master.app.Application.InnerRunnable(Application))
  Runnable: de.scrum_master.app.Application$InnerRunnable@6b884d57
  Has aspect: true
Running inner runnable
Any comments, Andy?

--

Alexander Kriegisch
https://scrum-master.de

Yongle Zhang schrieb am 18.05.2018 04:03:
More information

The part of the code that’s causing the exception - this is decompiled from the woven .class file:
public class TThreadPoolServer {
        
    public void serve() {

  . . .

  TThreadPoolServer.WorkerProcess var13;
        
  TThreadPoolServer.WorkerProcess var10000 = var13 = new     
     
  TThreadPoolServer.WorkerProcess(client, (<undefinedtype>)var10);

  // The exception says here afterReturning throws the exception
      
      
  EpredRunnablesCallables.aspectOf().ajc$afterReturning$EpredRunnablesCallables$1$8a935d86(var13);

  . . .       

  }

 // inner class
  private class WorkerProcess implements Runnable, InstrumentedRunnableCallable {
        public long myid; // inserted by aspectj
            
        . . .     
        
    }

}
Question: how does pertypewithin() work? what’s its scope?

For example, pertypewithin(Runnable+) - does it work every class in the classpath, even including those in rt.jar? When does it create instance for every class that implements Runnable (after class loading, on demand, …)?

Thank you!
On May 17, 2018 at 4:36:23 PM, Yongle Zhang (ynglzh@xxxxxxxxx) wrote:
Hi,

Problem

I have some aspects trying to insert an ID for every class that implements Runnable.

My aspects (provided below) works fine for a simple test in which 1) I wrote my own MyRunnable class implementing Runnable, 2) I have a simple main function that creates and runs a thread using MyRunnable.

However, when I use it to instrument apache thrift library, it gives me org.aspectj.lang.NoAspectBoundException exception.

I use compile-time weaving. The compile-time weaving finishes successfully, and the instrumented .class code shows the aspects was woven. However, running the instrumented apache thrift lib gives this excetpion:

(MyServer is my simple server implementation using thrift. TThreadPoolServer is the server class in apache thrift lib.)
org.aspectj.lang.NoAspectBoundException
    at EpredPerRunnable.aspectOf(EpredPerRunnable.aj:1)
    at EpredRunnablesCallables.ajc$afterReturning$EpredRunnablesCallables$1$8a935d86(EpredRunnablesCallables.aj:55)
    at org.apache.thrift.server.TThreadPoolServer.serve(TThreadPoolServer.java:168)
    at MyServer.StartsimpleServer(MyServer.java:21)
    at MyServer.main(MyServer.java:28)
My Aspects

Here are the aspects I wrote:

1) I have a counter for each class implements Runnable using pertypewithin.
privileged aspect PerRunnable
    pertypewithin(java.lang.Runnable+)
{
  public long counter = 0;

  public long getCounter() {
    return counter;
  }

  public void incrementCounter() {
    counter++;
  }
}
2) I insert an id into each class that implements Runnable using interface.
privileged aspect MyRunnables {

  public interface InstrumentedRunnable {}

  private long InstrumentedRunnable.myid = -1;

  public long InstrumentedRunnable.getMyid() {
    return myid;
  }
       
  public void InstrumentedRunnable.setMyid(long id) {
    myid = id;
  }


  declare parents: (Runnable)+ implements InstrumentedRunnable;

  after() returning(InstrumentedRunnable r):
      call(java.lang.Runnable+.new(..)) {

      long id = PerRunnable.aspectOf(r.getClass()).getCounter();
      r.setMyid(id);

      PerRunnable.aspectOf(r.getClass()).incrementCounter();

  }

}
3) Part of my scripts that only instruments thrift:
CLASSPATH=$CLASSPATH:~/aspectj1.9/lib/aspectjtools.jar
CLASSPATH=$CLASSPATH:~/aspectj1.9/lib/aspectjrt.jar
AJC=~/aspectj1.9/bin/ajc

echo "Compiling Aspects ..."
$AJC -classpath $CLASSPATH:./lib/libthrift-0.11.0.jar -source 1.8 asp/*.aj

echo "Weaving aspect into thrift lib..."
$AJC -classpath $CLASSPATH:./lib/servlet-api-2.5.jar:./lib/httpcore-4.4.1.jar:./lib/slf4j-api-1.7.12.jar:./lib/httpclient-4.4.1.jar -source 1.8 -inpath ./lib/libthrift-0.11.0.jar -aspectpath ./asp/ -outjar ./my-libthrift-0.11.0.jar
4) Part of my scripts that starts the thrift server:
CLASSPATH=$CLASSPATH:~/aspectj1.9/lib/aspectjtools.jar
CLASSPATH=$CLASSPATH:~/aspectj1.9/lib/aspectjrt.jar

java -cp $CLASSPATH:./asp:./my-add-server.jar:./my-libthrift-0.11.0.jar:./lib/slf4j-api-1.7.12.jar MyServer
Need Help

Has anyone met such problem before? Any guess? Note that these aspects works for my own Runnable but not for thrift lib. (I can send more code needed including my test classes and my scripts, but they don’t fit within an email…)

Is there a way to get all aspect instances and what they are matched to at runtime?

Does aspectj has this feature: given 1) a pointcut, 2) the signature of a target (class/method) I want the pointcut to match, tell me whether they matched, and if not why.

Thank you for your time and help!
_______________________________________________
aspectj-users mailing list
aspectj-users@xxxxxxxxxxx
To change your delivery options, retrieve your password, or unsubscribe from this list, visit
https://dev.eclipse.org/mailman/listinfo/aspectj-users

Attachment: yongle_aspectj.zip
Description: Zip archive

Follow-Ups:
- Re: [aspectj-users] Met [org.aspectj.lang.NoAspectBoundException] while running a post-compile woven (bytecode woven) apache thrift library
  - From: Alexander Kriegisch

References:
- [aspectj-users] Met [org.aspectj.lang.NoAspectBoundException] while running a post-compile woven (bytecode woven) apache thrift library
  - From: Yongle Zhang
- Re: [aspectj-users] Met [org.aspectj.lang.NoAspectBoundException] while running a post-compile woven (bytecode woven) apache thrift library
  - From: Yongle Zhang
- Re: [aspectj-users] Met [org.aspectj.lang.NoAspectBoundException] while running a post-compile woven (bytecode woven) apache thrift library
  - From: Alexander Kriegisch
- Re: [aspectj-users] Met [org.aspectj.lang.NoAspectBoundException] while running a post-compile woven (bytecode woven) apache thrift library
  - From: Yongle Zhang
- Re: [aspectj-users] Met [org.aspectj.lang.NoAspectBoundException] while running a post-compile woven (bytecode woven) apache thrift library
  - From: Alexander Kriegisch
- Re: [aspectj-users] Met [org.aspectj.lang.NoAspectBoundException] while running a post-compile woven (bytecode woven) apache thrift library
  - From: Yongle Zhang
- Re: [aspectj-users] Met [org.aspectj.lang.NoAspectBoundException] while running a post-compile woven (bytecode woven) apache thrift library
  - From: Alexander Kriegisch
- Re: [aspectj-users] Met [org.aspectj.lang.NoAspectBoundException] while running a post-compile woven (bytecode woven) apache thrift library
  - From: Yongle Zhang

Prev by Date: Re: [aspectj-users] Met [org.aspectj.lang.NoAspectBoundException] while running a post-compile woven (bytecode woven) apache thrift library
Next by Date: Re: [aspectj-users] Met [org.aspectj.lang.NoAspectBoundException] while running a post-compile woven (bytecode woven) apache thrift library
Previous by thread: Re: [aspectj-users] Met [org.aspectj.lang.NoAspectBoundException] while running a post-compile woven (bytecode woven) apache thrift library
Next by thread: Re: [aspectj-users] Met [org.aspectj.lang.NoAspectBoundException] while running a post-compile woven (bytecode woven) apache thrift library
Index(es):
- Date
- Thread

Breadcrumbs

Test that shows it works

Extra synchronization needed in your method

After fixing bugs and refactoring for my previous aspect

Added extra needed synchronization in your aspect

More information

Problem

My Aspects

Need Help

Thank you for your time and help!