qpid-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From conflue...@apache.org
Subject [CONF] Apache Qpid > Java Broker Analysis Tools
Date Fri, 14 Aug 2009 13:20:00 GMT
<html>
<head>
    <base href="http://cwiki.apache.org/confluence">
            <link rel="stylesheet" href="/confluence/s/1519/1/1/_/styles/combined.css?spaceKey=qpid&amp;forWysiwyg=true"
type="text/css">
    </head>
<body style="background-color: white" bgcolor="white">
<div id="pageContent">
<div id="notificationFormat">
<div class="wiki-content">
<div class="email">
     <h2><a href="http://cwiki.apache.org/confluence/display/qpid/Java+Broker+Analysis+Tools">Java
Broker Analysis Tools</a></h2>
     <h4>Page <b>edited</b> by             <a href="http://cwiki.apache.org/confluence/display/~ritchiem">Martin
Ritchie</a>
    </h4>
     
          <br/>
     <div class="notificationGreySide">
         <h2><a name="JavaBrokerAnalysisTools-AnalysisTools"></a>Analysis
Tools</h2>

<p>This page contains details of the broker analysis tools available as part of the
<a href="/confluence/pages/createpage.action?spaceKey=qpid&amp;title=Java+Performance+Tools&amp;linkCreation=true&amp;fromPageId=120979"
class="createlink">Performance Test</a> package. The design for this work is located
<a href="/confluence/display/qpid/Testing+Design+-+Java+Broker+CPU+GC+Monitoring" title="Testing
Design - Java Broker CPU GC Monitoring">here</a>. </p>


<div>
<ul>
    <li><a href='#JavaBrokerAnalysisTools-Overview'>Overview</a></li>
    <li><a href='#JavaBrokerAnalysisTools-Monitoring'>Monitoring</a></li>
<ul>
    <li><a href='#JavaBrokerAnalysisTools-GC%2FHeapUsage'>GC / Heap Usage</a></li>
    <li><a href='#JavaBrokerAnalysisTools-CPUUsage'>CPU Usage</a></li>
    <li><a href='#JavaBrokerAnalysisTools-Scripting'>Scripting</a></li>
</ul>
    <li><a href='#JavaBrokerAnalysisTools-Processing'>Processing</a></li>
    <li><a href='#JavaBrokerAnalysisTools-processTests.py'>processTests.py</a></li>
    <li><a href='#JavaBrokerAnalysisTools-processAll.sh'>processAll.sh</a></li>
    <li><a href='#JavaBrokerAnalysisTools-process.sh'>process.sh</a></li>
</ul></div>

<h3><a name="JavaBrokerAnalysisTools-Overview"></a>Overview</h3>

<p>To better understand the performance of the Java broker this collection of tools
have been gathered to perform analysis on a variety of logging that the broker can produce.
Looking solely at the throughput values from our performance suite is not sufficient to tell
us that the broker's performance has increased. </p>

<p>Currently it the scripts monitor:</p>
<ul>
	<li>Heap Usage via verbose GC logging</li>
	<li>GC Duration via verbose GC logging</li>
	<li>CPU Usage via batch mode top</li>
</ul>


<p>Additional logging can be added to gather data as required. The processing of the
resulting log files from the broker run can then processed and using <a href="http://www.gnuplot.info"
rel="nofollow">GnuPlot</a> graphs of the data are generated.</p>

<h3><a name="JavaBrokerAnalysisTools-Monitoring"></a>Monitoring</h3>

<p>To better understand how the broker is performing there are some easy things we can
start monitoring.</p>
<ul>
	<li>Verbose GC/Heap Usage</li>
	<li>CPU Usage</li>
</ul>


<h4><a name="JavaBrokerAnalysisTools-GC%2FHeapUsage"></a>GC / Heap Usage</h4>

<p>Enabling verbose gc will allow the broker to provide us with a log file that details
GC operation. SO we can get a better handle on the impact of GC on the performance of the
broker. Enabling is done by providing a few additional values via QPID_OPTS:</p>
<div class="preformatted panel" style="border-width: 1px;"><div class="preformattedContent
panelContent">
<pre>-Xloggc:&lt;gc log file&gt; -verbose:gc -XX:+PrintGCDetails -XX:+PrintGCTimeStamps
</pre>
</div></div>

<p>This will result in a gc log file that shows all GCs performed. Of inititial interest
is the extraction of:</p>
<ul>
	<li>Heap Usage ( Max Allocated, Pre/Post GC Usage)</li>
	<li>GC Count (Incremental, Full)</li>
	<li>GC Duration (Incremental, Full, Total)<br/>
Testing+Design+-+Java+Broker+CPU+GC+Monitoring<br/>
As we gather this information a better internal view of the broker in opperation can be built.
When changes are made to the broker this data should allow us to determine how the changes
have affected the GC and memory profile. </li>
</ul>


<h4><a name="JavaBrokerAnalysisTools-CPUUsage"></a>CPU Usage</h4>

<p>In addition to the GC and Memory profiling available via the verbose gc settings
monitoring the CPU usage via top is a quick and easy way to view the cpu utilisation of the
broker.</p>

<p>Using the following top command we can monitor a give broker and adjust the time
interval in which we record the CPU usage.</p>
<div class="preformatted panel" style="border-width: 1px;"><div class="preformattedContent
panelContent">
<pre>$ top -d $monitor_rate -S -c -p $broker_pid -b &gt; broker_cpu.log
</pre>
</div></div>


<h4><a name="JavaBrokerAnalysisTools-Scripting"></a>Scripting</h4>

<p>To make life easier and to allow for future automated testing the following monitoring
scripts have been added to the 'perftest' package:</p>
<ul>
	<li>monitor-broker.sh</li>
	<li>stop-monitored-broker.sh</li>
</ul>


<h5><a name="JavaBrokerAnalysisTools-monitorbroker.sh"></a>monitor-broker.sh</h5>

<p>The monitor-broker.sh script current starts the following processes:</p>
<ul class="alternate" type="square">
	<li>The broker with additional QPID_OPTS for gc logging</li>
	<li>Top to monitoring the CPU usage</li>
</ul>


<p>To run this script a number of parameters are requried:</p>
<div class="preformatted panel" style="border-width: 1px;"><div class="preformattedContent
panelContent">
<pre>Usage ./monitor-broker.sh &lt;Path to Test Broker&gt; &lt;LOG DIR&gt;
&lt;CPU Monitor Rate (s)&gt; [Additional options to
  pass to Qpid broker startup]
</pre>
</div></div>

<p>The first parameter is the path to a qpid-broker package, or at least a directory
that contains an executable broker.<br/>
The &lt;LOG DIR&gt; is a path that <em>must not exist</em> (this is checked)
for all the log files to be collected for this monitored startup process. The verbose gc,
broker log, std out/err and PID files will be written to this directory.<br/>
The rate at which top will run to monitor this broker is the third value, any value here that
is valid for top's '-d' parameter is valid here. <br/>
Finally the remainder of the command line is passed directly to the qpid-server start up so
additional log configuration or configuration can be provided here. NOTE: if providing custom
log4j setup please ensure that the log file is written to QPID_WORK as this is set to the
&lt;LOG DIR&gt; value. This will ensure that all the log files for the testing run
are located in a single directory for easy later processing.</p>

<p>The pids of the broker and top are written to a *.pid file in the LOG_DIR. These
are also used by the stop-monitored-broker.sh<br/>
  script to ensure clean shutdown. </p>

<p>If additional processes are desired to be run if they write a PID into LOG_DIR/*.pid
then they will be shutdown with the stop script.</p>

<h5><a name="JavaBrokerAnalysisTools-stopmonitoredbroker.sh"></a>stop-monitored-broker.sh</h5>

<p>This is a simple script that takes the &lt;LOG DIR&gt; as its only parameter.</p>

<p>It then looks in this directory for all '.pid' files and uses their contained pid
value to execute a 'kill' command.</p>

<p>If all processes have not stopped within 3 seconds then a 'kill -9' is executed.</p>


<h5><a name="JavaBrokerAnalysisTools-runTests.sh"></a>runTests.sh</h5>

<p>The final script in the monitoring package currently is 'runTest.sh' this simplifies
the execution of a suite of tests.</p>

<p>The script takes three parameters:</p>
<div class="preformatted panel" style="border-width: 1px;"><div class="preformattedContent
panelContent">
<pre>Usage ./runTests.sh &lt;Path to Test Pack&gt; &lt;LOG DIR&gt; &lt;TEST
LIST FILE&gt;
</pre>
</div></div>

<p>As with the monitor-broker.sh the first parameter is the path to the qpid-test package
that can be build using the <a href="/confluence/display/qpid/Build+Creator" title="Build
Creator">Build Creator</a>. The test simply looks for a path that has a bin which
will be used to execute your test lists.</p>

<p>The LOG_DIR path again is requied <em>not to exist</em> on startup to
ensure we have a clean result set. The results of each test run are instructed to be written
here by adding '-o &lt;LOG_DIR&gt; --csv' to the executed test.</p>

<p>Finally the 'Test List File' is a plain text file containing a single command per
line to execute. The entries here should at least respond to the '-o' parameter to ensure
that their output is collected in the LOG_DIR.</p>

<p>An example test file might contain something link:</p>
<div class="preformatted panel" style="border-width: 1px;"><div class="preformattedContent
panelContent">
<pre>TQBT-AA-Qpid-01.sh -d10M
TTBT-AA-Qpid-01.sh -d10M
</pre>
</div></div>

<p>The two test scripts are assumed to exist in thee &lt;path to test pack&gt;/bin
directory. </p>

<p><b>Monitoring</b><br/>
If you want to check the tests are running the standard out of the individual tests is redirected
to &lt;log dir&gt;/TestRun.log</p>

<h3><a name="JavaBrokerAnalysisTools-Processing"></a>Processing</h3>

<p>Monitoring is only the first stage to gather the data. It is the collection of processing
tools that are responsible for turing the raw data into something more human understandable.</p>

<p>There are three scripts here that perform take the raw data from the monitoring phase
and turn that in to three graphs such as these examples that were made during the design of
these scripts:<br/>
<a class="confluence-thumbnail-link 640x480" href='http://cwiki.apache.org/confluence/download/attachments/118853/0.5-queue-12b-0r-CPU.png'><img
src="/confluence/download/thumbnails/118853/0.5-queue-12b-0r-CPU.png" align="absmiddle" border="0"
/></a><a class="confluence-thumbnail-link 640x480" href='http://cwiki.apache.org/confluence/download/attachments/118853/0.5-queue-12b-0r-GCDuration.png'><img
src="/confluence/download/thumbnails/118853/0.5-queue-12b-0r-GCDuration.png" align="absmiddle"
border="0" /></a><a class="confluence-thumbnail-link 640x480" href='http://cwiki.apache.org/confluence/download/attachments/118853/0.5-queue-12b-0r-Heap.png'><img
src="/confluence/download/thumbnails/118853/0.5-queue-12b-0r-Heap.png" align="absmiddle" border="0"
/></a></p>

<p>The three scripts are:</p>
<ul>
	<li>processTests.py</li>
	<li>processAll.sh</li>
	<li>process.sh</li>
</ul>


<h3><a name="JavaBrokerAnalysisTools-processTests.py"></a>processTests.py</h3>

<p>This is the first script written in python that takes the raw output from the monitoring
stage and generates test packs.</p>

<p>The script has two parameters the two output directories (broker and test) from the
monitoring phase:</p>
<div class="preformatted panel" style="border-width: 1px;"><div class="preformattedContent
panelContent">
<pre>Usage: processTests.py [-b|--broker-log-dir] &lt;dir&gt; [-t|--test-dir]
&lt;dir&gt;
</pre>
</div></div>

<p>The tool currently looks for all the *.csv file the individual tests have generated
and uses the gathered metadata to create a slice of each of the broker log files (gc, logging,
cpu). In addition the script will gather details about the test run and broker used to form
the title and filename for the graph.</p>

<h3><a name="JavaBrokerAnalysisTools-processAll.sh"></a>processAll.sh</h3>
<p>The processAll.sh script searches for 'graph.data' files and then runs the process.sh
script on each of them to generate the graphs for that data.<br/>
The script takes a single argument, a directory to start searching in.</p>
<div class="preformatted panel" style="border-width: 1px;"><div class="preformattedContent
panelContent">
<pre>processAll.sh &lt;search dir&gt;
</pre>
</div></div>

<p>The graph images are then copied to a 'results' directory that is created in the
current working directory.</p>


<h3><a name="JavaBrokerAnalysisTools-process.sh"></a>process.sh</h3>

<p>This is the main processing script for the collected data. It has been updated to
work in conjuction with the processTests.py script. Further development of this script should
be performed to allow the explicit naming of the various log file and parameter inputs that
this uses.</p>

<p>This script is currently expected to be called from processAll.sh and as a result
takes a single arguement a graph.data file.</p>

<p>This graph.data file contains two text lines. The first is the title to give the
graph, the second is the name of the file.<br/>
This is an example file of the automatic output from the processTests.py:</p>
<div class="preformatted panel" style="border-width: 1px;"><div class="preformattedContent
panelContent">
<pre>0.5:TQBT-AA-Qpid-01:256kb x 962 msg/sec using AutoAck
0.5-TQBT-AA-Qpid-01-2009-06-19-17.04.25-timings
</pre>
</div></div>

<p>In generic terms it creates the following graph.data file:</p>
<div class="preformatted panel" style="border-width: 1px;"><div class="preformattedContent
panelContent">
<pre>&lt;broker version&gt;:&lt;test name&gt;:&lt;messageSize&gt;kb
x &lt;test volume as measured&gt; msg/sec using &lt;ackMode of test&gt;
&lt;broker version&gt;-&lt;test name&gt;
</pre>
</div></div>

<p>The process.sh script produces three graphs:</p>
<ul>
	<li>GC Heap Usage</li>
	<li>GC Duration</li>
	<li>CPU Utilisation</li>
</ul>


<p><b>NOTE</b> <a href="http://www.gnuplot.info" rel="nofollow">GnuPlot</a>
is used to generate the graphs.</p>

<p>To generated these graphs it does a lot of data manipulation and extraction on the
gc log file. Currently the script will process a ConcurrentMark and Sweep gc log file and
the format used by the new G1 collector. The processing of these files extracts the recorded
time for each gc and the instant count of minor and full GCs. This information is graphed
on the GC Duration graph.</p>

<p>The GC log file also highlights the Allocated Heap, Pre and Post GC heap sizes. This
is the data that is then graphed in the GC Heap Size graph.</p>

<p>The final graph, CPU Utilisation' is generated from the cpu data gathered using top.
Here the script has been updated to work with the data output from processTests.py where the
broker_cpu.log file contains a list of time-stamped entries. This is then used to show time
on the x-axis. </p>

<p>This improvement is also due  be applied to the other two graphs. In addition to
standardising the x-axis the y-axis scale for a given batch of tests, as processed by processAll.sh,
will be standardised allow for easy image comparison.</p>

     </div>
     <div id="commentsSection" class="wiki-content pageSection">
       <div style="float: right;">
            <a href="http://cwiki.apache.org/confluence/users/viewnotifications.action"
class="grey">Change Notification Preferences</a>
       </div>

       <a href="http://cwiki.apache.org/confluence/display/qpid/Java+Broker+Analysis+Tools">View
Online</a>
       |
       <a href="http://cwiki.apache.org/confluence/pages/diffpagesbyversion.action?pageId=120979&revisedVersion=7&originalVersion=6">View
Change</a>
              |
       <a href="http://cwiki.apache.org/confluence/display/qpid/Java+Broker+Analysis+Tools?showComments=true&amp;showCommentArea=true#addcomment">Add
Comment</a>
            </div>
</div>
</div>
</div>
</div>
</body>
</html>

---------------------------------------------------------------------
Apache Qpid - AMQP Messaging Implementation
Project:      http://qpid.apache.org
Use/Interact: mailto:commits-subscribe@qpid.apache.org


Mime
View raw message