Request log in AEM plays a very vital role towards analysis of site performance. For each request and response one entry is written into request.log file, you can analyze this log file to find out maximum time taken by a request to load and then troubleshoot the issue to increase overall site performance.

After completing this tutorial you will have a clear understanding about:-

• How to read or interpret request log.
• How to use rlog.jar to sort request log file.
• Troubleshoot pages taking longer time to load.

Below information can be extracted from Request log in aem:-

• Monitor traffic on website.
• Time taken to load each page in aem.
• How many concurrent or parallel users are active.

Follow below steps to Read or Analyze Request log in AEM:-

Go to <cq-installation-dir>/crx-quickstart/logs/request.log and open request.log file. It should look like this:-

02/Nov/2016:12:17:18 +0530 [5] -> GET /etc/clientlibs/granite/jquery.js HTTP/1.1
02/Nov/2016:12:17:18 +0530 [6] -> GET /etc/clientlibs/granite/typekit.js HTTP/1.1
02/Nov/2016:12:17:18 +0530 [6] <- 200 application/x-javascript 16ms 02/Nov/2016:12:17:18 +0530 [7] -> GET /libs/granite/core/content/login/clientlib.js HTTP/1.1
02/Nov/2016:12:17:18 +0530 [7] <- 200 application/x-javascript 15ms
02/Nov/2016:12:17:18 +0530 [4] <- 200 text/css 78ms
02/Nov/2016:12:17:18 +0530 [5] <- 200 application/x-javascript 78ms 02/Nov/2016:12:17:18 +0530 [8] -> GET /etc/clientlibs/granite/typekit/jwv7ouu/c/jwv7ouu-d.css HTTP/1.1
02/Nov/2016:12:17:18 +0530 [8] <- 200 text/css 49ms 02/Nov/2016:12:17:18 +0530 [9] -> GET /etc/clientlibs/granite/coralui2/resources/components/icon/AdobeIcons-9f70cb0d4828664f2e4de73fb6fb8149.eot HTTP/1.1
02/Nov/2016:12:17:18 +0530 [9] <- 200 application/vnd.ms-fontobject 30ms

Following information can be extracted from above request log file:

• Date and time: (02/Nov/2016:12:17:18 +0530) when request and response is made
• ID/ Number of request: (8 in above example), the response for this request will have the same ID so you can find out the request and response easily
• Arrow indicates whether it is a request or response
  •  -> Forward Arrow means it is a request
  • <- Backward arrow means it is a response

Each Request contains below information:-

• Method (GET, POST or HEAD) – GET
• Requested Resource Path  – /etc/clientlibs/granite/typekit/jwv7ouu/c/jwv7ouu-d.css
• Protocol – HTTP/1.1

Response contains below information:-

• Status Code – 200 means “success”, 404 means “page not found”
• MIME Type – If available
• Response Time – 49 ms

Use rlog.jar to sort request log file:-

AEM comes with a tool called rlog.jar that can be used to quickly sort request log in ascending order to display requests by duration, from longest to shortest time. Its very easy to use and effective tool that can be used for analyzing website performance.

Follow below steps to run rlog jar :-

• Rlog.jar tool is avilable under <cq-installation-dir>/crx-quickstart/opt/helpers folder.
• Open command prompt go to request log <cq-installation-dir>/crx-quickstart/logs/ and enter below command to run the tool:
  • java -jar ../opt/helpers/rlog.jar  request.log

Once the command is executed successfully, all the request gets sorted in ascending order by the response time with the request on the top as the slowest one. Refer below example and screenshot for your reference.

C:\Ankur\Softwares\AEM 6\crx-quickstart\logs>java -jar ../opt/helpers/rlog.jar request.log
Picked up JAVA_TOOL_OPTIONS: -Djava.vendor="Sun Microsystems Inc."
*Info * Parsed 620 requests.
*Info * Time for parsing: 42ms
*Info * Time for sorting: 3ms
*Info * Total Memory: 121mb
*Info * Free Memory: 119mb
*Info * Used Memory: 1mb
------------------------------------------------------
17640ms 02/Nov/2016:13:41:40 +0530 200 GET /mnt/overlay/granite/operations/config/diagnosis/granite:status.zip/configuration-status-20161102-134140.zip application/zip
2473ms 02/Nov/2016:13:07:18 +0530 200 GET /libs/granite/operations/content/healthreports.html text/html
2325ms 02/Nov/2016:13:39:16 +0530 200 GET /libs/granite/operations/content/hr.subview.html/system/sling/monitoring/mbeans/org/apache/sling/healthcheck/HealthCheck/securitychecks text/ht
1794ms 02/Nov/2016:12:22:28 +0530 404 GET /favicon.ico image/x-icon
1732ms 02/Nov/2016:19:02:45 +0530 200 GET /libs/granite/operations/content/hr.subview.html/system/sling/monitoring/mbeans/org/apache/sling/healthcheck/HealthCheck/systemchecks text/html
1724ms 02/Nov/2016:13:07:21 +0530 200 GET /libs/granite/operations/content/diagnosis.html text/html
1590ms 02/Nov/2016:13:40:22 +0530 200 GET /libs/granite/operations/content/hr.subview.html/system/sling/monitoring/mbeans/org/apache/sling/healthcheck/HealthCheck/systemchecks text/html
1341ms 02/Nov/2016:12:17:16 +0530 200 GET /libs/granite/core/content/login.html?resource=%2F&$$login$$=%24%24login%24%24 text/html;charset=utf-8
999ms 02/Nov/2016:12:20:32 +0530 200 GET /projects.html text/html; charset=utf-8
862ms 02/Nov/2016:13:44:20 +0530 200 GET /libs/granite/operations/content/healthreports.html text/html
858ms 02/Nov/2016:13:15:53 +0530 200 GET /libs/granite/operations/content/hr.html/system/sling/monitoring/mbeans/org/apache/sling/healthcheck/HealthCheck/requestsStatus text/html
835ms 02/Nov/2016:13:37:14 +0530 200 GET /libs/granite/operations/content/healthreports.html text/html

Note:- Here we are interested in the pages that are taking longer time for loading. We can analyze them and can reduce the average response time of website. If you want to analyze multiple request log files you will have to combine all logs files first and then run the command.

Troubleshooting Pages taking longer time to load:-

Once we got the requests that are taking longer time to load the page. We can follow below basic troubleshooting steps:-

• If a particular page is responding slow every time, Check if this page interacts with any other external system to get the data, if yes then check if external system is responding slowly.
•  Check the slowest request and compare that with other request that are of same time, are response of those request were also slow at that time as compared to request on other publish servers, if yes you need to find out the reason for slowness on your publish server(might be you GC is high on that server and you need to run offline tar compaction).
• Lastly check whether caching is configured properly on dispatcher or not, usually you should not see multiple request frequently of same page which is supposed to be cached (like a request that end with .html, have a status code of 200 and doesn’t have any query parameters).