<html 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=utf-8">
<meta name="Title" content="">
<meta name="Keywords" content="">
<meta name="Generator" content="Microsoft Word 15 (filtered medium)">
<style><!--
/* Font Definitions */
@font-face
{font-family:"Cambria Math";
panose-1:2 4 5 3 5 4 6 3 2 4;}
@font-face
{font-family:Calibri;
panose-1:2 15 5 2 2 2 4 3 2 4;}
/* Style Definitions */
p.MsoNormal, li.MsoNormal, div.MsoNormal
{margin:0in;
margin-bottom:.0001pt;
font-size:11.0pt;
font-family:"Calibri",sans-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;}
span.EmailStyle17
{mso-style-type:personal-reply;
font-family:"Calibri",sans-serif;
color:windowtext;
font-weight:normal;
font-style:normal;
text-decoration:none none;}
span.msoIns
{mso-style-type:export-only;
mso-style-name:"";
text-decoration:underline;
color:teal;}
.MsoChpDefault
{mso-style-type:export-only;
font-size:10.0pt;}
@page WordSection1
{size:8.5in 11.0in;
margin:1.0in 1.0in 1.0in 1.0in;}
div.WordSection1
{page:WordSection1;}
--></style>
</head>
<body bgcolor="white" lang="EN-US" link="blue" vlink="purple">
<div class="WordSection1">
<p class="MsoNormal"><span style="font-size:12.0pt"><o:p> </o:p></span></p>
<p class="MsoNormal"><span style="font-size:12.0pt">Matt,<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-size:12.0pt"><o:p> </o:p></span></p>
<p class="MsoNormal"><span style="font-size:12.0pt">Thanks for clarifying the logs, the older release I was using did not have much information in the scheduler log. I’ll double check on the Newton release to see how they look like.<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-size:12.0pt">As you mention, a simple pass/fail result may not always explain why it fails but it is definitely good to know which filter failed.<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-size:12.0pt">I still think that a VM failure to launch should be related to 1 ERROR log rather than 1 INFO log. In the example you provide, it is fine to have race conditions that result in a rejection and an ERROR log.<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-size:12.0pt"><o:p> </o:p></span></p>
<p class="MsoNormal"><span style="font-size:12.0pt">The main problem is that the nova API does not return sufficient detail on the reason for a NoValidHostFound and perhaps that should be fixed at that level. Extending the API to return a reason field which
is a json dict that is returned by the various filters (with more meaningful filter-specific info) will help tremendously (no more need to go through the log to find out why).<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-size:12.0pt"><o:p> </o:p></span></p>
<p class="MsoNormal"><span style="font-size:12.0pt">Regards,<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-size:12.0pt"><o:p> </o:p></span></p>
<p class="MsoNormal"><span style="font-size:12.0pt"> Alec<o:p></o:p></span></p>
<p class="MsoNormal"><span style="font-size:12.0pt"><o:p> </o:p></span></p>
<p class="MsoNormal"><span style="font-size:12.0pt"><o:p> </o:p></span></p>
<p class="MsoNormal"><span style="font-size:12.0pt"><o:p> </o:p></span></p>
<div style="border:none;border-top:solid #B5C4DF 1.0pt;padding:3.0pt 0in 0in 0in">
<p class="MsoNormal" style="margin-left:.5in"><b><span style="font-size:12.0pt;color:black">From:
</span></b><span style="font-size:12.0pt;color:black">Matt Riedemann <mriedemos@gmail.com><br>
<b>Date: </b>Wednesday, January 10, 2018 at 11:33 AM<br>
<b>To: </b>"openstack-operators@lists.openstack.org" <openstack-operators@lists.openstack.org><br>
<b>Subject: </b>Re: [Openstack-operators] [openstack-operators][nova] Verbosity of nova scheduler<o:p></o:p></span></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">On 1/10/2018 1:15 AM, Alec Hothan (ahothan) wrote:<o:p></o:p></p>
</div>
<blockquote style="border:none;border-left:solid #B5C4DF 4.5pt;padding:0in 0in 0in 4.0pt;margin-left:3.75pt;margin-right:0in" id="MAC_OUTLOOK_ATTRIBUTION_BLOCKQUOTE">
<div>
<p class="MsoNormal" style="margin-left:.5in">+1 on the “no valid host found”, this one should be at the very top of
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">the to-be-fixed list.<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">Very difficult to troubleshoot filters in lab testing (let alone in
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">production) as there can be many of them. This will get worst with more
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">NFV optimization filters with so many combinations it gets really
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">complex to debug when a VM cannot be launched with NFV optimized
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">flavors. With the scheduler filtering engine, there should be a
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">systematic way to log the reason for not finding a valid host - at the
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">very least the error should display which filter failed as an ERROR (and
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">not as DEBUG).<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">We really need to avoid deploying with DEBUG log level but unfortunately
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">this is the only way to troubleshoot. Too many debug-level logs are for
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">development debug (meaning pretty much useless in any circumstances –
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">developer forgot to remove before commit of the feature), many errors
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">that should be logged as ERROR but have been logged as DEBUG only.<o:p></o:p></p>
</div>
</blockquote>
<div>
<p class="MsoNormal" style="margin-left:.5in"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">The scheduler logs do print which filter returned 0 hosts for a given
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">request at INFO level.<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">For example, I was debugging this NoValidHost failure in a CI run:<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in"><a href="http://logs.openstack.org/20/531020/3/check/tempest-full/1287dde/job-output.txt.gz#_2018-01-05_17_39_54_336999">http://logs.openstack.org/20/531020/3/check/tempest-full/1287dde/job-output.txt.gz#_2018-01-05_17_39_54_336999</a><o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">And tracing the request ID to the scheduler logs, and filtering on just
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">INFO level logging to simulate what you'd have for the default in
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">production, I found the filter that kicked it out here:<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in"><a href="http://logs.openstack.org/20/531020/3/check/tempest-full/1287dde/controller/logs/screen-n-sch.txt.gz?level=INFO#_Jan_05_17_00_30_564582">http://logs.openstack.org/20/531020/3/check/tempest-full/1287dde/controller/logs/screen-n-sch.txt.gz?level=INFO#_Jan_05_17_00_30_564582</a><o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">And there is a summary like this:<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">Jan 05 17:00:30.565996 ubuntu-xenial-infracloud-chocolate-0001705073
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">nova-scheduler[8932]: INFO nova.filters [None
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">req-737984ae-3ae8-4506-a5f9-6655a4ebf206
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">tempest-ServersAdminTestJSON-787960229
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">tempest-ServersAdminTestJSON-787960229] Filtering removed all hosts for
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">the request with instance ID '8ae8dc23-8f3b-4f0f-8775-2dcc2a5fc75b'.
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">Filter results: ['RetryFilter: (start: 1, end: 1)',
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">'AvailabilityZoneFilter: (start: 1, end: 1)', 'ComputeFilter: (start: 1,
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">end: 1)', 'ComputeCapabilitiesFilter: (start: 1, end: 1)',
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">'ImagePropertiesFilter: (start: 1, end: 1)',
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">'ServerGroupAntiAffinityFilter: (start: 1, end: 1)',
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">'ServerGroupAffinityFilter: (start: 1, end: 1)', 'SameHostFilter:
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">(start: 1, end: 0)']<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">"end: 0" means that's the filter that rejected the request. Without
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">digging into the actual code, the descriptions for the filters is here:<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in"><a href="https://docs.openstack.org/nova/latest/user/filter-scheduler.html">https://docs.openstack.org/nova/latest/user/filter-scheduler.html</a><o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">Now just why this request failed requires a bit of understanding of why
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">my environment looks like (this CI run is using the CachingScheduler),
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">so there isn't a simple "ERROR: SameHostFilter rejected request because
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">you're using the CachingScheduler which is racy by design and you
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">created the instances in separate requests". You'd have a ton of false
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">negative ERRORs in the logs because of valid reasons for rejected a
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">request based on the current state of the system, which is going to make
<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">debugging real issues that much harder.<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">-- <o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">Thanks,<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">Matt<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">_______________________________________________<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in">OpenStack-operators mailing list<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in"><a href="mailto:OpenStack-operators@lists.openstack.org">OpenStack-operators@lists.openstack.org</a><o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in"><a href="http://lists.openstack.org/cgi-bin/mailman/listinfo/openstack-operators">http://lists.openstack.org/cgi-bin/mailman/listinfo/openstack-operators</a><o:p></o:p></p>
</div>
<div>
<p class="MsoNormal" style="margin-left:.5in"><o:p> </o:p></p>
</div>
</div>
</body>
</html>