Hot questions for Using AspectJ in logging

Question:

I am trying to implement AOP based logging in Google - Guice. I have used MethodInterceptor for this but it doesn't work. I have used same in Spring by defining point-cuts. Everything is working fine there.

Spring Code for AOP based logging -

@Aspect
public class LoggingAspect {

 private static Logger logger = LoggerFactory.getLogger(LoggingAspect.class);

   @Around("requiredLog()")
   public Object bentoBoxAround(ProceedingJoinPoint proceedingJoinPoint) {

      Object returnValue = null;
      try {

          logger.info("Entered into the method -> " + proceedingJoinPoint.getSignature().toShortString()
                  + " and input arguments are -> " + Arrays.asList(proceedingJoinPoint.getArgs()));
          returnValue = proceedingJoinPoint.proceed();
          logger.info("Method Execution over !! " + proceedingJoinPoint.getSignature().toShortString());
      } catch (Throwable e) {
          logger.error("Method has an exception " + e.getMessage());
      }
      return returnValue;
   }

   @Pointcut("within(org.cal.bento..*)")
   public void allRequiredPakageLog() {
   }

 }

From above code we can log all the class and method executions inside the org.cal.bento.* package.

Guice code for AOP based logging -

public class GuiceLoggingInterceptor implements MethodInterceptor {

 private static Logger logger = LoggerFactory
 .getLogger(GuiceLoggingInterceptor.class);

  @Override
  public Object invoke(MethodInvocation invocation) throws Throwable {
    Object returnValue = null;
    try {
        logger.info("GUICE - Entered into the method -> " + invocation.getMethod().getName()
                    + " and input arguments are -> " + Arrays.asList(invocation.getArguments()));
        returnValue = invocation.proceed();
        logger.info("Method Execution over !! " + invocation.getMethod().getName());
    } catch (Throwable e) {
        logger.error("GUICE - Method has an exception " + e.getMessage());
    }
    return returnValue;
  }
}

Binding Class -

public class GuiceAopModule extends AbstractModule {

  @Override
  protected void configure() {
      bindInterceptor(Matchers.any(), Matchers.any(), new GuiceLoggingInterceptor());
  }
}

Can we do similar in Guice for logging (by defining only one Aspect based class for whole logging system). I don't want to modify every class.

Refered Tutorial - https://schakrap.wordpress.com/2009/07/30/method-entry-exit-logging-in-guice-with-aop/

Any help would be highly appreciated.


Answer:

Your issue appears to be that you are not using guice for creation. From the guice docs:

This approach imposes limits on what classes and methods can be intercepted:

[...]

Instances must be created by Guice by an @Inject-annotated or no-argument constructor It is not possible to use method interception on instances that aren't constructed by Guice.

So this means, that because your instances are created by spring and likely added to guice, guice has no chance of proxying those classes for interception.

Source:

https://github.com/google/guice/wiki/AOP

Edit:

what you can do (as workaround) to be able to make this work would be:

  1. Spring creates your instances.

  2. Put them into guice

  3. Create a delegate object that is created by Guice and inject the bean of (1) into the wrapper.

  4. Use the wrapper instead of the object in 1 and then the methods will get intercepted.

Question:

In our back-end systems, there are many situations to update object, e.g. update goods, update goods prices, update user, update status, update order(cancel, update price) and so on. Now some object we have a specially log table, e.g. order_update_log , to logger update operations. Some only logger to file, e.g.

logger.info("goods update: before: {}, after: {}", oldGoods, newGoods)

Feel process these trivial things very annoying, does exist some better manner/tools to process logger like this?


Answer:

There is very nice thing called Aspects. You can write aspect for you project that is only aware of tracking changes of goods objects. Supposing you have Goods class:

public class Goods {
    private Integer id;
    private String name;
    private BigDecimal cost;

    // Getters, Setters
    ...
}

which mapped to database table goods with corresponding fields:

CREATE TABLE `goods` (
    `id` INT NOT NULL AUTO_INCREMENT,
    `name` varchar NOT NULL,
    `cost` DECIMAL NOT NULL,
    PRIMARY KEY (`id`)
);

Supposing you have GoodsService:

public class GoodsService {

    public Goods read(Integer id) {
        Goods goods = /* Read goods from database */
        return goods;
    }

    public void write(Goods goods) {
        /* Write goods to database */
    }
}

and GoodsController that using GoodsService:

public class GoodsController {

    private GoodsService goodsService;

    public void updateGoods(Integer id, String name, BigDecimal cost) {
        Goods goods = goodsService.read(id);
        goods.setName(name);
        goods.setCost(cost);
        goodsService.write(goods);
    }

}

So lets add some aspects magic to your project for tracking changes of goods. Now create another table with additional fields for storing user and datetime of updating goods object:

CREATE TABLE `goods_log` (
    `revision` INT NOT NULL AUTO_INCREMENT,
    `id` INT NOT NULL,
    `name` varchar NOT NULL,
    `cost` DECIMAL NOT NULL,
    `user` varchar NOT NULL,
    `timestamp` DATETIME NOT NULL,
    PRIMARY KEY (`revision`,`id`)
);

Write aspect class:

@Aspect
public class GoodsLogger {
    @Before(value = "execution(* org.antonu.service.GoodsService.write(..)) && args(goods)")
    public void logWrite(Goods goods) {
        // Get current user and timestamp,
        // Write it to goods_log table, as well as goods data
    }
}

That's it! Your business logic code didn't change, it's clear to read. But every time GoodsService's write method invoked you will get record in goods_log with new state of goods.

To make this code working it should be compiled with AJC compiler, also aspectjrt library should be included. It can be easily done via maven:

<properties>
    <aspectj.version>1.8.7</aspectj.version>
</properties>

<dependencies>
    <dependency>
        <groupId>org.aspectj</groupId>
        <artifactId>aspectjrt</artifactId>
        <version>${aspectj.version}</version>
    </dependency>
</dependencies>

<build>
    <plugins>
        <plugin>
            <groupId>org.codehaus.mojo</groupId>
            <artifactId>aspectj-maven-plugin</artifactId>
            <version>1.4</version>
            <executions>
                <execution>
                    <goals>
                        <goal>compile</goal>
                        <goal>test-compile</goal>
                    </goals>
                </execution>
            </executions>
            <dependencies>
                <dependency>
                    <groupId>org.aspectj</groupId>
                    <artifactId>aspectjrt</artifactId>
                    <version>${aspectj.version}</version>
                </dependency>
                <dependency>
                    <groupId>org.aspectj</groupId>
                    <artifactId>aspectjtools</artifactId>
                    <version>${aspectj.version}</version>
                </dependency>
            </dependencies>
        </plugin>
    </plugins>
</build>

Modern IDE Intellij Idea should automatically use AJC compiler with maven config above. If not, you must configure compiler via File - Settings - 'Build, Execution, Deployment' - Compiler - Java Compiler - Use compiler: Ajc. Path to AJC compiler: <path_to>/aspectjtools-1.8.7.jar

Question:

basic aop code

@Aspect
public class LoggingAspect {
private   Logger logger  ;

@Before("execution(*  *(..)) && !execution(* com.*model*.*(..))")
public void logBefore(JoinPoint joinPoint) {
    logger = LoggerFactory.getLogger(joinPoint.getTarget().getClass());
    logger.info("{} :" + joinPoint.getSignature().getName(),"info for user log" );
    //logger.info("hijacked target class : " + joinPoint.getTarget().getClass().getSimpleName() );
}

@After("execution(*  *(..)) && !execution(* com.*model*.*(..)) ")
public void logAfter(JoinPoint joinPoint) {

    System.out.println("logAfter() is running!");
    System.out.println("hijacked : " + joinPoint.getSignature().getName());
    System.out.println("******");

}
}

Currently, I am implementing the aop logging for some methods by default like methods starts and methods end .so using aop logger printing the apo class and method instead of printing method owned class and method. I have to override the class name inside aop to print that method's class name like so i need to get method name as native method name

currently i am getting

2017-09-20 18:32:06 INFO [main] c.m.customer.bo.impl.CustomerBoImpl - logBefore : info for user log() :addCustomer

what i need is

2017-09-20 18:32:06 INFO [main] c.m.customer.bo.impl.CustomerBoImpl - addCustomer : info for user log() :addCustomer


Answer:

at last, I found an easy solution with ProceedingJoinPoint from this link Log4j and AOP, how to get actual class name

Question:

I am pretty new to AspectJ and AOP in general. I do know that AspectJ has many Annotations (After, AfterReturning, etc) to execute code before a method is called, after it is called, after it returns, when an exception is thrown, etc.

I would like to use it for logging, a pretty typical use case. I've been looking at this article and I think it's most of what I need. It uses AspectJ as well as "jcambi aspects" to perform logging.

But I would like to do something like the following:

public void login(User user) {
  String userType = user.getType();

  if (!user.isActive()) {
    // point cut 1 -- log inactive user
  } else if (!user.isPasswordValid()) {
    // point cut 2 -- log wrong password  
  } else {
      // point cut 3 -- log successful login
  }  
}

We have an established log format. Something like:

<actor>|<action_code>|<error_code>|<extra_info>

All of the Actor types, Actions and Error Codes are contained in enums.

Is there any way to tell AspectJ to :

log within 'ifs', and log different info, depending on what happened? for example, in point cut 1 log one of the following:

admin|login|001|Admin user inactive
user|login|001|Normal user inactive

... and in point cut 2 log one of the following:

admin|login|002|Invalid Admin password
user|login|002|Invalid normal user password

... and in point cut 3 log one of the following:

admin|login|000|Successful Admin login
user|login|000|Successful Normal user login

Something tells me it is not possible. Or at least not easy. But I'm not sure if it's even worth attempting. So I'm torn. On the one hand I'd like to "sanitize" my code of all logging. On the other hand, I'm not sure if it's going to be too much work to implement this.

Any ideas?

*************************************** EDIT ***************************************

Thank you both for your answers! I realize now two things: 1. I've got a lot of work ahead of me. And 2. I think I put too much emphasis on the "login" example.

Login is just one tiny use case. My task is to add logging everywhere ... in a bunch of methods in many, many classes. Basically everywhere I see a LOG.debug() or LOG.info(), anywhere in the application, to replace it with Aspect logging. This also means that as much as I'd like to, I can't just refactor all of the code to make my life easier. I'd love to make login use Exceptions but it's beyond the scope of my task: add logging.

And of course, in each method the business logic will be different, and as such, so will the logging. So my question becomes: what's the best practice to do this? I mean, each method will have its own logic, its ifs ... and will log different things conditionally. So do I go ahead and create an aspect class for each one of these use cases and basically have the same "ifs" there as well?

An example (that's not login!): A method that imports data.

public void import(String type) {
      if (type.equals("people")) {
        try {
          int result = importPeople();
          if (result > 0) {
            // do some stuff
            LOG.info("ok");
          } else {
            // do some stuff
            LOG.info("problem");
          }
        } catch (Exception e) {
          // do some stuff
          LOG.debug("exception ...");
        }
      } else if (type.equals("places")) {
        try {
          int result = importPlaces();
          if (result > 0) {
            // do some stuff
            LOG.info("ok");
          } else {
            // do some stuff
            LOG.info("problem");
          }
        } catch (Exception e) {
          // do some stuff
          LOG.debug("exception ...");
        }  
      }  
    }

Mind you it's a crap example, with repeated code, etc. But you get the idea. Should I also create an "import" aspect, for logging this method ... with all the accompanying "ifs" to log "ok", "problem", "exception" ? And do this for every use case?

I'm all for getting rid of intrusive logging code but ... it seems like something of a code smell to have to have the logic, with its "ifs", etc., both in the original method (because the method is "doing more stuff" than logging) as well as in the corresponding Aspect ...

Anyway, you both answered my original question ... but I can only have 1 be the answer, so I'm going to accept kriegaex's because he seems to have put a lot of work into it!


Answer:

Yes, it is possible. But if I were you, I would model the whole story a bit differently. First of all, I would throw exceptions for failed logins due to unknown or inactive users or wrong passwords. Alternatively, the login method could return a boolean value (true for successful login, false otherwise). But in my opinion this would rather be old-fashioned C style than modern OOP.

Here is a self-consistent example. Sorry for the ugly UserDB class with lots of static members and methods. And in reality, you would not store clear-text passwords but randomised salts and salted hashes. But after all it is just a proof of concept for aspect-based, conditional logging.

User bean used for logins:

package de.scrum_master.app;

public class User {
    private String id;
    private String password;

    public User(String id, String password) {
        this.id = id;
        this.password = password;
    }

    public String getId() {
        return id;
    }

    public String getPassword() {
        return password;
    }
}

User database:

There are hard-coded DB entries, static enums, members and methods as well as static inner classes for simplicity's sake. Sorry! You can easily imagine how to do the same with better design, I hope.

package de.scrum_master.app;

import java.util.HashMap;
import java.util.Map;

public class UserDB {
    public static enum Role { admin, user, guest }
    public static enum Action { login, logout, read, write }
    public static enum Error { successful_login, user_inactive, invalid_password, unknown_user }

    private static class UserInfo {
        String password;
        Role role;
        boolean active;

        public UserInfo(String password, Role role, boolean active) {
            this.password = password;
            this.role = role;
            this.active = active;
        }
    }

    private static Map<String, UserInfo> knownUsers = new HashMap<>();

    static {
        knownUsers.put("bruce",   new UserInfo("alm1GHTy", Role.admin, true));
        knownUsers.put("john",    new UserInfo("LetMe_in", Role.user,  true));
        knownUsers.put("jane",    new UserInfo("heLL0123", Role.guest, true));
        knownUsers.put("richard", new UserInfo("dicky",    Role.user,  false));
        knownUsers.put("martha",  new UserInfo("paZZword", Role.admin, false));
    }

    public static class UserDBException extends Exception {
        private static final long serialVersionUID = 7662809670014934460L;

        public final String userId;
        public final Role role;
        public final Action action;
        public final Error error;

        public UserDBException(String userId, Role role, Action action, Error error, String message) {
            super(message);
            this.userId = userId;
            this.role = role;
            this.action = action;
            this.error = error;
        }
    }

    public static boolean isKnown(User user) {
        return knownUsers.get(user.getId()) != null;
    }

    public static boolean isActive(User user) {
        return isKnown(user) && knownUsers.get(user.getId()).active;
    }

    public static boolean isPasswordValid(User user) {
        return isKnown(user) && knownUsers.get(user.getId()).password.equals(user.getPassword());
    }

    public static Role getRole(User user) {
        return isKnown(user) ? knownUsers.get(user.getId()).role : null;
    }

    public static void login(User user) throws UserDBException {
        String userId = user.getId();
        if (!isKnown(user))
            throw new UserDBException(
                userId, getRole(user), Action.login,
                Error.unknown_user, "Unknown user"
            );
        if (!isActive(user))
            throw new UserDBException(
                userId, getRole(user), Action.login,
                Error.user_inactive, "Inactive " + getRole(user)
            );
        if (!isPasswordValid(user))
            throw new UserDBException(
                userId, getRole(user), Action.login,
                Error.invalid_password, "Invalid " + getRole(user) + " password"
            );
    }
}

Please note how the login(User) method throws exceptions with details helpful for logging.

Driver application simulating logins for several user/password combinations:

package de.scrum_master.app;

import java.util.Arrays;
import java.util.List;

public class Application {
    public static void main(String[] args) {
        List<User> users = Arrays.asList(
            new User("mr_x",    "foobar"),
            new User("bruce",   "foobar"),
            new User("bruce",   "alm1GHTy"),
            new User("john",    "foobar"),
            new User("john",    "LetMe_in"),
            new User("jane",    "foobar"),
            new User("jane",    "heLL0123"),
            new User("richard", "foobar"),
            new User("richard", "dicky"),
            new User("martha",  "foobar"),
            new User("martha",  "paZZword")
        );

        for (User user : users) {
            try {
                UserDB.login(user);
                System.out.printf("%-8s -> %s%n", user.getId(), "Successful " + UserDB.getRole(user) + " login");
            } catch (Exception e) {
                System.out.printf("%-8s -> %s%n", user.getId(), e.getMessage());
            }
        }
    }
}

Please note that we just catch and log all exceptions so as to avoid the application from exiting after failed login attempts.

Console log:

mr_x     -> Unknown user
bruce    -> Invalid admin password
bruce    -> Successful admin login
john     -> Invalid user password
john     -> Successful user login
jane     -> Invalid guest password
jane     -> Successful guest login
richard  -> Inactive user
richard  -> Inactive user
martha   -> Inactive admin
martha   -> Inactive admin

Login logger aspect:

I suggest you first comment out the two System.out.printf(..) calls in Application.main(..) so as not to mix them up with aspect logging.

package de.scrum_master.aspect;

import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;

import de.scrum_master.app.User;
import de.scrum_master.app.UserDB;
import de.scrum_master.app.UserDB.Action;
import de.scrum_master.app.UserDB.Error;
import de.scrum_master.app.UserDB.UserDBException;

@Aspect
public class UserActionLogger {
    @Around("execution(void de.scrum_master.app.UserDB.login(*)) && args(user)")
    public void captureLogin(ProceedingJoinPoint thisJoinPoint, User user) throws Throwable {
        try {
            thisJoinPoint.proceed();
            System.out.printf("%s|%s|%d03|%s%n",
                user.getId(), Action.login, Error.successful_login.ordinal(),
                "Successful " + UserDB.getRole(user) + " login"
            );
        } catch (UserDBException e) {
            System.out.printf("%s|%s|%03d|%s%n",
                e.userId, e.action, e.error.ordinal(),
                e.getMessage()
            );
            throw e;
        }
    }
}

Console log for aspect:

mr_x|login|003|Unknown user
bruce|login|002|Invalid admin password
bruce|login|003|Successful admin login
john|login|002|Invalid user password
john|login|003|Successful user login
jane|login|002|Invalid guest password
jane|login|003|Successful guest login
richard|login|001|Inactive user
richard|login|001|Inactive user
martha|login|001|Inactive admin
martha|login|001|Inactive admin

Et voilĂ ! I hope that this is roughly what you want.

Question:

I am trying to write an aspect to catch all methods execution and retrieve the line number where the methods have been invoked. For example, if I have:

public class MyMainClass {
    public static void main(String[] args){
        MyArray m = new MyArray(5);
        m.setValue //...
        //...
    }
}

I would like to write a pointcut and an advice able to get the line where the method setValue has been called (i.e. line number 4) and not the source code line, where the method has been implemented (accessible with thisJoinPoint.getSourceLocation().getLine()).

Is there any way to do this? Thanks!

UPDATE: I just found out that this code:

StackTraceElement[] trace = Thread.currentThread().getStackTrace();
System.out.println("[AspectJ]LineNumber: " + trace[trace.length-1].getLineNumber());

prints the last method invocation line number, the problem is that it is not useful when there is method invocation inside a method implementation (because, in that case I should decrease trace elements position, but I don't know how to understand when to do that).


Answer:

Next time, please share your aspect code if you have an AspectJ question, I had to guess what was going wrong in your case. But okay, this one was easy: If you get the source location from the executing method instead of the calling method, you have used an execution() pointcut, whereas you would have needed a call() pointcut, see also the first paragraph here.

BTW, In AspectJ you do not need to inspect stack traces manually, you just use thisJoinPoint.getSourceLocation(). That part of your initial idea was correct. You just had the wrong pointcut type.

Driver application + helper class:

package de.scrum_master.app;

public class MyMainClass {
  public static void main(String[] args) {
    MyArray m = new MyArray(5);
    m.setValue(2, 11);
  }
}
package de.scrum_master.app;

public class MyArray {
  public MyArray(int i) {
    // dummy
  }

  public void setValue(int i, int j) {
    // dummy
  }
}

Aspect in native AspectJ syntax:

package de.scrum_master.aspect;

import de.scrum_master.app.MyArray;

public aspect MyAspect {
  before() : call(* MyArray.setValue(..)) {
    System.out.println(thisJoinPoint + " -> " + thisJoinPoint.getSourceLocation());
  }
}

Console log:

call(void de.scrum_master.app.MyArray.setValue(int, int)) -> MyMainClass.java:6

I much prefer the native syntax, but if you prefer the weird, annotation-based @AspectJ syntax where you need the fully qualified class name inside the pointcut, this is the equivalent aspect:

package de.scrum_master.aspect;

import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Before;

@Aspect
public class MyAspect {
  @Before("call(* de.scrum_master.app.MyArray.setValue(..))")
  public void logSourceLocation(JoinPoint thisJoinPoint) {
    System.out.println(thisJoinPoint + " -> " + thisJoinPoint.getSourceLocation());
  }
}

If you have any follow-up questions, feel free to ask, but please express yourself more clearly. It is quite hard to understand what exactly you are asking.

Question:

We are working on a web application where we are logging input and output of all the database calls in DAO classes. An example is:

@Override
public List<Long> findUsers(final List<Long> userIds) {
    LOGGER.info("findUsers: finding user ids  by  followeeId {} ", userIds);
    ... // hibernate DB call
    LOGGER.info("findUsers: number of ids  founds are {}", userIdList.size());  

This code will be present inside all the DAO classes, and the number of such classes is around 100, and it may go higher.

My question is shall we continue logging the info in the same way or shall we go for Spring-AspectJ implementation? -We'll have an aspect defined for @Before and @After for all such methods. This aspect will call logger and log the required info.

Will implementing Spring-AspectJ be a performance hit? Any pointers are appreciated.

I have gone through the below SO questions, but need some more clarity with respect to the example quoted above.

  • Performance impact of using aop
  • Performance impact of using aop

Answer:

Using AOP will give you a small performance penalty, how much depends on how you apply AOP (proxies or weaving) and what you do in your aspect. I would suggest using Springs CustomizableTraceInterceptor or if you are also interested (or more interested in performance one of the subclasses of AbstractMonitoringInterceptor saves you implementing your own.

I wouldn't log in the way you are doing it as it is easy to forget and if you want to change something (or disable logging) you have to change those 100 classes instead of 1 or just configuration.

Question:

My question is very similar to this one: Suppressing logs from AppClassLoader

The difference is that I'm using AspectJ with Spring Boot (via @EnableAspectJAutoProxy and @EnableLoadTimeWeaving(aspectjWeaving = ENABLED) annotations), so I have neither META-INF/aop.xml, not META-INF/aop-ajc.xml files, which are mentioned in the answer there.

How do I disable these annoying AppClassLoader warnings with annotation-based configuration?

Update Just to clarify, I'm talking about this kind of logs:

...
[AppClassLoader@18b4aac2] error can't determine implemented interfaces of missing type org.springframework.cache.ehcache.EhCacheCacheManager
when weaving type org.springframework.boot.autoconfigure.cache.EhCacheCacheConfiguration
when weaving classes 
when weaving 
 [Xlint:cantFindType]
[AppClassLoader@18b4aac2] error can't determine implemented interfaces of missing type org.springframework.cache.ehcache.EhCacheCacheManager
when weaving type org.springframework.boot.autoconfigure.cache.EhCacheCacheConfiguration
when weaving classes 
when weaving 
 [Xlint:cantFindType]
[AppClassLoader@18b4aac2] error can't determine implemented interfaces of missing type org.springframework.cache.ehcache.EhCacheCacheManager
when weaving type org.springframework.boot.autoconfigure.cache.EhCacheCacheConfiguration
when weaving classes 
when weaving 
...

They are printed in red and there's A LOT of them. So I want to suppress these logs somehow.


Answer:

In order to suppress some of the AspectJ compiler messages while using AspectJ load-time weaving, you can do the following.

Create a copy of the file aspectjweaver.jar!/org/aspectj/weaver/XlintDefault.properties to your resources/META-INF folder with the name Xlint.properties.

Change the line

cantFindType = error

to

cantFindType = ignore

Then, create your aop.xml in your resources/META-INF folder as follows, or add the corresponding option to the <weaver> entry as shown:

<!DOCTYPE aspectj PUBLIC "-//AspectJ//DTD//EN"
        "http://www.eclipse.org/aspectj/dtd/aspectj.dtd">
<aspectj>
    <weaver options="-Xlintfile:META-INF/Xlint.properties" />
</aspectj>

Now you should have your cantFindType errors suppressed, but other AspectJ messages left alone. You can change the reporting of other linter messages similarly.

Question:

I want to use AspetcJ to plug in to log4J method that is located in org.apache.log4j.Category.java file.

protected void forcedLog(String fqcn, Priority level, Object message, Throwable t) {
    callAppenders(new LoggingEvent(fqcn, this, level, message, t));
  }

so finally that

@Around("execution(protected void org.apache.log4j.Category.*(..))

would work.

What problem do i have?

My aspect dont get called.

So i made easier example - and it also does not get called.

core.xml

<?xml version="1.0" encoding="UTF-8"?>

<beans 
    xmlns="http://www.springframework.org/schema/beans"
    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xmlns:aop="http://www.springframework.org/schema/aop"
    xmlns:context="http://www.springframework.org/schema/context"    
    xsi:schemaLocation="http://www.springframework.org/schema/beans
    http://www.springframework.org/schema/beans/spring-beans-3.0.xsd
    http://www.springframework.org/schema/aop 
    http://www.springframework.org/schema/aop/spring-aop-3.0.xsd 
    http://www.springframework.org/schema/context
    http://www.springframework.org/schema/context/spring-context-3.0.xsd">

    <!-- <aop:aspectj-autoproxy /> -->

    <context:load-time-weaver/>


    <!-- Aspect -->
    <!--  
    <bean id="beanName"  class="class.sth.ClazzName" />
    <bean id="beanName2"  class="class.sth.Clazz2Name" />
    -->

<!-- other beans - not aspects -->
    </beans>

aop.xml

<!DOCTYPE aspectj PUBLIC "-//AspectJ//DTD//EN" "http://www.eclipse.org/aspectj/dtd/aspectj.dtd">
<aspectj>

    <weaver>
        <!-- only weave classes in our application-specific packages -->
         <include within="*"/>
    <exclude within="org.jibx*"/>
    </weaver>

    <aspects>
        <!-- weave in just this aspect -->
        <aspect name="class.sth.ClazzName"/>
        <aspect name="class.sth.Clazz2Name"/>
    </aspects>

</aspectj>

Example java class which should be invoked when i run JUnit test - in which clearly i see that this line of code is executed:

System.out.println("test");

Still i don't see my aspect getting called.

@Aspect
@Order(3)
public class ClazzName {

    @Around("call(* *println(..))")
    public void testMethod(ProceedingJoinPoint joinPoint) {
        Object o = joinPoint.getArgs();
        System.out.println("test");
    }
}

In my app in the same JUnit test other aspect is called. That can tell Us that we have good dependencies in the project.

@Aspect
@Order(2)
public class Clazz2Name {


    @Around("@annotation(loggable)")
    public Object doStuff(ProceedingJoinPoint joinPoint, Clazz2Name log) throws Throwable{
        ...
    }

    ...

My classes are not always marked as @Component and i want to leave it that way.

JUnit VM arguments

-javaagent:C:\aspectjWeaver\spring-instrument-3.0.4.jar

The question is how i can achieve my goal and make my aspect get called when i want it to ?


Answer:

You actually have at least the following problems:

  1. You did not read the Spring AOP documentation. (Sorry, couldn't resist.)
  2. You are using Spring AOP, not full AspectJ. The difference is that the former only works for Spring components, but Log4J is not a Spring component. So if you want to make it work you need to use full AspectJ via load-time weaving as described by chapter 11.8 of the Spring manual, secsion Using AspectJ with Spring applications.
  3. Even when using full AspectJ you need to know that you cannot hook into executions of JDK methods because those have already been loaded before the aspect weaver is instantiated. Thus, you should hook into method calls via call(* println(..)), not into method executions.

What I do not understand is why you want to hook into Log4J and JDK methods anyway. Do you want to redirect the calls to some other channel? Maybe it would be better to describe what you actually want to achieve, not how you think the problem should be solved.

Question:

My application has three projects:- Web Module, Enterprise and Shared. The enterprise module has already implemented the Log4J aspect and has the code specific to Logging Aspect. Now I need to implement the Logging aspects in the web module and for that I need to move the Logging aspect code to Shared project. And the other 2 modules will use that. I moved the source files(except the log4j xml) to the shared project.

Now when I tries to define a Logger Aspect bean in the enterprise project context.xml, it doesn't find the class ? The shared project doesn't have the context file which can be imported in the enterprise project. Also, the shared project is added in enterprise project dependencies.

  Enterprise context XML:- 
    <aop:aspectj-autoproxy>
            <aop:include name="loggerAspect"/>
        </aop:aspectj-autoproxy>

        <!--  Logger Aspect -->
        <bean id="loggerAspect" class="net.prcins.esales.aspects.LoggerAspect" /> 

    Enterprise POM :- 
    <properties>
    <esales-shared.Version>2.1.0-SNAPSHOT</esales-shared.Version>
    </properties>

How to access the class from the shared code ? Also, shall I keep the XML file specific to a project or common ? I am fairly new to spring and aspects, pls suggest.


Answer:

I am maintaining the spring context file/Logger Aspects bean at the shared project level. The web module and the enterprise module will import it in their respective spring context xml.

I couldn't move the Log4J settings at the shared level, so the web module and the enterprise module has their own Log4j file. The shared project doesn't have any Log4J file.

If somebody finds an answer on how to override and maintain the shared logging information in the shared code, please let me know.