<html xmlns:v="urn:schemas-microsoft-com:vml" xmlns:o="urn:schemas-microsoft-com:office:office" xmlns:w="urn:schemas-microsoft-com:office:word" xmlns:m="http://schemas.microsoft.com/office/2004/12/omml" xmlns="http://www.w3.org/TR/REC-html40">
<head>
<meta http-equiv="Content-Type" content="text/html; charset=iso-8859-1">
<meta name="Generator" content="Microsoft Word 14 (filtered medium)">
<style><!--
/* Font Definitions */
@font-face
{font-family:Calibri;
panose-1:2 15 5 2 2 2 4 3 2 4;}
@font-face
{font-family:Tahoma;
panose-1:2 11 6 4 3 5 4 4 2 4;}
@font-face
{font-family:Consolas;
panose-1:2 11 6 9 2 2 4 3 2 4;}
/* Style Definitions */
p.MsoNormal, li.MsoNormal, div.MsoNormal
{margin:0in;
margin-bottom:.0001pt;
font-size:12.0pt;
font-family:"Times New Roman","serif";}
a:link, span.MsoHyperlink
{mso-style-priority:99;
color:blue;
text-decoration:underline;}
a:visited, span.MsoHyperlinkFollowed
{mso-style-priority:99;
color:purple;
text-decoration:underline;}
pre
{mso-style-priority:99;
mso-style-link:"HTML Preformatted Char";
margin:0in;
margin-bottom:.0001pt;
font-size:10.0pt;
font-family:"Courier New";}
span.HTMLPreformattedChar
{mso-style-name:"HTML Preformatted Char";
mso-style-priority:99;
mso-style-link:"HTML Preformatted";
font-family:Consolas;}
span.EmailStyle19
{mso-style-type:personal-reply;
font-family:"Calibri","sans-serif";
color:#1F497D;}
.MsoChpDefault
{mso-style-type:export-only;
font-family:"Calibri","sans-serif";}
@page WordSection1
{size:8.5in 11.0in;
margin:1.0in 1.0in 1.0in 1.0in;}
div.WordSection1
{page:WordSection1;}
--></style><!--[if gte mso 9]><xml>
<o:shapedefaults v:ext="edit" spidmax="1026" />
</xml><![endif]--><!--[if gte mso 9]><xml>
<o:shapelayout v:ext="edit">
<o:idmap v:ext="edit" data="1" />
</o:shapelayout></xml><![endif]-->
</head>
<body lang="EN-US" link="blue" vlink="purple">
<div class="WordSection1">
<p class="MsoNormal"><span style="font-size:11.0pt;font-family:"Calibri","sans-serif";color:#1F497D">Hi Nadya,<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-size:11.0pt;font-family:"Calibri","sans-serif";color:#1F497D"><o:p> </o:p></span></p>
<p class="MsoNormal"><span style="font-size:11.0pt;font-family:"Calibri","sans-serif";color:#1F497D">You mentioned multiple DB backends in your mail. Which one did you use to perform these tests or did you get the same/similar performance results in case of
both?<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-size:11.0pt;font-family:"Calibri","sans-serif";color:#1F497D"><o:p> </o:p></span></p>
<p class="MsoNormal"><span style="font-size:11.0pt;font-family:"Calibri","sans-serif";color:#1F497D">Best Regards,<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-size:11.0pt;font-family:"Calibri","sans-serif";color:#1F497D">Ildiko<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-size:11.0pt;font-family:"Calibri","sans-serif";color:#1F497D"><o:p> </o:p></span></p>
<p class="MsoNormal"><b><span style="font-size:10.0pt;font-family:"Tahoma","sans-serif"">From:</span></b><span style="font-size:10.0pt;font-family:"Tahoma","sans-serif""> Nadya Privalova [mailto:nprivalova@mirantis.com]
<br>
<b>Sent:</b> Tuesday, March 11, 2014 6:05 PM<br>
<b>To:</b> OpenStack Development Mailing List<br>
<b>Subject:</b> [openstack-dev] [Ceilometer]Collector's performance<o:p></o:p></span></p>
<p class="MsoNormal"><o:p> </o:p></p>
<div>
<div>
<div>
<div>
<div>
<div>
<div>
<div>
<div>
<p class="MsoNormal" style="margin-bottom:12.0pt">Hi team!<o:p></o:p></p>
</div>
</div>
<p class="MsoNormal" style="margin-bottom:12.0pt">Last week we were working on notification problem in ceilometer during tempest tests creation. Tests for notification passed successfully on Postgres but failed on MySQL. This made us start investigations and
this email contains some results. <o:p></o:p></p>
</div>
<p class="MsoNormal">As it turned out, tempest as it is is something like performance-testing for Ceilometer. It contains 2057 tests. Almost in all test OpenStack resources are being created and deleted: images, instances, volumes. E.g. during instance creation
nova sends 9 notifications. And all the tests are running in parallel for about 40 minutes.
<o:p></o:p></p>
</div>
<p class="MsoNormal">From ceilometer-collector logs we may found very useful message:
<o:p></o:p></p>
<pre><span style="font-size:13.5pt"><a href="http://logs.openstack.org/36/64136/20/check/check-tempest-dsvm-full/e361520/logs/screen-ceilometer-collector.txt.gz#_2014-03-10_09_42_41_356" target="_blank">2014-03-10 09:42:41.356</a> 22845 DEBUG ceilometer.dispatcher.database [req-16ea95c5-6454-407a-9c64-94d5ef900c9e - - - - -] metering data storage.objects.outgoing.bytes for b7a490322e65422cb1129b13b49020e6 @ 2014-03-10T09:34:31.090107: </span><o:p></o:p></pre>
<p class="MsoNormal">So collector starts to process_metering_data in dispatcher only in 9:42 but nova sent it in 9:34. To look at whole picture please take look at picture [1]. It illustrates time difference based on this message in logs.
<o:p></o:p></p>
</div>
<p class="MsoNormal">Besides, I decided to take a look on difference between the RPC-publisher sends the message and the collector receives the message. To create this plot I've parsed the lines like below from anotifications log:<o:p></o:p></p>
</div>
<p class="MsoNormal"><o:p> </o:p></p>
<pre><a name="144b1ef6f6d7eb33_144b1c6a5bf5963f__2014-"></a><a href="http://logs.openstack.org/36/64136/20/check/check-tempest-dsvm-full/e361520/logs/screen-ceilometer-anotification.txt.gz#_2014-03-10_09_25_49_333" target="_blank"><span style="font-size:13.5pt">2014-03-10 09:25:49.333</span></a><span style="font-size:13.5pt"> 22833 DEBUG ceilometer.openstack.common.rpc.amqp [-] UNIQUE_ID is <span style="background:#B6D7A8">683dd3f130534b9fbb5606aef862b83d</span>.<br><br><o:p></o:p></span></pre>
<pre><span style="font-size:13.5pt"><o:p> </o:p></span></pre>
<pre><o:p> </o:p></pre>
</div>
<p class="MsoNormal">After that I found the corresponding id in collector log:<o:p></o:p></p>
<pre><a name="144b1ef6f6d7eb33__2014-03-10_09_25_49_35"></a><a href="http://logs.openstack.org/36/64136/20/check/check-tempest-dsvm-full/e361520/logs/screen-ceilometer-collector.txt.gz#_2014-03-10_09_25_49_352" target="_blank"><span style="font-size:13.5pt">2014-03-10 09:25:49.352</span></a><span style="font-size:13.5pt"> 22845 DEBUG ceilometer.openstack.common.rpc.amqp [-] received {u'_context_domain': None, u'_context_request_id': u'req-0a5fafe6-e097-4f90-a68a-a91da1cff22c', <br><br><o:p></o:p></span></pre>
<pre><span style="font-size:13.5pt"><o:p> </o:p></span></pre>
<pre><span style="font-size:13.5pt">u'args': {u'data': [...,<br> u'message_id': u'f7ad63fc-a835-11e3-8223-bc764e205385', u'counter_type': u'gauge'}]}, u'_context_read_only': False, u'_unique_id': u'<span style="background:#B6D7A8">683dd3f130534b9fbb5606aef862b83d</span>', <br><br><o:p></o:p></span></pre>
<pre><span style="font-size:13.5pt"><o:p> </o:p></span></pre>
<pre><span style="font-size:13.5pt">u'_context_user_identity': u'- - - - -', u'_context_instance_uuid': None, u'_context_show_deleted': False, u'_context_tenant': None, u'_context_auth_token': '<SANITIZED>', <br><br><o:p></o:p></span></pre>
<pre><span style="font-size:13.5pt"><o:p> </o:p></span></pre>
<pre style="margin-bottom:12.0pt"><span style="font-size:13.5pt">....} _safe_log /opt/stack/new/ceilometer/ceilometer/openstack/common/rpc/common.py:280</span><o:p></o:p></pre>
<p class="MsoNormal" style="margin-bottom:12.0pt">So in the example above we see time-difference only in 20 milliseconds. But it grows very quickly :( To see it please take a look on picture [2].
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal">To summarize pictures:<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal">1. Picture 1: Axis Y: amount of seconds between nova creates notification and the collector retrieves the message. Axis X: timestamp
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-bottom:12.0pt">2. Picture 2: Axis Y: amount of seconds between the publisher publishes the message and the collector retrieves the message. Axis X: timestamp<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal">These pictures are almost the same and it makes me think that collector cannot manage with big amount of messages. What do you think about it? Do you agree or you need more evidences, e.g. amount of messages in rabbit or amth else?<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal">Let's discuss that in [Ceilometer] topic first, I will create a new thread about testing strategy in tempest later. Because in this circumstances we forced to refuse from created notification tests and cannot reduce time for polling because
it will make everything even worst.<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal">[1]: <a href="http://postimg.org/image/r4501bdyb/" target="_blank">
http://postimg.org/image/r4501bdyb/</a><br>
[2]: <a href="http://postimg.org/image/yy5a1ste1/" target="_blank">http://postimg.org/image/yy5a1ste1/</a><o:p></o:p></p>
</div>
<div>
<p class="MsoNormal"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal">Thanks for your attention,<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal">Nadya<o:p></o:p></p>
</div>
</div>
</div>
</body>
</html>