ApiLoggingAspect { @Around("publicMethod() && @within(apiController)") public Object around(ProceedingJoinPoint point, ApiController apiController) throws Throwable { StopWatch watch = new StopWatch(); watch.start(); ApiLogger apiLogger = new ApiLogger(apiLoggingProperties, apiController.resourceName(), LoggerFactory.getLogger(point.getTarget().getClass())); MethodSignature signature = (MethodSignature) point.getSignature(); Object[] args = point.getArgs(); String[] parameterNames = signature.getParameterNames(); Class[] parameterTypes = signature.getParameterTypes(); String normalizedMethodName = capitalize(decamelize(signature.getName())); List<Integer> complexTypeIndexes = Lists.newArrayList(); StringJoiner parametersJoiner = new StringJoiner(", ", "[", "]"); if (parameterTypes.length > 0) { for (int i = 0; i < parameterTypes.length; i++) { if (parameterTypes[i].isPrimitive() || parameterTypes[i].getName().startsWith("java")) { parametersJoiner.add(String.join(": ", parameterNames[i], String.valueOf(args[i]))); } else { complexTypeIndexes.add(i); } } } apiLogger.logEntryPoint(normalizedMethodName, evaluateParamJoiner(parametersJoiner)); if (!complexTypeIndexes.isEmpty()) { StringJoiner complexParamsJoiner = new StringJoiner(", ", "[", "]"); complexTypeIndexes.stream() .forEach(index -> complexParamsJoiner.add(String.join(": ", parameterNames[index], String.valueOf(args[index])))); apiLogger.logCustomObjectDetails(evaluateParamJoiner(complexParamsJoiner)); } try { return evaluateResponse(apiLogger, point.proceed()); } finally { watch.stop(); apiLogger.logExitPoint(normalizedMethodName, evaluateParamJoiner(parametersJoiner), watch.getTotalTimeSeconds()); } }  @Pointcut("execution(* *(..))") void publicMethod(); @Around("publicMethod() && @within(apiController)") Object around(ProceedingJoinPoint point, ApiController apiController);  }
@Test public void singleStringParam() throws Throwable { prepareTest(); when(point.getArgs()).thenReturn(new Object[]{"asd"}); when(methodSignature.getName()).thenReturn("findById"); when(methodSignature.getParameterNames()).thenReturn(new String[]{"id"}); when(methodSignature.getParameterTypes()).thenReturn(new Class[]{String.class}); logbackVerifier.expectMessage(INFO, "[JobOffer] Find by id [id: asd]."); logbackVerifier.expectMessage(INFO, "[JobOffer] Find by id [id: asd] took"); loggingAspect.around(point, apiController); }
@Test public void singleStringParamWithoutResource() throws Throwable { prepareTest(); when(apiController.resourceName()).thenReturn(""); when(point.getArgs()).thenReturn(new Object[]{"asd"}); when(methodSignature.getName()).thenReturn("findById"); when(methodSignature.getParameterNames()).thenReturn(new String[]{"id"}); when(methodSignature.getParameterTypes()).thenReturn(new Class[]{String.class}); logbackVerifier.expectMessage(INFO, "Find by id [id: asd]."); logbackVerifier.expectMessage(INFO, "Find by id [id: asd] took"); loggingAspect.around(point, apiController); }
@Test public void multipleStandardJavaParams() throws Throwable { prepareTest(); when(point.getArgs()).thenReturn(new Object[]{ZonedDateTime.parse("2010-01-10T10:00Z"), Integer.valueOf(2010)}); when(methodSignature.getName()).thenReturn("searchWithParams"); when(methodSignature.getParameterNames()).thenReturn(new String[]{"dateTime", "number"}); when(methodSignature.getParameterTypes()).thenReturn(new Class[]{ZonedDateTime.class, Integer.TYPE}); logbackVerifier.expectMessage(INFO, "[JobOffer] Search with params [dateTime: 2010-01-10T10:00Z, number: 2010]."); loggingAspect.around(point, apiController); }
@Test public void mixedParams() throws Throwable { prepareTest(); when(point.getArgs()).thenReturn(new Object[]{Duty.newBuilder().setName("abc").setValue(5).build(), Integer.valueOf(2010)}); when(methodSignature.getName()).thenReturn("searchWithParams"); when(methodSignature.getParameterNames()).thenReturn(new String[]{"duty", "number"}); when(methodSignature.getParameterTypes()).thenReturn(new Class[]{Duty.class, Integer.TYPE}); logbackVerifier.expectMessage(INFO, "[JobOffer] Search with params [number: 2010]."); logbackVerifier.expectMessage(INFO, "[JobOffer] Details: [duty: Duty(name=abc, value=5, cachedHashCode=2987940)]."); loggingAspect.around(point, apiController); }
@Test public void jsonApiListReturnedSingleElement() throws Throwable { prepareTest(); when(point.getArgs()).thenReturn(new Object[]{}); when(methodSignature.getName()).thenReturn("find"); when(methodSignature.getParameterNames()).thenReturn(new String[]{}); when(methodSignature.getParameterTypes()).thenReturn(new Class[]{}); when(point.proceed()).thenReturn(JsonApiList.wrap(Duty.newBuilder().setName("abc").setValue(5).build()).build()); logbackVerifier.expectMessage(INFO, "[JobOffer] Find."); logbackVerifier.expectMessage(INFO, "[JobOffer] Returning 1 item."); logbackVerifier.expectMessage(INFO, "[JobOffer] Find took"); loggingAspect.around(point, apiController); }
@Test public void jsonApiListReturnedMultipleElements() throws Throwable { prepareTest(); when(point.getArgs()).thenReturn(new Object[]{}); when(methodSignature.getName()).thenReturn("find"); when(methodSignature.getParameterNames()).thenReturn(new String[]{}); when(methodSignature.getParameterTypes()).thenReturn(new Class[]{}); when(point.proceed()).thenReturn(JsonApiList.wrap( Lists.newArrayList( Duty.newBuilder().setName("abc").setValue(5).build(), Duty.newBuilder().setName("xxx").setValue(50).build())) .build()); logbackVerifier.expectMessage(INFO, "[JobOffer] Returning 2 items"); loggingAspect.around(point, apiController); }
@Test public void jsonApiObjectReturned() throws Throwable { prepareTest(); when(point.getArgs()).thenReturn(new Object[]{}); when(methodSignature.getName()).thenReturn("findById"); when(methodSignature.getParameterNames()).thenReturn(new String[]{}); when(methodSignature.getParameterTypes()).thenReturn(new Class[]{}); when(point.proceed()).thenReturn(JsonApiObject.wrap(Duty.newBuilder().setName("abc").setValue(5).build()).build()); logbackVerifier.expectMessage(INFO, "[JobOffer] Find by id."); logbackVerifier.expectMessage(INFO, "[JobOffer] Returning [Duty("); logbackVerifier.expectMessage(INFO, "[JobOffer] Find by id took"); loggingAspect.around(point, apiController); }
@Test public void singleCustomParam() throws Throwable { prepareTest(); when(point.getArgs()).thenReturn(new Object[]{Duty.newBuilder().setName("abc").setValue(5).build()}); when(methodSignature.getName()).thenReturn("create"); when(methodSignature.getParameterNames()).thenReturn(new String[]{"duty"}); when(methodSignature.getParameterTypes()).thenReturn(new Class[]{Duty.class}); logbackVerifier.expectMessage(INFO, "[JobOffer] Create."); logbackVerifier.expectMessage(INFO, "[JobOffer] Details: [duty: Duty(name=abc, value=5, cachedHashCode=2987940)]."); logbackVerifier.expectMessage(INFO, "[JobOffer] Create took"); loggingAspect.around(point, apiController); }
@Test public void multipleCustomParam() throws Throwable { prepareTest(); when(point.getArgs()).thenReturn(new Object[]{Duty.newBuilder().setName("abc").setValue(5).build(), Duty.newBuilder().setName("xxx").setValue(10).build()}); when(methodSignature.getName()).thenReturn("doIt"); when(methodSignature.getParameterNames()).thenReturn(new String[]{"duty", "duty2"}); when(methodSignature.getParameterTypes()).thenReturn(new Class[]{Duty.class, Duty.class}); logbackVerifier.expectMessage(INFO, "[JobOffer] Do it."); logbackVerifier.expectMessage(INFO, "Details: [duty: Duty(name=abc, value=5, cachedHashCode=2987940), duty2: Duty(name=xxx, value=10, cachedHashCode=3694931)]"); logbackVerifier.expectMessage(INFO, "[JobOffer] Do it took"); loggingAspect.around(point, apiController); }