What is writing to my Oak repository?

If you were ever curious what’s happening on the Oak repository in AEM (and I can tell: a lot!), there’s a chance to logs all the repo write actions.

Just set create a logger for „org.apache.jackrabbit.oak.jcr.operations.write“ on loglevel TRACE and there you go.


21.05.2016 23:38:34.353 *TRACE* [Thread-8145] org.apache.jackrabbit.oak.jcr.operations.writes [session-43731] Setting property [/var/audit/com.day.cq.wcm.core.page/content/geometrixx/en/services/59a34cc6-ee23-4423-9e76-03868cd5e7e6/cq:userid]
21.05.2016 23:38:34.353 *TRACE* [Thread-8145] org.apache.jackrabbit.oak.jcr.operations.writes [session-43731] Setting property [/var/audit/com.day.cq.wcm.core.page/content/geometrixx/en/services/59a34cc6-ee23-4423-9e76-03868cd5e7e6/cq:path]
21.05.2016 23:38:34.353 *TRACE* [Thread-8145] org.apache.jackrabbit.oak.jcr.operations.writes [session-43731] Setting property [/var/audit/com.day.cq.wcm.core.page/content/geometrixx/en/services/59a34cc6-ee23-4423-9e76-03868cd5e7e6/cq:type]
21.05.2016 23:38:34.353 *TRACE* [Thread-8145] org.apache.jackrabbit.oak.jcr.operations.writes [session-43731] Setting property [/var/audit/com.day.cq.wcm.core.page/content/geometrixx/en/services/59a34cc6-ee23-4423-9e76-03868cd5e7e6/cq:category]
21.05.2016 23:38:34.353 *TRACE* [Thread-8145] org.apache.jackrabbit.oak.jcr.operations.writes [session-43731] Setting property [/var/audit/com.day.cq.wcm.core.page/content/geometrixx/en/services/59a34cc6-ee23-4423-9e76-03868cd5e7e6/userId]
21.05.2016 23:38:34.354 *TRACE* [Thread-8145] org.apache.jackrabbit.oak.jcr.operations.writes [session-43731] Setting property [/var/audit/com.day.cq.wcm.core.page/content/geometrixx/en/services/59a34cc6-ee23-4423-9e76-03868cd5e7e6/path]
21.05.2016 23:38:34.354 *TRACE* [Thread-8145] org.apache.jackrabbit.oak.jcr.operations.writes [session-43731] Setting property [/var/audit/com.day.cq.wcm.core.page/content/geometrixx/en/services/59a34cc6-ee23-4423-9e76-03868cd5e7e6/type]
21.05.2016 23:38:34.354 *TRACE* [Thread-8145] org.apache.jackrabbit.oak.jcr.operations.writes [session-43731] Setting property [/var/audit/com.day.cq.wcm.core.page/content/geometrixx/en/services/59a34cc6-ee23-4423-9e76-03868cd5e7e6/cq:properties]
21.05.2016 23:38:34.356 *TRACE* [Thread-8145] org.apache.jackrabbit.oak.jcr.operations.writes [session-43731] save

This thread with the name [Thread-8145] writes to the /var/audit path, so it’s quite likely related to the Audit logger. And this is using the session [session-43731]; the session name is random per session, but it is a very useful information:

  • you can identify a single session and what’s happening within this session. It is especially useful to determine what this specific session is writing and how often there are saves.
  • If you have the session name, and it is a long-running session, you can look up this session in the JMX MBean console; in Oak 1.0 and Oak 1.2 a stack trace is stored when the session is opened; in Oak 1.4 this has been removed for performance reasons, but you can get it back when you set the System property ‚oak.sessionStats.initStackTraceThreshold‘ to ‚0‘ (zero).

So if you need to understand what’s happening on your repository and what might causing repository write activity, this is an easy way to go. The only drawback: Such logging eats up a lot of diskspace, especially if run it for an extended period of time.

It’s also possible to do this for reads, but at least on Oak 1.0 it doesn’t log the paths, but only the operation; so it’s less useful here. And it produces a lot of data: Having it enabled for 2 minutes and 1 page load on my local instance it produced 10 megabytes of logs.

Advertisements