To my understanding, @Around
annotation on Spring AOP can handle any return type on methods; with void
type returning null.
This is a simple advice to log duration of a method:
@Target(ElementType.METHOD)
@Retention(RetentionPolicy.RUNTIME)
public @interface Profiling { }
@Aspect
@Component
public class ProfilingAspect {
// ...
@Around("@annotation(profilingAnnotation)")
public Object logDuration(ProceedingJoinPoint joinPoint, Profiling profilingAnnotation) throws Throwable {
long startTime = Instant.now().toEpochMilli();
Object result = null;
try {
result = joinPoint.proceed(); // on void methods, this supposed to return null
} catch (Throwable e) {
logger.error(e.getMessage(), e);
throw e;
} finally {
long endTime = Instant.now().toEpochMilli(); // Below is not ran all together
long duration = endTime - startTime;
logger.info(joinPoint.getSignature().toShortString()+": "+duration+"ms");
}
//return the result to the caller
return result;
}
}
However, when invoked on this method, it doesn't return anything and instead skips every code after proceed()
altogether. Even finally
block.
This is the problematic code:
@GetMapping("/members/exportpdf")
@Profiling
public void exportToPDF(@RequestParam(required = false)String role, HttpServletResponse response) throws DocumentException, IOException, ExecutionException, InterruptedException {
CompletableFuture<List<GuildMember>> guildMembers;
if (role==null) {
guildMembers = guildService.findAll(); // Async Method
} else {
guildMembers = guildService.findByType(role); // Async Method
}
response.setContentType("application/pdf");
DateFormat dateFormatter = new SimpleDateFormat("yyyy-MM-dd_HH:mm:ss");
String currentDateTime = dateFormatter.format(new Date());
String headerKey = "Content-Disposition";
String headerValue = "inline; filename=guildmembers_" + currentDateTime + ".pdf";
response.setHeader(headerKey, headerValue);
PDFExporter exporter = new PDFExporter(guildMembers);
exporter.export(response).get(); // exporter.export(..) is an Async method returning CompletableFuture<Void>
}
How is this possible? Am I missing something here on the configuration? Or is it a bug on Spring?
Note. I'm using Spring Boot 2.4.4 with starter dependencies
Edit. PDFExporter.export()
uses OutputStream
on HttpServletResponse
to print application/pdf
to the user and returns CompletableFuture<Void>
. As to why, the method communicates with the async functions above, as such I want to guarantee the operation is finished somehow.
In order to teach you what an MCVE is and how to better ask questions here, I am going to show you the MCVE I created according to your code fragments and description:
Dependency classes we need in order to make the code compile:
package de.scrum_master.spring.q66958382;
import java.lang.annotation.ElementType;
import java.lang.annotation.Retention;
import java.lang.annotation.RetentionPolicy;
import java.lang.annotation.Target;
@Target(ElementType.METHOD)
@Retention(RetentionPolicy.RUNTIME)
public @interface Profiling {}
package de.scrum_master.spring.q66958382;
public class GuildMember {
private String name;
public GuildMember(String name) {
this.name = name;
}
@Override
public String toString() {
return "GuildMember{" +
"name='" + name + '\'' +
'}';
}
}
PDFExporter
utility:
Maybe you are using the PDFExporter
from PrimeFaces, but that is just a guess. In any case, it seems not to be a Spring component, because later you call the constructor instead of getting a bean instance from the application context. So I am modeling it here as a simple POJO too.
package de.scrum_master.spring.q66958382;
import org.springframework.scheduling.annotation.Async;
import javax.servlet.http.HttpServletResponse;
import java.util.List;
import java.util.concurrent.CompletableFuture;
public class PDFExporter {
CompletableFuture<List<GuildMember>> guildMembers;
public PDFExporter(CompletableFuture<List<GuildMember>> guildMembers) {
this.guildMembers = guildMembers;
}
@Async
public CompletableFuture<Void> export(HttpServletResponse response) {
return CompletableFuture.supplyAsync(() -> {
try { Thread.sleep(1000); } catch (InterruptedException e) { e.printStackTrace(); }
return null;
});
}
}
Service with @Async
methods:
Next, I was making an educated guess about what your guild service might look like:
package de.scrum_master.spring.q66958382;
import org.springframework.scheduling.annotation.Async;
import org.springframework.stereotype.Service;
import java.util.Arrays;
import java.util.Collections;
import java.util.List;
import java.util.concurrent.CompletableFuture;
@Service
public class GuildService {
@Async
public CompletableFuture<List<GuildMember>> findAll() {
return CompletableFuture.supplyAsync(() -> {
try { Thread.sleep(1000); } catch (InterruptedException e) { e.printStackTrace(); }
return Arrays.asList(new GuildMember("Jane"), new GuildMember("John"), new GuildMember("Eve"));
});
}
@Async
public CompletableFuture<List<GuildMember>> findByType(String role) {
return CompletableFuture.supplyAsync(() -> {
try { Thread.sleep(1000); } catch (InterruptedException e) { e.printStackTrace(); }
return Collections.singletonList(new GuildMember("Eve"));
});
}
}
Component to be targeted by profiling aspect:
Here is your sample component, only slightly streamlined with regard to guildMembers
initialisation. But it does not change the functionality at all:
package de.scrum_master.spring.q66958382;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.stereotype.Component;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RequestParam;
import javax.servlet.http.HttpServletResponse;
import java.io.IOException;
import java.text.DateFormat;
import java.text.SimpleDateFormat;
import java.util.Date;
import java.util.List;
import java.util.concurrent.CompletableFuture;
import java.util.concurrent.ExecutionException;
@Component
public class MyComponent {
@Autowired
private GuildService guildService;
@GetMapping("/members/exportpdf")
@Profiling
public void exportToPDF(@RequestParam(required = false) String role, HttpServletResponse response) throws IOException, ExecutionException, InterruptedException {
CompletableFuture<List<GuildMember>> guildMembers = role == null ? guildService.findAll() : guildService.findByType(role);
response.setContentType("application/pdf");
DateFormat dateFormatter = new SimpleDateFormat("yyyy-MM-dd_HH:mm:ss");
String currentDateTime = dateFormatter.format(new Date());
String headerKey = "Content-Disposition";
String headerValue = "inline; filename=guildmembers_" + currentDateTime + ".pdf";
response.setHeader(headerKey, headerValue);
PDFExporter exporter = new PDFExporter(guildMembers);
exporter.export(response).get();
}
}
Driver application + @EnableAsync
configuration:
package de.scrum_master.spring.q66958382;
import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
import org.springframework.context.ConfigurableApplicationContext;
import org.springframework.context.annotation.Configuration;
import org.springframework.mock.web.MockHttpServletResponse;
import org.springframework.scheduling.annotation.EnableAsync;
import java.io.IOException;
import java.util.concurrent.ExecutionException;
@SpringBootApplication
@Configuration
@EnableAsync
public class DemoApplication {
public static void main(String[] args) throws InterruptedException, IOException, ExecutionException {
try (ConfigurableApplicationContext appContext = SpringApplication.run(DemoApplication.class, args)) {
doStuff(appContext);
}
}
private static void doStuff(ConfigurableApplicationContext appContext) throws InterruptedException, IOException, ExecutionException {
MyComponent myComponent = appContext.getBean(MyComponent.class);
myComponent.exportToPDF("admin", new MockHttpServletResponse());
}
}
Profiling aspect:
Last, but not least, here is the aspect. It is also the same you presented, only a bit less complicated concerning how to return the result. But again, this does not change the fact that the aspect works as expected:
package de.scrum_master.spring.q66958382;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Component;
import java.time.Instant;
@Aspect
@Component
public class ProfilingAspect {
private static final Logger logger = LoggerFactory.getLogger(ProfilingAspect.class);
@Around("@annotation(profilingAnnotation)")
public Object logDuration(ProceedingJoinPoint joinPoint, Profiling profilingAnnotation) throws Throwable {
long startTime = Instant.now().toEpochMilli();
try {
return joinPoint.proceed();
}
catch (Throwable e) {
logger.error(e.getMessage(), e);
throw e;
}
finally {
long duration = Instant.now().toEpochMilli() - startTime;
logger.info(joinPoint.getSignature().toShortString() + ": " + duration + " ms");
}
}
}
Console log:
If you run the application, the console log says:
. ____ _ __ _ _
/\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
\\/ ___)| |_)| | | | | || (_| | ) ) ) )
' |____| .__|_| |_|_| |_\__, | / / / /
=========|_|==============|___/=/_/_/_/
:: Spring Boot :: (v2.1.8.RELEASE)
2021-04-06 09:18:10.793 INFO 13616 --- [ main] d.s.spring.q66958382.DemoApplication : Starting DemoApplication on Xander-Ultrabook with PID 13616 (C:\Users\alexa\Documents\java-src\spring-aop-playground\target\classes started by alexa in C:\Users\alexa\Documents\java-src\spring-aop-playground)
(...)
2021-04-06 09:18:14.809 INFO 13616 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port(s): 8080 (http) with context path ''
2021-04-06 09:18:14.812 INFO 13616 --- [ main] d.s.spring.q66958382.DemoApplication : Started DemoApplication in 4.815 seconds (JVM running for 7.782)
(...)
2021-04-06 09:18:15.839 INFO 13616 --- [ main] d.s.spring.q66958382.ProfilingAspect : MyComponent.exportToPDF(..): 1014 ms
(...)
So if it does not work in your own application, either there is something different from how you described it or you are misinterpreting the log.