[openstack-dev] [olso] olso incubator logging issues

Sean Dague sean at dague.net
Wed Jul 9 11:39:39 UTC 2014


On 07/03/2014 01:52 PM, Doug Hellmann wrote:
> On Mon, Jun 30, 2014 at 9:00 AM, Sean Dague <sean at dague.net> wrote:
>> Every time I crack open a nova logs in detail, at least 2 new olso
>> incubator log issues have been introduced.
>>
>> The current ones is clearly someone is over exploding arrays, as we're
>> getting things like:
>> 2014-06-29 13:36:41.403 19459 DEBUG nova.openstack.common.processutils
>> [-] Running cmd (subprocess): [ ' e n v ' ,   ' L C _ A L L = C ' ,   '
>> L A N G = C ' ,   ' q e m u - i m g ' ,   ' i n f o ' ,   ' / o p t / s
>> 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
>> 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
>> /opt/stack/new/nova/nova/openstack/common/processutils.py:160
>>
>> (yes all those spaces are in there, which now effectively inhibits search).
>>
>> Also on every wsgi request to Nova API we get something like this:
>>
>>
>> 2014-06-29 13:26:43.836 DEBUG nova.openstack.common.policy
>> [req-86680d63-6d6c-4962-9274-1de7de8ca37d
>> FixedIPsNegativeTestJson-768779075 FixedIPsNegativeTestJson-579905596]
>> Rule compute:get will be now enforced enforce
>> /opt/stack/new/nova/nova/openstack/common/policy.py:288
>> 2014-06-29 13:26:43.837 DEBUG nova.openstack.common.policy
>> [req-86680d63-6d6c-4962-9274-1de7de8ca37d
>> FixedIPsNegativeTestJson-768779075 FixedIPsNegativeTestJson-579905596]
>> Rule compute_extension:security_groups will be now enforced enforce
>> /opt/stack/new/nova/nova/openstack/common/policy.py:288
>> 2014-06-29 13:26:43.838 DEBUG nova.openstack.common.policy
>> [req-86680d63-6d6c-4962-9274-1de7de8ca37d
>> FixedIPsNegativeTestJson-768779075 FixedIPsNegativeTestJson-579905596]
>> Rule compute_extension:security_groups will be now enforced enforce
>> /opt/stack/new/nova/nova/openstack/common/policy.py:288
>> 2014-06-29 13:26:43.838 DEBUG nova.openstack.common.policy
>> [req-86680d63-6d6c-4962-9274-1de7de8ca37d
>> FixedIPsNegativeTestJson-768779075 FixedIPsNegativeTestJson-579905596]
>> Rule compute_extension:keypairs will be now enforced enforce
>> /opt/stack/new/nova/nova/openstack/common/policy.py:288
>> 2014-06-29 13:26:43.838 DEBUG nova.openstack.common.policy
>> [req-86680d63-6d6c-4962-9274-1de7de8ca37d
>> FixedIPsNegativeTestJson-768779075 FixedIPsNegativeTestJson-579905596]
>> Rule compute_extension:hide_server_addresses will be now enforced
>> enforce /opt/stack/new/nova/nova/openstack/common/policy.py:288
>> 2014-06-29 13:26:43.838 DEBUG nova.openstack.common.policy
>> [req-86680d63-6d6c-4962-9274-1de7de8ca37d
>> FixedIPsNegativeTestJson-768779075 FixedIPsNegativeTestJson-579905596]
>> Rule compute_extension:extended_volumes will be now enforced enforce
>> /opt/stack/new/nova/nova/openstack/common/policy.py:288
>> 2014-06-29 13:26:43.842 DEBUG nova.openstack.common.policy
>> [req-86680d63-6d6c-4962-9274-1de7de8ca37d
>> FixedIPsNegativeTestJson-768779075 FixedIPsNegativeTestJson-579905596]
>> Rule compute_extension:config_drive will be now enforced enforce
>> /opt/stack/new/nova/nova/openstack/common/policy.py:288
>> 2014-06-29 13:26:43.842 DEBUG nova.openstack.common.policy
>> [req-86680d63-6d6c-4962-9274-1de7de8ca37d
>> FixedIPsNegativeTestJson-768779075 FixedIPsNegativeTestJson-579905596]
>> Rule compute_extension:server_usage will be now enforced enforce
>> /opt/stack/new/nova/nova/openstack/common/policy.py:288
>> 2014-06-29 13:26:43.842 DEBUG nova.openstack.common.policy
>> [req-86680d63-6d6c-4962-9274-1de7de8ca37d
>> FixedIPsNegativeTestJson-768779075 FixedIPsNegativeTestJson-579905596]
>> Rule compute_extension:extended_status will be now enforced enforce
>> /opt/stack/new/nova/nova/openstack/common/policy.py:288
>> 2014-06-29 13:26:43.843 DEBUG nova.openstack.common.policy
>> [req-86680d63-6d6c-4962-9274-1de7de8ca37d
>> FixedIPsNegativeTestJson-768779075 FixedIPsNegativeTestJson-579905596]
>> Rule compute_extension:extended_server_attributes will be now enforced
>> enforce /opt/stack/new/nova/nova/openstack/common/policy.py:288
>> 2014-06-29 13:26:43.843 DEBUG nova.openstack.common.policy
>> [req-86680d63-6d6c-4962-9274-1de7de8ca37d
>> FixedIPsNegativeTestJson-768779075 FixedIPsNegativeTestJson-579905596]
>> Rule compute_extension:extended_ips_mac will be now enforced enforce
>> /opt/stack/new/nova/nova/openstack/common/policy.py:288
>> 2014-06-29 13:26:43.843 DEBUG nova.openstack.common.policy
>> [req-86680d63-6d6c-4962-9274-1de7de8ca37d
>> FixedIPsNegativeTestJson-768779075 FixedIPsNegativeTestJson-579905596]
>> Rule compute_extension:extended_ips will be now enforced enforce
>> /opt/stack/new/nova/nova/openstack/common/policy.py:288
>> 2014-06-29 13:26:43.843 DEBUG nova.openstack.common.policy
>> [req-86680d63-6d6c-4962-9274-1de7de8ca37d
>> FixedIPsNegativeTestJson-768779075 FixedIPsNegativeTestJson-579905596]
>> Rule compute_extension:extended_availability_zone will be now enforced
>> enforce /opt/stack/new/nova/nova/openstack/common/policy.py:288
>> 2014-06-29 13:26:43.844 DEBUG nova.openstack.common.policy
>> [req-86680d63-6d6c-4962-9274-1de7de8ca37d
>> FixedIPsNegativeTestJson-768779075 FixedIPsNegativeTestJson-579905596]
>> Rule compute_extension:disk_config will be now enforced enforce
>> /opt/stack/new/nova/nova/openstack/common/policy.py:288
>>
>> On *every* request.
>>
>> oslo code, by definition, is going to be used a lot, inside of tight
>> loops. Which means extremely verbose. Actually
>> nova.openstack.common.policy currently represents ~40% of all bytes in
>> nova-api logs (15 MB uncompressed content during a Tempest run).
>>
>> Both these are bugs that should be fixed, however, I'd like to figure
>> out how we come up with more systematic approach to keep the quality of
>> these things up, especially as an oslo fix is expensive in terms of
>> labor, as we have to fix in oslo first, then sync to projects. And as
>> more syncs have caused issues like this an oslo sync is not longer a
>> fast approve as it used to be.
> 
> Do you have some automation in mind, or just focusing more on logging
> in reviews?

I don't know. I'm just concerned that some really bad bugs are slipping
through oslo incubator, which is then copy / pasted into projects before
they get noticed (because there is no forward testing), then we have to
run around and replicate fixes everywhere.

Stuff like this is generating a ton of extra work on everyone that's not
oslo.

	-Sean

-- 
Sean Dague
http://dague.net

-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 482 bytes
Desc: OpenPGP digital signature
URL: <http://lists.openstack.org/pipermail/openstack-dev/attachments/20140709/62c889cd/attachment.pgp>


More information about the OpenStack-dev mailing list