March 15, 2020
Estimated Post Reading Time ~

Explore Request Logs in AEM/Adobe CQ5

Request log in AEM plays a very vital role in the 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 the 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 of:-
· How to read or interpret the request log.
· How to use rlog.jar to sort request log files.
· Troubleshoot pages taking a longer time to load.

Below information can be extracted from Request log in AEM:-
· Monitor traffic on the 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


The following information can be extracted from the 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

The 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. It's 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 available 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 for example and screenshot for your reference.

C:\User\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 a long time to load:-
Once we got the requests that are taking a long time to load the page. We can follow below basic troubleshooting steps:-
· If a particular page is responding slowly every time, Check if this page interacts with any other external system to get the data, if yes then check if the external system is responding slowly.
· Check the slowest request and compare that with other requests that are of the same time, are the 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 requests frequently of the 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).




By aem4beginner

No comments:

Post a Comment

If you have any doubts or questions, please let us know.