Magnolia CMS provided you with default audit logging service where some major actions such as login, logout, activate and deactivate actions are logged to default appender. Follow the same principle with some additional integrations here, I would like to introduce an approach on how to implement some extra logging information with minimal affect impact on existing code base.
Overview
An example use case is that we would like to log some info information after execution of info.magnolia.importexport.command.JcrImportCommand where current implementation didn't provide any logging out of the box. We just don't want to alter existing code to include few lines of code, rebuild the whole bundle and redeploy them that takes us too much time and effort. Here we can find an easy way to achieve that with an affordable effort.efforts. By utilizing AOP - Load time weaving, we just have to implement our Before or After advice for some information in this case. Moreover you can also alter some instance object values or parameters during runtime (on the fly). Therefore this is an easy way to achieve our goal with an affordable effort.
Implementation
Add AspectJ libraries to your Maven project
...
Put your aop.xml under src/main/resource folder in development mode or right under WEB-INF/classes in production mode, notice underlying lines below:
Image Removedour include tags which define where we would like to put our point cuts.
| Code Block |
|---|
|
<aspectj>
<aspects>
<aspect name="info.magnolia.audit.AuditLogger" />
<weaver options="-showWeaveInfo">
<include within="info.magnolia.importexport.command.JcrImportCommand" />
<include within="info.magnolia.ui.framework.action.*" />
<include within="info.magnolia.commands.impl.*" />
<include within="info.magnolia.audit.*"/>
</weaver>
</aspects>
</aspectj> |
Implement your Aspect
In this example, I'm using info.magnolia.audit.AuditLogger as our aspect file AuditLogger.java, just notice the advice below:
Image Removed
| Code Block |
|---|
|
@Aspect
public class AuditLogger {
private static final Logger log = LoggerFactory.getLogger(AuditLogger.class);
@Before("execution(* info.magnolia.importexport.command.JcrImportCommand.execute(..)) ")
public void beforeImportLogger(JoinPoint point) throws RepositoryException {
JcrImportCommand runner = (JcrImportCommand) point.getThis();
Context context = (Context) point.getArgs()[0];
final Node node = context.getJCRSession(runner.getRepository()).getNode(runner.getPath());
log.info("Importing file {} to node path {}.", runner.getFileName(), node.getPath());
log.info("Before function {}.{}({}) called by user {}.",
point.getTarget().getClass().getName(),
MethodSignature.class.cast(point.getSignature()).getMethod().getName(),
Arrays.toString(point.getArgs()),
getUser());
}
@After("execution(* info.magnolia.importexport.command.JcrImportCommand.execute(..)) ")
public void afterImportLogger(JoinPoint point) {
log.info("After function {}.{}({}) called by user {}.",
point.getTarget().getClass().getName(),
MethodSignature.class.cast(point.getSignature()).getMethod().getName(),
Arrays.toString(point.getArgs()),
getUser());
}
...
} |
Enabling Load-Time Weaving
AspectJ load-time weaving can be enabled using AspectJ agent that can get involved in the class loading process and weave any types before they are defined in the VM. We specify the javaagent option to the JVM -javaagent:pathto/aspectjweaver.jar or using Maven plugin to configure the javaagent javaagent:
...
...
...
...
...
groupId>
<artifactId>maven-surefire-plugin</ |
...
artifactId>
<version>2.10</version>
<configuration>
<argLine>
-javaagent:"${settings.localRepository}"/org/aspectj/ |
...
aspectjweaver/${aspectj.version}/ |
...
aspectjweaver-${aspectj.version}.jar |
...
</argLine>
<useSystemClassLoader>true</useSystemClassLoader>
<forkMode>always</forkMode>
</configuration>
</plugin> |
Verify your setup
Few lines of log should be printed out in your default log when we import a page under our 'travel' demo site:
Image Removed
| Code Block |
|---|
|
2018-06-12 11:10:10,447 INFO info.magnolia.audit.AuditLogger : Importing file website.mypage.xml to node path /travel.
2018-06-12 11:10:10,447 INFO info.magnolia.audit.AuditLogger : Before function info.magnolia.importexport.command.JcrImportCommand.execute([info.magnolia.context.SimpleContext@cfd5f7a]) called by user superuser.
2018-06-12 11:10:10,498 INFO info.magnolia.audit.AuditLogger : After function info.magnolia.importexport.command.JcrImportCommand.execute([info.magnolia.context.SimpleContext@cfd5f7a]) called by user superuser.
|
Log4j2 config
Configure log4j2.xml to direct audit log info to magnolia-audit.log just by adding your aspect class to the log such as this case:
| Code Block |
|---|
<Logger name="info.magnolia.audit.AuditLogger" level="DEBUG" additivity="true">
<AppenderRef ref="log-audit"/>
</Logger> |
Recommended update for magnolia-audit.log appender to have a nicer output - please change your existing PatternLayout using provided patter here for better log info "%-5p %c %d{dd.MM.yyyy HH:mm:ss} -- %m%n"
| Code Block |
|---|
|
<RollingFile name="sync-log-audit"
fileName="${magnolia.logs.dir}/magnolia-audit.log"
filePattern="${magnolia.logs.dir}/magnolia-audit-%i.log"
append="true">
<PatternLayout pattern="%-5p %c %d{dd.MM.yyyy HH:mm:ss} -- %m%n"/>
<ThresholdFilter level="DEBUG"/>
<Policies>
<SizeBasedTriggeringPolicy size="1MB"/>
</Policies>
<DefaultRolloverStrategy max="5"/>
</RollingFile>
<Async name="log-audit">
<AppenderRef ref="sync-log-audit"/>
</Async> |
Performance warning
Load time weaving will intercept your instance at JVM level. This instrumentation will produce some overhead and has its performance trade-offs. So please just use it to trace your issue then turn it off later. Also this approach has a limitation that you have to restart your running instance to get it work.Further settings will be provided later. Hope this helps!