<div dir="ltr"><br><div class="gmail_extra"><br><br><div class="gmail_quote">On Thu, Jul 3, 2014 at 10:52 AM, Doug Hellmann <span dir="ltr"><<a href="mailto:doug.hellmann@dreamhost.com" target="_blank">doug.hellmann@dreamhost.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">On Mon, Jun 30, 2014 at 9:00 AM, Sean Dague <<a href="mailto:sean@dague.net">sean@dague.net</a>> wrote:<br>


> Every time I crack open a nova logs in detail, at least 2 new olso<br>
> incubator log issues have been introduced.<br>
><br>
> The current ones is clearly someone is over exploding arrays, as we're<br>
> getting things like:<br>
> 2014-06-29 13:36:41.403 19459 DEBUG nova.openstack.common.processutils<br>
> [-] Running cmd (subprocess): [ ' e n v ' ,   ' L C _ A L L = C ' ,   '<br>
> L A N G = C ' ,   ' q e m u - i m g ' ,   ' i n f o ' ,   ' / o p t / s<br>
> t a c k / d a t a / n o v a / i n s t a n c e s / e f f 7 3 1 3 a - 1 1<br>
> b 2 - 4 0 2 b - 9 c c d - 6 5 7 8 c b 8 7 9 2 d b / d i s k ' ] execute<br>
> /opt/stack/new/nova/nova/openstack/common/processutils.py:160<br>
><br>
> (yes all those spaces are in there, which now effectively inhibits search).<br>
><br>
> Also on every wsgi request to Nova API we get something like this:<br>
><br>
><br>
> 2014-06-29 13:26:43.836 DEBUG nova.openstack.common.policy<br>
> [req-86680d63-6d6c-4962-9274-1de7de8ca37d<br>
> FixedIPsNegativeTestJson-768779075 FixedIPsNegativeTestJson-579905596]<br>
> Rule compute:get will be now enforced enforce<br>
> /opt/stack/new/nova/nova/openstack/common/policy.py:288<br>
> 2014-06-29 13:26:43.837 DEBUG nova.openstack.common.policy<br>
> [req-86680d63-6d6c-4962-9274-1de7de8ca37d<br>
> FixedIPsNegativeTestJson-768779075 FixedIPsNegativeTestJson-579905596]<br>
> Rule compute_extension:security_groups will be now enforced enforce<br>
> /opt/stack/new/nova/nova/openstack/common/policy.py:288<br>
> 2014-06-29 13:26:43.838 DEBUG nova.openstack.common.policy<br>
> [req-86680d63-6d6c-4962-9274-1de7de8ca37d<br>
> FixedIPsNegativeTestJson-768779075 FixedIPsNegativeTestJson-579905596]<br>
> Rule compute_extension:security_groups will be now enforced enforce<br>
> /opt/stack/new/nova/nova/openstack/common/policy.py:288<br>
> 2014-06-29 13:26:43.838 DEBUG nova.openstack.common.policy<br>
> [req-86680d63-6d6c-4962-9274-1de7de8ca37d<br>
> FixedIPsNegativeTestJson-768779075 FixedIPsNegativeTestJson-579905596]<br>
> Rule compute_extension:keypairs will be now enforced enforce<br>
> /opt/stack/new/nova/nova/openstack/common/policy.py:288<br>
> 2014-06-29 13:26:43.838 DEBUG nova.openstack.common.policy<br>
> [req-86680d63-6d6c-4962-9274-1de7de8ca37d<br>
> FixedIPsNegativeTestJson-768779075 FixedIPsNegativeTestJson-579905596]<br>
> Rule compute_extension:hide_server_addresses will be now enforced<br>
> enforce /opt/stack/new/nova/nova/openstack/common/policy.py:288<br>
> 2014-06-29 13:26:43.838 DEBUG nova.openstack.common.policy<br>
> [req-86680d63-6d6c-4962-9274-1de7de8ca37d<br>
> FixedIPsNegativeTestJson-768779075 FixedIPsNegativeTestJson-579905596]<br>
> Rule compute_extension:extended_volumes will be now enforced enforce<br>
> /opt/stack/new/nova/nova/openstack/common/policy.py:288<br>
> 2014-06-29 13:26:43.842 DEBUG nova.openstack.common.policy<br>
> [req-86680d63-6d6c-4962-9274-1de7de8ca37d<br>
> FixedIPsNegativeTestJson-768779075 FixedIPsNegativeTestJson-579905596]<br>
> Rule compute_extension:config_drive will be now enforced enforce<br>
> /opt/stack/new/nova/nova/openstack/common/policy.py:288<br>
> 2014-06-29 13:26:43.842 DEBUG nova.openstack.common.policy<br>
> [req-86680d63-6d6c-4962-9274-1de7de8ca37d<br>
> FixedIPsNegativeTestJson-768779075 FixedIPsNegativeTestJson-579905596]<br>
> Rule compute_extension:server_usage will be now enforced enforce<br>
> /opt/stack/new/nova/nova/openstack/common/policy.py:288<br>
> 2014-06-29 13:26:43.842 DEBUG nova.openstack.common.policy<br>
> [req-86680d63-6d6c-4962-9274-1de7de8ca37d<br>
> FixedIPsNegativeTestJson-768779075 FixedIPsNegativeTestJson-579905596]<br>
> Rule compute_extension:extended_status will be now enforced enforce<br>
> /opt/stack/new/nova/nova/openstack/common/policy.py:288<br>
> 2014-06-29 13:26:43.843 DEBUG nova.openstack.common.policy<br>
> [req-86680d63-6d6c-4962-9274-1de7de8ca37d<br>
> FixedIPsNegativeTestJson-768779075 FixedIPsNegativeTestJson-579905596]<br>
> Rule compute_extension:extended_server_attributes will be now enforced<br>
> enforce /opt/stack/new/nova/nova/openstack/common/policy.py:288<br>
> 2014-06-29 13:26:43.843 DEBUG nova.openstack.common.policy<br>
> [req-86680d63-6d6c-4962-9274-1de7de8ca37d<br>
> FixedIPsNegativeTestJson-768779075 FixedIPsNegativeTestJson-579905596]<br>
> Rule compute_extension:extended_ips_mac will be now enforced enforce<br>
> /opt/stack/new/nova/nova/openstack/common/policy.py:288<br>
> 2014-06-29 13:26:43.843 DEBUG nova.openstack.common.policy<br>
> [req-86680d63-6d6c-4962-9274-1de7de8ca37d<br>
> FixedIPsNegativeTestJson-768779075 FixedIPsNegativeTestJson-579905596]<br>
> Rule compute_extension:extended_ips will be now enforced enforce<br>
> /opt/stack/new/nova/nova/openstack/common/policy.py:288<br>
> 2014-06-29 13:26:43.843 DEBUG nova.openstack.common.policy<br>
> [req-86680d63-6d6c-4962-9274-1de7de8ca37d<br>
> FixedIPsNegativeTestJson-768779075 FixedIPsNegativeTestJson-579905596]<br>
> Rule compute_extension:extended_availability_zone will be now enforced<br>
> enforce /opt/stack/new/nova/nova/openstack/common/policy.py:288<br>
> 2014-06-29 13:26:43.844 DEBUG nova.openstack.common.policy<br>
> [req-86680d63-6d6c-4962-9274-1de7de8ca37d<br>
> FixedIPsNegativeTestJson-768779075 FixedIPsNegativeTestJson-579905596]<br>
> Rule compute_extension:disk_config will be now enforced enforce<br>
> /opt/stack/new/nova/nova/openstack/common/policy.py:288<br>
><br>
> On *every* request.<br>
><br>
> oslo code, by definition, is going to be used a lot, inside of tight<br>
> loops. Which means extremely verbose. Actually<br>
> nova.openstack.common.policy currently represents ~40% of all bytes in<br>
> nova-api logs (15 MB uncompressed content during a Tempest run).<br>
><br>
> Both these are bugs that should be fixed, however, I'd like to figure<br>
> out how we come up with more systematic approach to keep the quality of<br>
> these things up, especially as an oslo fix is expensive in terms of<br>
> labor, as we have to fix in oslo first, then sync to projects. And as<br>
> more syncs have caused issues like this an oslo sync is not longer a<br>
> fast approve as it used to be.<br>
<br>
</div></div>Do you have some automation in mind, or just focusing more on logging<br>
in reviews?<br></blockquote><div><br></div><div><br></div><div>Is it possible to add a test that fails if the logs grow are more then then x% larger then trunk? </div><div> </div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">


<br>
Doug<br>
<div class=""><br>
><br>
>         -Sean<br>
><br>
> --<br>
> Sean Dague<br>
> <a href="http://dague.net" target="_blank">http://dague.net</a><br>
><br>
><br>
</div>> _______________________________________________<br>
> OpenStack-dev mailing list<br>
> <a href="mailto:OpenStack-dev@lists.openstack.org">OpenStack-dev@lists.openstack.org</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>
OpenStack-dev mailing list<br>
<a href="mailto:OpenStack-dev@lists.openstack.org">OpenStack-dev@lists.openstack.org</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>
</blockquote></div><br></div></div>