<div dir="ltr"><br><div class="gmail_extra"><br><div class="gmail_quote">On 10 November 2015 at 11:12, Matt Riedemann <span dir="ltr"><<a href="mailto:mriedem@linux.vnet.ibm.com" target="_blank">mriedem@linux.vnet.ibm.com</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div class="HOEnZb"><div class="h5"><br>
<br>
On 11/10/2015 1:10 PM, Matt Riedemann wrote:<br>
<blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
<br>
<br>
On 11/10/2015 12:51 PM, Armando M. wrote:<br>
<blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
<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" rel="noreferrer" target="_blank">https://bugs.launchpad.net/neutron/+bugs?field.tag=logging</a><br>
</blockquote>
<br>
Tagged:<br>
<br>
<a href="https://bugs.launchpad.net/nova/+bug/1514935" rel="noreferrer" 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.<br>
</blockquote>
<br></div></div>
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.</blockquote><div><br></div><div>Ah, gotcha!</div><div> </div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div class="HOEnZb"><div class="h5"><br>
<br>
<blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
<br>
<blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
<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" rel="noreferrer" 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" rel="noreferrer" 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" rel="noreferrer" 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" rel="noreferrer" 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/" rel="noreferrer" 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" rel="noreferrer" 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" rel="noreferrer" 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" rel="noreferrer" target="_blank">OpenStack-dev-request@lists.openstack.org?subject:unsubscribe</a><br>
<br>
<<a href="http://OpenStack-dev-request@lists.openstack.org?subject:unsubscribe" rel="noreferrer" 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" rel="noreferrer" 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" rel="noreferrer" target="_blank">OpenStack-dev-request@lists.openstack.org?subject:unsubscribe</a><br>
<a href="http://lists.openstack.org/cgi-bin/mailman/listinfo/openstack-dev" rel="noreferrer" target="_blank">http://lists.openstack.org/cgi-bin/mailman/listinfo/openstack-dev</a><br>
<br>
</blockquote>
<br>
</blockquote>
<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" rel="noreferrer" target="_blank">OpenStack-dev-request@lists.openstack.org?subject:unsubscribe</a><br>
<a href="http://lists.openstack.org/cgi-bin/mailman/listinfo/openstack-dev" rel="noreferrer" target="_blank">http://lists.openstack.org/cgi-bin/mailman/listinfo/openstack-dev</a><br>
</div></div></blockquote></div><br></div></div>