How to use AspectJ to log different data, conditionally?

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 1

Its possible. Create a point-cut/within around login method and get the user object also in your aspect class and once you get User object you can do your logging conditionally. To get the user object,please check the below answered question by me and how it got the value of surveyId.Same way you can get the User object.

@Around("updateDate()"
public Object myAspect(final ProceedingJoinPoint pjp) {

    //retrieve the runtime method arguments (dynamic)
    Object returnVal = null;
    for (final Object argument : pjp.getArgs())
    {

        if (argument instanceof SurveyHelper)
        {
            SurveyHelper surveyHelper = (SurveyHelper) argument;
            surveyId = surveyHelper.getSurveyId();

        }

    }
    try
    {
        returnVal = pjp.proceed();
    }
    catch (Throwable e)
    {
        gtLogger.debug("Unable to use JointPoint :(");
    }
    return returnVal;
}

Here is the complete link for your reference: Spring AOP for database operation

Answer 2

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.