<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=utf-8">
<meta name="Generator" content="Microsoft Word 12 (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;}
@font-face
{font-family:Tahoma;
panose-1:2 11 6 4 3 5 4 4 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;}
span.EmailStyle17
{mso-style-type:personal-reply;
font-family:"Calibri","sans-serif";
color:#1F497D;}
.MsoChpDefault
{mso-style-type:export-only;}
@page Section1
{size:8.5in 11.0in;
margin:1.0in 1.0in 1.0in 1.0in;}
div.Section1
{page:Section1;}
-->
</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="Section1">
<p class="MsoNormal"><span style="font-size:11.0pt;font-family:"Calibri","sans-serif";
color:#1F497D">Thanks both Armando and Matt!<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">I am cross posting this to the operators' list (as the main post -- operators, simple reply and no spam to dev).<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">The logging tag should be a tag in all projects. I'm glad it's already there in Neutron. And, this sort of feedback is exactly what we need operators and
gate debuggers to provide when they hit stuff in the logs that is either classified at the wrong level (e.g., warning instead of info), is too verbose, generates a traceback rather than an error, or is too chatty, happens too often.<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">Please file these bugs to the appropriate projects and tag them "logging". Generally, these are easy fixes, or are "while you're in there" fixes while a
bug is being addressed, so reporting them will most often get them fixed quickly. I know that doesn't help the Ops folks as much as the developers, but it will help the developers when they upgrade to releases the logging has been fixed in.<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">These sorts of issues are major maintainability issues for operators, so a focus on this for the Mitaka release will help make it a release operators want
to upgrade to :-)<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">Thanks for the ear and for the help with debugging OpenStack issues by improving the signal to noise ratio.<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">--Rocky<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>
<div style="border:none;border-left:solid blue 1.5pt;padding:0in 0in 0in 4.0pt">
<div>
<div style="border:none;border-top:solid #B5C4DF 1.0pt;padding:3.0pt 0in 0in 0in">
<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""> Armando M. [mailto:armamig@gmail.com]
<br>
<b>Sent:</b> Tuesday, November 10, 2015 11:39 AM<br>
<b>To:</b> OpenStack Development Mailing List (not for usage questions)<br>
<b>Subject:</b> Re: [openstack-dev] Can we get some sanity in the Neutron logs please?<o:p></o:p></span></p>
</div>
</div>
<p class="MsoNormal"><o:p> </o:p></p>
<div>
<p class="MsoNormal"><o:p> </o:p></p>
<div>
<p class="MsoNormal"><o:p> </o:p></p>
<div>
<p class="MsoNormal">On 10 November 2015 at 11:12, Matt Riedemann <<a href="mailto:mriedem@linux.vnet.ibm.com" target="_blank">mriedem@linux.vnet.ibm.com</a>> wrote:<o:p></o:p></p>
<div>
<div>
<p class="MsoNormal"><br>
<br>
On 11/10/2015 1:10 PM, Matt Riedemann wrote:<o:p></o:p></p>
<p class="MsoNormal"><br>
<br>
On 11/10/2015 12:51 PM, Armando M. wrote:<o:p></o:p></p>
<p class="MsoNormal"><br>
<br>
On 10 November 2015 at 10:33, Matt Riedemann <<a href="mailto:mriedem@linux.vnet.ibm.com" target="_blank">mriedem@linux.vnet.ibm.com</a><br>
<mailto:<a href="mailto:mriedem@linux.vnet.ibm.com" target="_blank">mriedem@linux.vnet.ibm.com</a>>> wrote:<br>
<br>
Let me qualify by saying I'm not a Neutron person.<br>
<br>
We know that gate-tempest-dsvm-neutron-full is failing hard as of<br>
the last 24 hours [1].<br>
<br>
An error that's been showing up in tempest runs with neutron a lot<br>
is:<br>
<br>
"AssertionError: 0 == 0 : No IPv4 addresses found in: []"<br>
<br>
So checking logstash [2] it's hitting a lot. It's only recent<br>
because that failure message is new to Tempest in the last day or<br>
so, but it has a lot of hits, so whatever it is, it's failing a lot.<br>
<br>
So the next step is usually digging into service logs looking for<br>
errors. I check the q-svc logs first. Not many errors but a<br>
bazillion warnings for things not found (networks and devices). [3]<br>
<br>
For example:<br>
<br>
2015-11-10 17:13:02.542 WARNING neutron.plugins.ml2.rpc<br>
[req-15a73753-1512-4689-9404-9658a0cd0c09 None None] Device<br>
aaa525be-14eb-44a5-beb0-ed722896be93 requested by agent<br>
ovs-agent-devstack-trusty-rax-iad-5785199 not found in database<br>
<br>
2015-11-10 17:14:17.754 WARNING neutron.api.rpc.handlers.dhcp_rpc<br>
[req-3d7e9848-6151-4780-907f-43f11a2a8545 None None] Network<br>
b07ad9b2-e63e-4459-879d-3721074704e5 could not be found, it might<br>
have been deleted concurrently.<br>
<br>
Are several hundred of these warnings useful to an operator trying<br>
to debug a problem? The point of the CI gate testing is to try and<br>
simulate a production cloud environment. When something goes wrong,<br>
you check the logs. With the amount of warning/error level logging<br>
that is in the neutron logs, finding a real problem is like looking<br>
for a needle in a haystack. Since everything is async, 404s are<br>
expected when racing to delete a resource and they should be handled<br>
gracefully.<br>
<br>
Anyway, the server log isn't useful so I go digging in the agent<br>
logs and stacktraces there are aplenty. [4]<br>
<br>
Particularly this:<br>
<br>
"Exception: Port tapcea51630-e1 is not ready, resync needed"<br>
<br>
That's due to a new change landing in the last 24 hours [5]. But the<br>
trace shows up over 16K times since it landed [6].<br>
<br>
Checking the code, it's basically a loop processing events and when<br>
it hits an event it can't handle, it punts (breaking the loop so you<br>
don't process the other events after it - which is a bug), and the<br>
code that eventually handles it is just catching all Exception and<br>
tracing them out assuming they are really bad.<br>
<br>
At this point, as a non-neutron person, i.e. not well versed in the<br>
operations of neutron or how to debug it in great detail, I assume<br>
something is bad here but I don't really know - and the logs are so<br>
full of noise that I can't distinguish real failures.<br>
<br>
I don't mean to pick on this particular change, but it's a good<br>
example of a recent thing.<br>
<br>
I'd like to know if this is all known issue or WIP type stuff. I've<br>
complained about excessively noisey neutron logs in channel before<br>
and I'm usually told that they are either necessary (for whatever<br>
reason) or that rather than complain about the verbosity, I should<br>
fix the race that is causing it - which is not likely to happen<br>
since I don't have the async rpc happy nature of everything in<br>
neutron in my head to debug it (I doubt many do).<br>
<br>
<br>
I am not sure that's a fair statement: we usually pinpoint that just<br>
lowering log levels is not really solving the underlying issue<br>
(whichever it may be), and that comment really should apply to any<br>
project, not just Neutron. That said, we had examples where we took your<br>
input and drove the right fix ourselves.<br>
<br>
We have a 'logging' tag for Neutron bugs that we use to identify these<br>
type of cleanups. We'd need your attention to details to alert us of<br>
issues like these; we'll take care of the right fixes. Currently, the<br>
queue is pretty dry. If you can top it up, that'll be great. Going off<br>
on a log cleanup rampage doesn't seem like the best course of action;<br>
I'd rather knock issues one by one as they come, like the one you just<br>
mentioned.<br>
<br>
[1] <a href="https://bugs.launchpad.net/neutron/+bugs?field.tag=logging" target="_blank">
https://bugs.launchpad.net/neutron/+bugs?field.tag=logging</a><o:p></o:p></p>
<p class="MsoNormal"><br>
Tagged:<br>
<br>
<a href="https://bugs.launchpad.net/nova/+bug/1514935" target="_blank">https://bugs.launchpad.net/nova/+bug/1514935</a><br>
<br>
Although it must not be an official tag since it didn't auto-complete<br>
for me, that should be fixed.<o:p></o:p></p>
<p class="MsoNormal"><o:p> </o:p></p>
</div>
</div>
<p class="MsoNormal">Crap, nevermind that, my bad - I had created the bug against nova (force of habit) rather than neutron. Confirmed that 'logging' is a neutron tag in LP.<o:p></o:p></p>
<div>
<p class="MsoNormal"><o:p> </o:p></p>
</div>
<div>
<p class="MsoNormal">Ah, gotcha!<o:p></o:p></p>
</div>
<div>
<p class="MsoNormal"> <o:p></o:p></p>
</div>
<blockquote style="border:none;border-left:solid #CCCCCC 1.0pt;padding:0in 0in 0in 6.0pt;
margin-left:4.8pt;margin-right:0in">
<div>
<div>
<blockquote style="border:none;border-left:solid #CCCCCC 1.0pt;padding:0in 0in 0in 6.0pt;
margin-left:4.8pt;margin-right:0in">
<p class="MsoNormal" style="margin-bottom:12.0pt"><o:p> </o:p></p>
<blockquote style="border:none;border-left:solid #CCCCCC 1.0pt;padding:0in 0in 0in 6.0pt;
margin-left:4.8pt;margin-right:0in">
<p class="MsoNormal"><o:p> </o:p></p>
<p class="MsoNormal" style="margin-bottom:12.0pt"><br>
<br>
Anyway, this is a plea for sanity in the logs. There are logging<br>
guidelines for openstack [7]. Let's please abide by them. Let's keep<br>
operators in mind when we're looking at logs and be proactive about<br>
making them useful (which includes more granular error handling and<br>
less global try/except Exception: LOG.exception constructs).<br>
<br>
Your point is duly noted. We have documented this, and we are being more<br>
meticulous during reviews.<br>
<br>
<br>
[1] <a href="http://tinyurl.com/ne3ex4v" target="_blank">http://tinyurl.com/ne3ex4v</a><br>
[2]<br>
<br>
<a href="http://logstash.openstack.org/#dashboard/file/logstash.json?query=message:%5C%22AssertionError:%200%20==%200%20:%20No%20IPv4%20addresses%20found%20in:%20%5B%5D%5C%22%20AND%20tags:%5C%22console%5C%22" target="_blank">http://logstash.openstack.org/#dashboard/file/logstash.json?query=message:%5C%22AssertionError:%200%20==%200%20:%20No%20IPv4%20addresses%20found%20in:%20%5B%5D%5C%22%20AND%20tags:%5C%22console%5C%22</a><br>
<br>
[3]<br>
<br>
<a href="http://logs.openstack.org/85/239885/2/gate/gate-tempest-dsvm-neutron-full/602d864/logs/screen-q-svc.txt.gz?level=TRACE" target="_blank">http://logs.openstack.org/85/239885/2/gate/gate-tempest-dsvm-neutron-full/602d864/logs/screen-q-svc.txt.gz?level=TRACE</a><br>
<br>
[4]<br>
<br>
<a href="http://logs.openstack.org/85/239885/2/gate/gate-tempest-dsvm-neutron-full/602d864/logs/screen-q-agt.txt.gz?level=TRACE" target="_blank">http://logs.openstack.org/85/239885/2/gate/gate-tempest-dsvm-neutron-full/602d864/logs/screen-q-agt.txt.gz?level=TRACE</a><br>
<br>
[5] <a href="https://review.openstack.org/#/c/164880/" target="_blank">https://review.openstack.org/#/c/164880/</a><br>
[6]<br>
<br>
<a href="http://logstash.openstack.org/#dashboard/file/logstash.json?query=message:%5C%22Exception:%20Port%5C%22%20AND%20message:%5C%22is%20not%20ready,%20resync%20needed%5C%22%20AND%20tags:%5C%22screen-q-agt.txt%5C%22" target="_blank">http://logstash.openstack.org/#dashboard/file/logstash.json?query=message:%5C%22Exception:%20Port%5C%22%20AND%20message:%5C%22is%20not%20ready,%20resync%20needed%5C%22%20AND%20tags:%5C%22screen-q-agt.txt%5C%22</a><br>
<br>
[7]<br>
<br>
<a href="http://specs.openstack.org/openstack/openstack-specs/specs/log-guidelines.html" target="_blank">http://specs.openstack.org/openstack/openstack-specs/specs/log-guidelines.html</a><br>
<br>
<br>
--<br>
<br>
Thanks,<br>
<br>
Matt Riedemann<br>
<br>
<br>
<br>
__________________________________________________________________________<br>
<br>
OpenStack Development Mailing List (not for usage questions)<br>
Unsubscribe:<br>
<a href="http://OpenStack-dev-request@lists.openstack.org?subject:unsubscribe" target="_blank">
OpenStack-dev-request@lists.openstack.org?subject:unsubscribe</a><br>
<br>
<<a href="http://OpenStack-dev-request@lists.openstack.org?subject:unsubscribe" target="_blank">http://OpenStack-dev-request@lists.openstack.org?subject:unsubscribe</a>><br>
<a href="http://lists.openstack.org/cgi-bin/mailman/listinfo/openstack-dev" target="_blank">
http://lists.openstack.org/cgi-bin/mailman/listinfo/openstack-dev</a><br>
<br>
<br>
<br>
<br>
__________________________________________________________________________<br>
<br>
OpenStack Development Mailing List (not for usage questions)<br>
Unsubscribe:<br>
<a href="http://OpenStack-dev-request@lists.openstack.org?subject:unsubscribe" target="_blank">OpenStack-dev-request@lists.openstack.org?subject:unsubscribe</a><br>
<a href="http://lists.openstack.org/cgi-bin/mailman/listinfo/openstack-dev" target="_blank">http://lists.openstack.org/cgi-bin/mailman/listinfo/openstack-dev</a><o:p></o:p></p>
</blockquote>
<p class="MsoNormal"><o:p> </o:p></p>
</blockquote>
<p class="MsoNormal"><br>
-- <br>
<br>
Thanks,<br>
<br>
Matt Riedemann<br>
<br>
<br>
__________________________________________________________________________<br>
OpenStack Development Mailing List (not for usage questions)<br>
Unsubscribe: <a href="http://OpenStack-dev-request@lists.openstack.org?subject:unsubscribe" target="_blank">
OpenStack-dev-request@lists.openstack.org?subject:unsubscribe</a><br>
<a href="http://lists.openstack.org/cgi-bin/mailman/listinfo/openstack-dev" target="_blank">http://lists.openstack.org/cgi-bin/mailman/listinfo/openstack-dev</a><o:p></o:p></p>
</div>
</div>
</blockquote>
</div>
<p class="MsoNormal"><o:p> </o:p></p>
</div>
</div>
</div>
</div>
</body>
</html>