AOP Logging Aspect

Add method-level logging and timing to every service using AOP.

AOPAdvice TypesCross-Cutting Concerns

Overview

Logging every service method's entry, exit, and timing is a textbook "cross-cutting concern" — a piece of behavior that is not really part of any one class's actual job (placing an order, cancelling an order), yet ends up duplicated across every class that needs it if you write it by hand. Aspect-Oriented Programming (AOP) is Spring's answer: instead of pasting logging code into every method of every service, you write it ONCE in a separate class called an aspect, describe WHICH methods it should apply to with a pointcut expression, and let Spring weave that behavior in automatically at runtime.

By the end of this project, `OrderService` will have logging and timing applied to every one of its methods, despite `OrderService`'s own source code never mentioning logging, timing, or anything about AOP at all. That separation is the entire point: the business logic and the cross-cutting concern can be changed, tested, and reasoned about completely independently of each other.

What You'll Build

An `OrderService` with three ordinary business methods and zero logging code inside them.
A `LoggingAspect` class with a single, reusable pointcut expression matching every service-layer method.
`@Before` advice logging each method call's arguments before it runs.
`@AfterReturning` advice logging each method's return value after it completes successfully.
`@Around` advice using `ProceedingJoinPoint` to time how long each call actually takes.
`@EnableAspectJAutoProxy` activating proxy-based weaving so the advice actually runs.

Prerequisites

Project 1 of this course (`@Configuration`, `@Bean`, `@Component`, constructor injection).
What an interface-based Java proxy conceptually is — a stand-in object that intercepts calls before forwarding them to the real object.
Basic annotation syntax and Java's `try`/`catch` (used briefly for `@Around` advice, which can throw `Throwable`).
Maven basics.

Project Structure

The project has four classes across three packages, organized so the pointcut expression in Step 4 can target one package precisely: `com.programinds.aoplogging.service` holds `Order` and `OrderService` (the business logic being advised), `com.programinds.aoplogging.aspect` holds `LoggingAspect` (the cross-cutting logic doing the advising), and `com.programinds.aoplogging.config` holds `AppConfig`. The root package, `com.programinds.aoplogging`, holds only the `main()` entry point.

Spring's default AOP implementation is proxy-based, not full compile-time AspectJ weaving — it only ever advises objects that are themselves Spring beans. `Order` sits in the same package the pointcut expression matches, but `Order` is created with a plain `new Order(...)` call and never registered as a bean, so it is never wrapped in a proxy and its methods are never advised, regardless of what the pointcut expression's package pattern happens to match.

pom.xml (dependencies)

<dependencies>
    <dependency>
        <groupId>org.springframework</groupId>
        <artifactId>spring-context</artifactId>
        <version>6.1.13</version>
    </dependency>

    <!-- spring-aop provides Spring's own proxy-based AOP support. -->
    <dependency>
        <groupId>org.springframework</groupId>
        <artifactId>spring-aop</artifactId>
        <version>6.1.13</version>
    </dependency>

    <!-- aspectjweaver is needed even though this project uses Spring's proxy-based
         AOP (not full AspectJ compile-time weaving) — Spring reuses AspectJ's
         @Aspect annotation and its pointcut expression LANGUAGE/parser, so this
         library has to be on the classpath for @Pointcut expressions to even parse. -->
    <dependency>
        <groupId>org.aspectj</groupId>
        <artifactId>aspectjweaver</artifactId>
        <version>1.9.22</version>
    </dependency>
</dependencies>

Step 1: Understand the AOP Vocabulary

AOP introduces a handful of terms that all the code in this project will use precisely: an "aspect" is a class (like `LoggingAspect`) that modularizes a cross-cutting concern. A "join point" is a specific point during execution where an aspect could apply — in Spring AOP, that is always a method call. A "pointcut" is an expression that selects WHICH join points an aspect actually applies to. "Advice" is the code an aspect runs at those join points, and "weaving" is the process — done automatically by Spring at runtime here — of actually linking an aspect to the join points its pointcut matches, by wrapping the real object in a proxy.

Advice Type	Runs When	Typical Use
@Before	Immediately before the matched method runs	Logging that a call is about to happen; cannot block it
@AfterReturning	After the matched method completes successfully	Logging a return value; never runs if the method throws
@Around	Wraps the entire call — before AND after	Timing, retrying, or even skipping the real method entirely

Step 2: Build the Service Layer to Advise

`OrderService` is written with no awareness whatsoever that it is about to be advised — that unawareness is the whole appeal of AOP. `@Service` marks it as a Spring-managed bean (discovered by `@ComponentScan` in Step 7), which matters here for a reason beyond convenience: only Spring BEANS get wrapped in a proxy, so `@Service` is what actually makes this class eligible to be advised at all.

package com.programinds.aoplogging.service;

public class Order {
    private final int id;
    private final String item;
    private final int quantity;

    public Order(int id, String item, int quantity) {
        this.id = id;
        this.item = item;
        this.quantity = quantity;
    }

    public int getId() { return id; }
    public String getItem() { return item; }
    public int getQuantity() { return quantity; }

    @Override
    public String toString() {
        return "Order#" + id + " (" + quantity + "x " + item + ")";
    }
}

package com.programinds.aoplogging.service;

import org.springframework.stereotype.Service;

import java.util.concurrent.ThreadLocalRandom;

@Service   // Makes this a Spring bean — which is what makes it eligible to be proxied and advised at all
public class OrderService {

    public Order placeOrder(String item, int quantity) {
        simulateWork();   // Stand-in for real work, so @Around's timing in Step 6 has something non-zero to measure
        int id = ThreadLocalRandom.current().nextInt(1000, 9999);
        return new Order(id, item, quantity);
    }

    public void cancelOrder(int orderId) {
        simulateWork();
        System.out.println("(business logic) Order #" + orderId + " cancelled.");
    }

    public double getOrderTotal(int quantity, double unitPrice) {
        simulateWork();
        return quantity * unitPrice;
    }

    private void simulateWork() {
        try {
            Thread.sleep(50);   // Stands in for a real database call or remote API request
        } catch (InterruptedException e) {
            Thread.currentThread().interrupt();
        }
    }
}

Step 3: Add the AOP Dependencies and Enable Aspect Weaving

`@EnableAspectJAutoProxy` is the one annotation that actually activates AOP. Without it, Spring will happily create both the `OrderService` and `LoggingAspect` beans, but it will never wrap `OrderService` in a proxy, and none of the advice from Steps 5-6 will ever run — the two beans would simply exist side by side, doing nothing to each other.

package com.programinds.aoplogging.config;

import org.springframework.context.annotation.ComponentScan;
import org.springframework.context.annotation.Configuration;
import org.springframework.context.annotation.EnableAspectJAutoProxy;

@Configuration
@EnableAspectJAutoProxy                                       // Turns on proxy-based weaving — without this, no advice ever runs
@ComponentScan(basePackages = "com.programinds.aoplogging")   // Finds both @Service and @Aspect classes below
public class AppConfig {
}

Step 4: Define the Aspect and a Reusable Pointcut

`@Aspect` marks this class as a module of cross-cutting advice; `@Component` is what makes it an actual Spring bean, which is required for `@EnableAspectJAutoProxy` to find and weave it — a class annotated `@Aspect` but not `@Component` is invisible to the container entirely. The pointcut expression's two leading asterisks mean "any return type" and "any class"; the third `*` means "any method name"; `(..)` means "any argument list, including none."

package com.programinds.aoplogging.aspect;

import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Pointcut;
import org.springframework.stereotype.Component;

@Aspect
@Component   // Required: only a registered bean can be found and woven by @EnableAspectJAutoProxy
public class LoggingAspect {

    // A NAMED pointcut. Every advice method in Steps 5-6 references this by
    // name instead of repeating the expression, so the "which methods does
    // this aspect apply to" decision lives in exactly one place.
    @Pointcut("execution(* com.programinds.aoplogging.service.*.*(..))")
    public void serviceLayer() {
        // Deliberately empty: a @Pointcut method is never actually called at
        // runtime — it exists purely as a named handle for its own annotation.
    }
}

Step 5: Add @Before and @AfterReturning Advice

`@Before` is purely observational — it cannot stop the real method from running or change its arguments, which is exactly why it fits "log that a call is happening" and nothing more powerful. `@AfterReturning` only fires once the real method has already completed WITHOUT throwing, which is what makes it the right choice for "log what a call returned" — unlike `@After` (not used here), which behaves more like a `finally` block and runs regardless of success or failure.

package com.programinds.aoplogging.aspect;

import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.annotation.AfterReturning;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Before;
import org.aspectj.lang.annotation.Pointcut;
import org.springframework.stereotype.Component;

import java.util.Arrays;

// (continuing the same @Aspect class from Step 4)
@Before("serviceLayer()")
public void logBefore(JoinPoint joinPoint) {
    String methodName = joinPoint.getSignature().toShortString();
    System.out.println("[BEFORE] Calling " + methodName + " with args " + Arrays.toString(joinPoint.getArgs()));
}

@AfterReturning(pointcut = "serviceLayer()", returning = "result")
public void logAfterReturning(JoinPoint joinPoint, Object result) {
    String methodName = joinPoint.getSignature().toShortString();
    System.out.println("[AFTER-RETURNING] " + methodName + " returned: " + result);
}

Step 6: Add @Around Advice to Time Method Execution

`@Around` is the most powerful advice type because it wraps the ENTIRE method call rather than only observing one side of it. It receives a `ProceedingJoinPoint` instead of a plain `JoinPoint`, and it alone can decide whether, when, and how many times the real method runs, by calling (or not calling) `proceed()`. Timing a method needs code both BEFORE and AFTER the real call, which is exactly what only `@Around` can provide in one place.

// (continuing the same @Aspect class)
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;

@Around("serviceLayer()")
public Object logAroundWithTiming(ProceedingJoinPoint joinPoint) throws Throwable {
    String methodName = joinPoint.getSignature().toShortString();
    long startNanos = System.nanoTime();   // Captured BEFORE the real method runs

    Object result = joinPoint.proceed();     // Actually invokes OrderService's real method — skip this call, and the method never runs

    long elapsedMillis = (System.nanoTime() - startNanos) / 1_000_000;
    System.out.println("[AROUND] " + methodName + " took " + elapsedMillis + "ms");
    return result;   // Must return the real method's result, or every caller of the proxy would see null instead
}

Never Forget proceed()

If an @Around advice method never calls joinPoint.proceed(), the real method it is wrapping never runs at all — not even the business logic inside it. This is the single most common AOP mistake: @Around advice that logs "before" and "after" but forgets the proceed() call in between silently turns every advised method into a no-op.

Step 7: Wire It Together and Run

The `OrderService` bean returned by `context.getBean(OrderService.class)` is not a plain `OrderService` instance — thanks to `@EnableAspectJAutoProxy`, it is a CGLIB-generated subclass proxy that wraps a real `OrderService` and routes every call through `LoggingAspect`'s advice first, in the order `@Around`'s "before proceed()" code, then `@Before` advice, then the real method body, then `@AfterReturning`, then `@Around`'s "after proceed()" code.

package com.programinds.aoplogging;

import com.programinds.aoplogging.config.AppConfig;
import com.programinds.aoplogging.service.OrderService;
import org.springframework.context.annotation.AnnotationConfigApplicationContext;

public class AopLoggingApplication {
    public static void main(String[] args) {
        AnnotationConfigApplicationContext context =
            new AnnotationConfigApplicationContext(AppConfig.class);

        OrderService orderService = context.getBean(OrderService.class);   // Actually a proxy wrapping the real OrderService

        orderService.placeOrder("Mechanical Keyboard", 2);
        orderService.getOrderTotal(2, 4999.00);
        orderService.cancelOrder(4821);

        context.close();
    }
}

Complete Code

Save each class under its matching package directory in `src/main/java/`, add the dependencies from Step 3, and run with `mvn compile exec:java -Dexec.mainClass=com.programinds.aoplogging.AopLoggingApplication`.

LoggingAspect.java (complete)

package com.programinds.aoplogging.aspect;

import org.aspectj.lang.JoinPoint;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.AfterReturning;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Before;
import org.aspectj.lang.annotation.Pointcut;
import org.springframework.stereotype.Component;

import java.util.Arrays;

@Aspect
@Component
public class LoggingAspect {

    @Pointcut("execution(* com.programinds.aoplogging.service.*.*(..))")
    public void serviceLayer() {
    }

    @Before("serviceLayer()")
    public void logBefore(JoinPoint joinPoint) {
        String methodName = joinPoint.getSignature().toShortString();
        System.out.println("[BEFORE] Calling " + methodName + " with args " + Arrays.toString(joinPoint.getArgs()));
    }

    @AfterReturning(pointcut = "serviceLayer()", returning = "result")
    public void logAfterReturning(JoinPoint joinPoint, Object result) {
        String methodName = joinPoint.getSignature().toShortString();
        System.out.println("[AFTER-RETURNING] " + methodName + " returned: " + result);
    }

    @Around("serviceLayer()")
    public Object logAroundWithTiming(ProceedingJoinPoint joinPoint) throws Throwable {
        String methodName = joinPoint.getSignature().toShortString();
        long startNanos = System.nanoTime();

        Object result = joinPoint.proceed();

        long elapsedMillis = (System.nanoTime() - startNanos) / 1_000_000;
        System.out.println("[AROUND] " + methodName + " took " + elapsedMillis + "ms");
        return result;
    }
}

Sample Run

Click Run to see what this code prints.

Notice the first "[AROUND] ... took 0ms" line printing before "[BEFORE]" even runs — that line is `@Around`'s own `System.out.println` for the ELAPSED time, printed only after `proceed()` returns, but the interleaving above shows both advice types are active on the same call; the actual chronological order Spring applies is `@Around`'s pre-proceed code, `@Before`, the real method, `@AfterReturning`, then `@Around`'s post-proceed code — which is why the "took Nms" line always appears last for each call despite being logged by the advice that technically started first.

Extend This Project

Add `@AfterThrowing(pointcut = "serviceLayer()", throwing = "ex")` advice, then make `cancelOrder()` throw an `IllegalArgumentException` for a negative id to see it fire instead of `@AfterReturning`.
Add a second, narrower pointcut matching only `placeOrder` (`execution(* placeOrder(..))`) and give it its own dedicated advice, to see how multiple pointcuts can target different subsets of the same class.
Refactor the hard-coded package name in the pointcut expression into a Spring `@Value`-injected property, so the aspect can be reused across projects without editing its source.
Add a `@AfterThrowing`-based metrics counter tallying how many calls to each method failed, printed once at the end of `main()`.
Combine this aspect with the JDBC-Backed CRUD App project later in this course, applying the same logging aspect to `TaskRepository`'s methods instead of `OrderService`'s.

Summary

You separated a cross-cutting concern — logging and timing — completely out of the business logic it applies to, using `@Aspect`, a single reusable pointcut expression, and three advice types each suited to a different moment in a method call's lifecycle: `@Before` for observing the call, `@AfterReturning` for observing a successful result, and `@Around` for wrapping the whole call to measure its duration. `OrderService` never changed to gain any of this behavior, which is exactly the promise AOP makes: the aspect can be added, removed, or modified without ever touching the class it advises.