AEM_Interpreting the request.log

Monitoring traffic on your website:

  • The request log registers each request made, together with the response made:
1
2
09:43:41 [66] -> GET /author/y.html HTTP/1.1
09:43:41 [66] <- 200="" 797ms="" font="" html="" text="">
  • By totaling all the GET entries within a specific periods (e.g. over various 24 hour periods) you can make statements about the average traffic on your website.

Monitoring response times with the CQ request.log

  • A good starting point for performance analysis is the request log:

         <cq-installation-dir>/crx-quickstart/logs/request.log
  • The log looks as follows (the lines are shortened for simplicity):
1
2
3
4
31/Mar/2009:11:32:57 +0200 [379] -> GET /path/x HTTP/1.1
31/Mar/2009:11:32:57 +0200 [379] <- 200="" 33ms="" font="" html="" text="">
31/Mar/2009:11:33:17 +0200 [380] -> GET /path/y HTTP/1.1
31/Mar/2009:11:33:17 +0200 [380] <- 200="" 39ms="" application="" font="" json="">
This log has one line per request or response:
  • The date at which each request or response was made.
  • The number of the request, in square brackets. This number matches for the request and the response.
  • An arrow indicating whether this is a request (arrow pointing to the right) or a response (arrow to the left).
  • For requests, the line contains:
    • the method (typically, GET, HEAD or POST)
    • the requested page
    • the protocol
  • For responses, the line contains:
    • the status code (200 means “success”, 404 means “page not found”
    • the MIME type
    • the response time
You can see which pages or types of pages are slow, and if the overall performance is satisfactory.

Monitoring search response times with the CQ5 request.log

  • Search requests are also registered in the log file:
1
2
31/Mar/2009:11:35:34 +0200 [338] -> GET /author/playground/en/tools/search.html?query=dilbert&size=5&dispenc=utf-8 HTTP/1.1
31/Mar/2009:11:35:34 +0200 [338] <- 1562ms="" 200="" font="" html="" text="">
  • you can use scripts to extract the relevant information and build up statistics.
  • However, once you have determined the response time, 
  • you may need to analyze why the request is taking the time it does, and what can be done to improve the response.
Monitoring the number and impact of concurrent users
Again the request.log can be used to monitor concurrency and the system's reaction to it.
Tests must be made to determine how many concurrent users the system can handle before a negative impact is seen. Again scripts can be used to extract results from the log file:
  • monitor how many requests are made within a specific time span e.g. one minute
  • test the effects of a specific number of users all making the same requests at (as close as possible) the same time; e.g. 30 users clicking Save at the same time.
1
2
3
4
5
6
7
8
9
10
31/Mar/2009:11:45:29 +0200 [333] -> GET /author/libs/Personalize/content/statics.close.gif HTTP/1.1
31/Mar/2009:11:45:29 +0200 [334] -> GET /author/libs/Personalize/content/statics.detach.gif HTTP/1.1
31/Mar/2009:11:45:30 +0200 [335] -> GET /author/libs/CFC/content/imgs/logo.rZMNURccynWcTpCxyuBNiTCoiBMmw000.default.gif HTTP/1.1
31/Mar/2009:11:45:32 +0200 [335] <- 0ms="" 304="" font="" html="" text="">
31/Mar/2009:11:45:33 +0200 [334] <- 200="" 31ms="" font="" gif="" image="">
31/Mar/2009:11:45:38 +0200 [333] <- 200="" 31ms="" font="" gif="" image="">
31/Mar/2009:11:45:42 +0200 [336] -> GET /author/libs/CFC/content/imgs/logo.rZMNURccynWcTZRXunQbbQtvuuCMbRRBuWXz0000.default.gif HTTP/1.1
31/Mar/2009:11:45:43 +0200 [337] -> GET /author/titlebar_bg.gif HTTP/1.1
31/Mar/2009:11:45:43 +0200 [336] <- 0ms="" 304="" font="" html="" text="">
31/Mar/2009:11:45:44 +0200 [337] <- 0ms="" 304="" font="" html="" text="">

AEM_Basics of Performance Common issues and how to prevent them


AreaSymptom(s)To increase capacity...To reduce volume...
ClientHigh client CPU usage.Install a client CPU with higher performance.Simplify (HTML) layout.
 Low server CPU usage.Upgrade to a faster browser.Improve client-side cache.
 Some clients fast, some slow.  
Server   
NetworkCPU usage low on both servers and clients.Remove any network bottlenecks.Improve/optimize the configuration of the client cache.
 Browsing locally on the server is (comparatively) fast.Increase network bandwidth.Reduce the "weight" of your web pages (e.g. less images, optimized HTML).
Web-serverCPU usage on the web-server is high.Cluster your web-servers.Reduce the hits per page (visit).
  Use a hardware load-balancer. 
ApplicationServer CPU usage is high.Cluster your CQ5 instances.Search for, and eliminate, CPU and memory hogs (use code review, timing output, etc).
 High memory consumption. Improve caching on all levels.
 Low response times. Optimize templates and components (e.g. structure, logic).
Repository   
Cache   
  • Performance issues may stem from a number of causes that have nothing to do with your website, 
  • including temporary slowdowns in connection speed, CPU load, and many more.
  • It may also impact either all your visitors, or only a subset of them.
  • All this information needs to be obtained, sorted and analyzed before you can either optimize the general performance or solve specific issues.
  • Before you experience a performance issue:
    • collect as much information as possible to build up a good working knowledge of the system under normal circumstances
  • When you experience a performance issue:
    • try to replicate it with one (or preferably more) standard web-browsers, on a different client that you know has good general performance and/or on the server itself (if possible)
    • check whether anything (related to the system) has changed within an appropriate time-space, and if any of these changes could have impacted the performance
    • ask questions such as:
      • does the issue only occur at specific times?
      • does the issue only occur on specific pages?
      • are other requests impacted?
    • collect as much information as possible to compare with your knowledge of the system under normal circumstances:

AEM_How to find requests with long duration times

Solution:
§  AEM includes the rlog.jar file in the below path:  /crx-quickstart/opt/helpers
§  It is used to find requests with long duration times
The following command shows the possible arguments of rlog.jar file
$java -jar rlog.jar
Request Log Analyzer Version 21584 Copyright 2005 Day Management AG
Usage:
  java -jar rlog.jar [options]
Options:
  -h               Prints this usage.
  -n   Limits output to lines.
  -m Limits input to requests.
  -xdev            Exclude POST request to CRXDE.

For example, you can run it specifying request.log file as a parameter and show the 10 first requests that have the longest duration:

$ java -jar ../opt/helpers/rlog.jar -n 10 request.log

Trace results :

*Info * Parsed 464 requests.
*Info * Time for parsing: 22ms
*Info * Time for sorting: 2ms
*Info * Total Memory: 1mb
*Info * Free Memory: 1mb
*Info * Used Memory: 0mb
------------------------------------------------------
18051ms 31/Mar/2009:11:15:34 +0200 200 GET /content/geometrixx/en/company.html text/ html
2198ms 31/Mar/2009:11:15:20 +0200 200 GET /libs/cq/widgets.js application/x-javascript
1981ms 31/Mar/2009:11:15:11 +0200 200 GET /libs/wcm/content/welcome.html text/html
1973ms 31/Mar/2009:11:15:52 +0200 200 GET /content/campaigns/geometrixx.teasers..html text/htm
1883ms 31/Mar/2009:11:15:20 +0200 200 GET /libs/security/cq-security.js application/x-javascript
1876ms 31/Mar/2009:11:15:20 +0200 200 GET /libs/tagging/widgets.js application/x-javascript
1869ms 31/Mar/2009:11:15:20 +0200 200 GET /libs/tagging/widgets/themes/default.js application/x-javascript
1729ms 30/Mar/2009:16:45:56 +0200 200 GET /libs/wcm/content/welcome.html text/html; charset=utf-8
1510ms 31/Mar/2009:11:15:34 +0200 200 GET /bin/wcm/contentfinder/asset/view.json/ content/dam?_dc=1238490934657&query=&mimeType=image&_charset_=utf-8 application/json
1462ms 30/Mar/2009:17:23:08 +0200 200 GET /libs/wcm/content/welcome.html text