Open Stack

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.

	-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/20140630/61853f64/attachment.pgp>